Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250613220004\orcl_j002_10076_bucket.trc Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options Windows NT Version V6.2 CPU : 32 - type 8664, 16 Physical Cores Process Affinity : 0x0x0000000000000000 Memory (Avail/Total): Ph:36709M/63366M, Ph+PgF:43188M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 27 Windows thread id: 10076, image: ORACLE.EXE (J002) *** 2025-06-13 22:00:04.791 *** SESSION ID:(219.57347) 2025-06-13 22:00:04.791 *** 2025-06-13 22:00:04.791 Process diagnostic dump for ORACLE.EXE (J002), OS id=10076, pid: 27, proc_ser: 194, sid: 219, sess_ser: 57347 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 10076 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.249302 sec, exc=0.249302 sec, total=0.249302 sec wait times: max=0.500000 sec, heur=4.356251 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500005 sec, exc=0.500005 sec, total=0.500005 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499992 sec, exc=0.499992 sec, total=0.499992 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.510117 sec, exc=0.510117 sec, total=0.510117 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499232 sec, exc=0.499232 sec, total=0.499232 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.097547 sec, exc=0.097547 sec, total=0.097547 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 219 serial 57347 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [5 samples, 22:00:00 - 22:00:04] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-13 22:00:04.791 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 27 (osid: 10076, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-13 20:13:16.044415 :A443B8A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 20:13:16.044428 :A443B8A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 20:13:16.046623 :A443B8A3:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 20:43:19.744551 :A4460184:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 20:43:19.732 2025-06-13 20:43:19.744553 :A4460185:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=12532 pso_num=27 pso_serial#=186 2025-06-13 20:43:19.744682 :A4460186:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=12532 osp_idx=25 osp_ver=61385 osp_pg=0 (spawn #282295) 2025-06-13 20:43:19.744683 :A4460187:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 20:43:19.744683 :A4460188:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=2 time=2823142922 2025-06-13 20:43:19.744684 :A4460189:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 20:43:19.744684 :A446018A:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 20:43:19.744685 :A446018B:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 20:43:19.744685 :A446018C:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 20:43:19.744685 :A446018D:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 20:43:19.745226 :A446018E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-13 20:43:19.745272 :A4460194:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 20:43:19.749208 :A44601BD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 20:43:19.749248 :A44601BE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 20:43:19.749531 :A44601BF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 20:43:19.749554 :A44601C0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 20:43:19.749801 :A44601C1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 20:43:19.749815 :A44601C2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 20:43:19.750021 :A44601C3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 20:43:19.750034 :A44601C4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 20:43:19.750246 :A44601C5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 20:43:19.750259 :A44601C6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 20:43:19.750460 :A44601C7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 20:43:19.750472 :A44601C8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 20:43:19.752683 :A44601C9:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 21:00:21.991195 :A4474E19:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 21:00:21.977 2025-06-13 21:00:21.991197 :A4474E1A:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=13912 pso_num=27 pso_serial#=187 2025-06-13 21:00:21.991334 :A4474E1B:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=13912 (legacy spawn) 2025-06-13 21:00:21.997833 :A4474E1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:21.998156 :A4474E25:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 21:00:21.998951 :A4474E26:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 21:00:22.007554 :A4474E29:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 21:00:21.993 2025-06-13 21:00:22.007556 :A4474E2A:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16716 pso_num=27 pso_serial#=188 2025-06-13 21:00:22.007686 :A4474E2B:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=16716 (legacy spawn) 2025-06-13 21:00:22.014124 :A4474E2C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:22.014284 :A4474E35:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 21:00:22.015053 :A4474E36:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 21:00:23.065611 :A4474E88:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 21:00:23.060 2025-06-13 21:00:23.065614 :A4474E89:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15812 pso_num=27 pso_serial#=189 2025-06-13 21:00:23.065751 :A4474E8A:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=15812 osp_idx=25 osp_ver=61388 osp_pg=0 (spawn #282333) 2025-06-13 21:00:23.065751 :A4474E8B:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:00:23.065752 :A4474E8C:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=3 time=2824166235 2025-06-13 21:00:23.065752 :A4474E8D:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:00:23.065753 :A4474E8E:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:00:23.065753 :A4474E8F:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:00:23.065753 :A4474E90:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:00:23.065754 :A4474E91:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:00:23.066258 :A4474E92:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.066302 :A4474E98:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 21:00:23.073892 :A4474EA6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.074986 :A4474EAE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.075559 :A4474EB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.076025 :A4474EBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.076538 :A4474EC6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.079019 :A4474ECE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.080099 :A4474ED6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.130081 :A4474EDE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.131035 :A4474EE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.131289 :A4474EEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.131516 :A4474EF6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:00:23.133229 :A4474EFE:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 21:03:22.052026 :A4478902:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 21:03:22.040 2025-06-13 21:03:22.052027 :A4478903:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=13440 pso_num=27 pso_serial#=190 2025-06-13 21:03:22.052167 :A4478904:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=13440 osp_idx=25 osp_ver=61389 osp_pg=0 (spawn #282342) 2025-06-13 21:03:22.052168 :A4478905:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:03:22.052169 :A4478906:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=4 time=2824345235 2025-06-13 21:03:22.052169 :A4478907:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:03:22.052170 :A4478908:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:03:22.052170 :A4478909:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:03:22.052170 :A447890A:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:03:22.052170 :A447890B:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:03:22.052763 :A447890C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-13 21:03:22.052810 :A4478912:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 21:03:22.061194 :A4478927:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 21:13:23.219674 :A44851B5:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 21:13:23.207 2025-06-13 21:13:23.219676 :A44851B6:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=7708 pso_num=27 pso_serial#=191 2025-06-13 21:13:23.219809 :A44851B7:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=7708 osp_idx=25 osp_ver=61390 osp_pg=0 (spawn #282365) 2025-06-13 21:13:23.219809 :A44851B8:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:13:23.219810 :A44851B9:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=5 time=2824946407 2025-06-13 21:13:23.219810 :A44851BA:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:13:23.219811 :A44851BB:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:13:23.219811 :A44851BC:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:13:23.219812 :A44851BD:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:13:23.219812 :A44851BE:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:13:23.220314 :A44851BF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-13 21:13:23.220367 :A44851C5:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 21:13:23.224372 :A44851EE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:13:23.224410 :A44851EF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:13:23.224651 :A44851F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:13:23.224665 :A44851F1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:13:23.224876 :A44851F2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:13:23.224889 :A44851F3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:13:23.225091 :A44851F4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:13:23.225104 :A44851F5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:13:23.225303 :A44851F6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:13:23.225319 :A44851F7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:13:23.225520 :A44851F8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:13:23.225536 :A44851F9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:13:23.227880 :A44851FA:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 21:28:24.956176 :A44977E6:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 21:28:24.947 2025-06-13 21:28:24.956177 :A44977E7:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=5020 pso_num=27 pso_serial#=192 2025-06-13 21:28:24.956306 :A44977E8:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=5020 (legacy spawn) 2025-06-13 21:28:24.962801 :A44977EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 21:28:24.962923 :A44977F7:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 21:28:24.963745 :A44977F8:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 21:43:26.555444 :A44A9C6E:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 21:43:26.543 2025-06-13 21:43:26.555446 :A44A9C6F:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15540 pso_num=27 pso_serial#=193 2025-06-13 21:43:26.555582 :A44A9C70:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=15540 osp_idx=25 osp_ver=61392 osp_pg=0 (spawn #282433) 2025-06-13 21:43:26.555583 :A44A9C71:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:43:26.555584 :A44A9C72:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=6 time=2826749735 2025-06-13 21:43:26.555584 :A44A9C73:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:43:26.555585 :A44A9C74:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:43:26.555585 :A44A9C75:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:43:26.555585 :A44A9C76:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:43:26.555586 :A44A9C77:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:43:26.556108 :A44A9C78:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-13 21:43:26.556146 :A44A9C7E:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 21:43:26.560108 :A44A9CA7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:43:26.560153 :A44A9CA8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:43:26.560405 :A44A9CA9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:43:26.560422 :A44A9CAA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:43:26.560639 :A44A9CAB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:43:26.560653 :A44A9CAC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:43:26.560862 :A44A9CAD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:43:26.560875 :A44A9CAE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:43:26.561086 :A44A9CAF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:43:26.561099 :A44A9CB0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:43:26.561301 :A44A9CB1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-13 21:43:26.561314 :A44A9CB2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-13 21:43:26.563631 :A44A9CB3:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-13 22:00:00.421040 :A44BDE68:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-13 22:00:00.420 2025-06-13 22:00:00.421042 :A44BDE69:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=10076 pso_num=27 pso_serial#=194 2025-06-13 22:00:00.421177 :A44BDE6C:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=10076 osp_idx=25 osp_ver=61393 osp_pg=0 (spawn #282473) 2025-06-13 22:00:00.421177 :A44BDE6D:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 22:00:00.421178 :A44BDE6E:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=7 time=2827743594 2025-06-13 22:00:00.421178 :A44BDE6F:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 22:00:00.421179 :A44BDE70:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 22:00:00.421179 :A44BDE71:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 22:00:00.421180 :A44BDE72:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 22:00:00.421180 :A44BDE73:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 22:00:00.421672 :A44BDE7B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.426706 :A44BDE98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.426747 :A44BDE9B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-06-13 22:00:00.431463 :A44BDEC8:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-13 22:00:00.432068 :A44BDEC9:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 c105120000000000 2025-06-13 22:00:00.433742 :A44BDEFF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.433814 :A44BDF0D:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 22:00:00.433823 :A44BDF13:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-06-13 22:00:00.433827 :A44BDF14:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.433854 :A44BDF27:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 22:00:00.434570 :A44BDF33:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 228284896) 2025-06-13 22:00:00.434574 :A44BDF34:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.434595 :A44BDF3F:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 22:00:00.434602 :A44BDF4C:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65563 1) 2025-06-13 22:00:00.434604 :A44BDF4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.434631 :A44BDF59:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 22:00:00.434634 :A44BDF62:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65563) 2025-06-13 22:00:00.434636 :A44BDF66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.434681 :A44BDF8B:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 22:00:00.435648 :A44BE026:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 22:00:00.435672 :A44BE035:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-13 22:00:00.436586 :A44BE036:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 c205120000000000 2025-06-13 22:00:00.436946 :A44BE037:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 228284896) 2025-06-13 22:00:00.436952 :A44BE038:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.436978 :A44BE042:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-13 22:00:00.445418 :A44BE0A6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-06-13 22:00:00.447226 :A44BE0A7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.447279 :A44BE0AA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-06-13 22:00:00.447401 :A44BE0B7:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 22:00:00.545690 :A44BE1A7:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 27 (osid: 10076, J002)