Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250917082641\orcl_w000_22828_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:35971M/63366M, Ph+PgF:40274M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 22828, image: ORACLE.EXE (W000) *** 2025-09-17 08:26:41.481 *** SESSION ID:(177.21173) 2025-09-17 08:26:41.481 *** 2025-09-17 08:26:41.481 Process diagnostic dump for ORACLE.EXE (W000), OS id=22828, pid: 22, proc_ser: 6, sid: 177, sess_ser: 21173 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=106 seq_num=107 snap_id=1 wait times: snap=0.975317 sec, exc=0.975317 sec, total=0.975317 sec wait times: max=5.000000 sec, heur=8 min 46 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.000032 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=105 seq_num=106 snap_id=1 wait times: snap=5.000321 sec, exc=5.000321 sec, total=5.000321 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=104 seq_num=105 snap_id=1 wait times: snap=5.001799 sec, exc=5.001799 sec, total=5.001799 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=103 seq_num=104 snap_id=1 wait times: snap=5.014731 sec, exc=5.014731 sec, total=5.014731 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=102 seq_num=103 snap_id=1 wait times: snap=5.014696 sec, exc=5.014696 sec, total=5.014696 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=101 seq_num=102 snap_id=1 wait times: snap=5.010135 sec, exc=5.010135 sec, total=5.010135 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=100 seq_num=101 snap_id=1 wait times: snap=5.001681 sec, exc=5.001681 sec, total=5.001681 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000050 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=99 seq_num=100 snap_id=1 wait times: snap=5.001247 sec, exc=5.001247 sec, total=5.001247 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=98 seq_num=99 snap_id=1 wait times: snap=5.012690 sec, exc=5.012690 sec, total=5.012690 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=97 seq_num=98 snap_id=1 wait times: snap=5.007311 sec, exc=5.007311 sec, total=5.007311 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=96 seq_num=97 snap_id=1 wait times: snap=5.014740 sec, exc=5.014740 sec, total=5.014740 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time Sampled Session History of session 177 serial 21173 --------------------------------------------------- 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 --------------------------------------------------- [121 samples, 08:24:41 - 08:26:41] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-17 08:26:41.481 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 22828, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-17 05:57:37.458329 :CE8307BE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=52 time=2474308768 2025-09-17 05:57:37.458330 :CE8307BF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 05:57:37.458330 :CE8307C0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 05:57:37.458330 :CE8307C1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 05:57:37.458331 :CE8307C2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 05:57:37.458331 :CE8307C3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 05:57:37.458865 :CE8307C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 05:57:37.458912 :CE8307CE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 06:07:38.263173 :CE83D2C8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 06:07:38.705429 :CE83D327:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 06:07:38.701 2025-09-17 06:07:38.705431 :CE83D328:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19336 pso_num=22 pso_serial#=249 2025-09-17 06:07:38.705571 :CE83D329:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19336 osp_idx=0 osp_ver=616911 osp_pg=0 (spawn #600314) 2025-09-17 06:07:38.705571 :CE83D32A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 06:07:38.705572 :CE83D32B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=53 time=2474910018 2025-09-17 06:07:38.705572 :CE83D32C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 06:07:38.705572 :CE83D32D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 06:07:38.705573 :CE83D32E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 06:07:38.705573 :CE83D32F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 06:07:38.705573 :CE83D330:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 06:07:38.706107 :CE83D331:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 06:07:38.706166 :CE83D33B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 06:17:39.621188 :CE849691:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 06:17:39.985502 :CE8496E0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 06:17:39.980 2025-09-17 06:17:39.985504 :CE8496E1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=25204 pso_num=22 pso_serial#=250 2025-09-17 06:17:39.985642 :CE8496E2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=25204 osp_idx=0 osp_ver=616912 osp_pg=0 (spawn #600336) 2025-09-17 06:17:39.985643 :CE8496E3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 06:17:39.985643 :CE8496E4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=54 time=2475511283 2025-09-17 06:17:39.985644 :CE8496E5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 06:17:39.985644 :CE8496E6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 06:17:39.985645 :CE8496E7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 06:17:39.985645 :CE8496E8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 06:17:39.985645 :CE8496E9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 06:17:39.986185 :CE8496EA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 06:17:39.986234 :CE8496F2:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 06:18:10.055699 :CE84A195:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-09-17 06:18:10.055715 :CE84A19A:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-09-17 06:18:10.055716 :CE84A19B:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=16, exc=16, tot=16 2025-09-17 06:27:40.987078 :CE855D19:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 06:27:41.304782 :CE855D7F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 06:27:41.299 2025-09-17 06:27:41.304784 :CE855D80:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19820 pso_num=22 pso_serial#=251 2025-09-17 06:27:41.304931 :CE855D81:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19820 osp_idx=0 osp_ver=616913 osp_pg=0 (spawn #600359) 2025-09-17 06:27:41.304932 :CE855D82:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 06:27:41.304932 :CE855D83:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=55 time=2476112612 2025-09-17 06:27:41.304933 :CE855D84:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 06:27:41.304933 :CE855D85:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 06:27:41.304933 :CE855D86:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 06:27:41.304934 :CE855D87:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 06:27:41.304934 :CE855D88:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 06:27:41.305533 :CE855D89:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 06:27:41.305583 :CE855D93:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 06:37:42.156555 :CE8620E6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 06:37:42.505536 :CE862152:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 06:37:42.500 2025-09-17 06:37:42.505538 :CE862153:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24488 pso_num=22 pso_serial#=252 2025-09-17 06:37:42.505685 :CE862154:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24488 osp_idx=0 osp_ver=616914 osp_pg=0 (spawn #600382) 2025-09-17 06:37:42.505686 :CE862155:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 06:37:42.505686 :CE862156:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=56 time=2476713815 2025-09-17 06:37:42.505687 :CE862157:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 06:37:42.505688 :CE862158:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 06:37:42.505688 :CE862159:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 06:37:42.505689 :CE86215A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 06:37:42.505689 :CE86215B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 06:37:42.506253 :CE86215C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 06:37:42.506311 :CE862166:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 06:47:43.344899 :CE86E5FE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 06:47:43.787186 :CE86E660:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 06:47:43.783 2025-09-17 06:47:43.787188 :CE86E661:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23772 pso_num=22 pso_serial#=253 2025-09-17 06:47:43.787330 :CE86E662:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23772 osp_idx=0 osp_ver=616915 osp_pg=0 (spawn #600404) 2025-09-17 06:47:43.787331 :CE86E663:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 06:47:43.787331 :CE86E664:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=57 time=2477315096 2025-09-17 06:47:43.787332 :CE86E665:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 06:47:43.787332 :CE86E666:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 06:47:43.787332 :CE86E667:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 06:47:43.787333 :CE86E668:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 06:47:43.787333 :CE86E669:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 06:47:43.787828 :CE86E66A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 06:47:43.787872 :CE86E672:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 06:57:44.619085 :CE87A911:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 06:57:44.868307 :CE87A970:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 06:57:44.863 2025-09-17 06:57:44.868309 :CE87A971:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24260 pso_num=22 pso_serial#=254 2025-09-17 06:57:44.868475 :CE87A972:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24260 osp_idx=0 osp_ver=616916 osp_pg=0 (spawn #600427) 2025-09-17 06:57:44.868476 :CE87A973:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 06:57:44.868476 :CE87A974:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=58 time=2477916174 2025-09-17 06:57:44.868477 :CE87A975:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 06:57:44.868477 :CE87A976:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 06:57:44.868477 :CE87A977:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 06:57:44.868478 :CE87A978:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 06:57:44.868478 :CE87A979:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 06:57:44.869013 :CE87A97A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 06:57:44.869058 :CE87A982:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 07:07:45.730188 :CE887596:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 07:07:46.078931 :CE8875F0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 07:07:46.074 2025-09-17 07:07:46.078933 :CE8875F1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24680 pso_num=22 pso_serial#=255 2025-09-17 07:07:46.079076 :CE8875F2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24680 osp_idx=0 osp_ver=616917 osp_pg=0 (spawn #600453) 2025-09-17 07:07:46.079076 :CE8875F3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 07:07:46.079077 :CE8875F4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=59 time=2478517377 2025-09-17 07:07:46.079077 :CE8875F5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 07:07:46.079078 :CE8875F6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 07:07:46.079078 :CE8875F7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 07:07:46.079078 :CE8875F8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 07:07:46.079079 :CE8875F9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 07:07:46.079634 :CE8875FA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 07:07:46.079682 :CE887602:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 07:15:08.525887 :CE890608:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-09-17 07:17:47.360177 :CE893BBF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-09-17 07:27:48.192964 :CE89FF10:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 07:27:48.557514 :CE89FF7E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 07:27:48.552 2025-09-17 07:27:48.557516 :CE89FF7F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23560 pso_num=22 pso_serial#=1 2025-09-17 07:27:48.557650 :CE89FF80:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23560 osp_idx=0 osp_ver=616918 osp_pg=0 (spawn #600497) 2025-09-17 07:27:48.557650 :CE89FF81:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 07:27:48.557651 :CE89FF82:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=60 time=2479719862 2025-09-17 07:27:48.557651 :CE89FF83:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 07:27:48.557651 :CE89FF84:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 07:27:48.557651 :CE89FF85:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 07:27:48.557651 :CE89FF86:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 07:27:48.557652 :CE89FF87:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 07:27:48.558224 :CE89FF88:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 07:27:48.558273 :CE89FF91:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 07:37:49.437858 :CE8AC32A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 07:37:49.755507 :CE8AC3AF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 07:37:49.750 2025-09-17 07:37:49.755509 :CE8AC3B0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23448 pso_num=22 pso_serial#=2 2025-09-17 07:37:49.755648 :CE8AC3B1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23448 osp_idx=0 osp_ver=616919 osp_pg=0 (spawn #600520) 2025-09-17 07:37:49.755649 :CE8AC3B2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 07:37:49.755649 :CE8AC3B3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=61 time=2480321065 2025-09-17 07:37:49.755650 :CE8AC3B4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 07:37:49.755650 :CE8AC3B5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 07:37:49.755651 :CE8AC3B6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 07:37:49.755651 :CE8AC3B7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 07:37:49.755651 :CE8AC3B8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 07:37:49.756220 :CE8AC3B9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 07:37:49.756267 :CE8AC3C1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 07:47:50.668982 :CE8B856B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 07:47:50.970926 :CE8B85D7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 07:47:50.966 2025-09-17 07:47:50.970928 :CE8B85D8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19760 pso_num=22 pso_serial#=3 2025-09-17 07:47:50.971070 :CE8B85D9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19760 osp_idx=0 osp_ver=616920 osp_pg=0 (spawn #600542) 2025-09-17 07:47:50.971071 :CE8B85DA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 07:47:50.971071 :CE8B85DB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=62 time=2480922268 2025-09-17 07:47:50.971072 :CE8B85DC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 07:47:50.971072 :CE8B85DD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 07:47:50.971072 :CE8B85DE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 07:47:50.971073 :CE8B85DF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 07:47:50.971073 :CE8B85E0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 07:47:50.971611 :CE8B85E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 07:47:50.971655 :CE8B85E9:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 07:57:51.920806 :CE8C490E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 07:57:52.269518 :CE8C4972:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 07:57:52.264 2025-09-17 07:57:52.269520 :CE8C4973:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=25056 pso_num=22 pso_serial#=4 2025-09-17 07:57:52.269664 :CE8C4974:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=25056 osp_idx=0 osp_ver=616921 osp_pg=0 (spawn #600565) 2025-09-17 07:57:52.269665 :CE8C4975:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 07:57:52.269665 :CE8C4976:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=63 time=2481523580 2025-09-17 07:57:52.269665 :CE8C4977:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 07:57:52.269666 :CE8C4978:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 07:57:52.269666 :CE8C4979:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 07:57:52.269666 :CE8C497A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 07:57:52.269667 :CE8C497B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 07:57:52.270220 :CE8C497C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 07:57:52.270272 :CE8C4986:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 08:07:53.188780 :CE8D13D5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 08:07:53.459388 :CE8D145C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 08:07:53.454 2025-09-17 08:07:53.459390 :CE8D145D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=25464 pso_num=22 pso_serial#=5 2025-09-17 08:07:53.459532 :CE8D145E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=25464 osp_idx=0 osp_ver=616922 osp_pg=0 (spawn #600591) 2025-09-17 08:07:53.459533 :CE8D145F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 08:07:53.459533 :CE8D1460:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=64 time=2482124768 2025-09-17 08:07:53.459534 :CE8D1461:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 08:07:53.459534 :CE8D1462:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 08:07:53.459534 :CE8D1463:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 08:07:53.459534 :CE8D1464:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 08:07:53.459535 :CE8D1465:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 08:07:53.460082 :CE8D1466:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 08:07:53.460128 :CE8D146E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 08:08:23.502521 :CE8D1F55:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-09-17 08:08:23.502524 :CE8D1F58:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-09-17 08:08:23.502525 :CE8D1F5B:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=4, exc=4, tot=4 2025-09-17 08:08:23.502529 :CE8D1F61:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-17 08:17:54.334833 :CE8DDA3A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-17 08:17:54.714612 :CE8DDACC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-17 08:17:54.710 2025-09-17 08:17:54.714614 :CE8DDACD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22828 pso_num=22 pso_serial#=6 2025-09-17 08:17:54.714747 :CE8DDACE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22828 osp_idx=0 osp_ver=616923 osp_pg=0 (spawn #600613) 2025-09-17 08:17:54.714747 :CE8DDACF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-17 08:17:54.714748 :CE8DDAD0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=65 time=2482726018 2025-09-17 08:17:54.714748 :CE8DDAD1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-17 08:17:54.714748 :CE8DDAD2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-17 08:17:54.714749 :CE8DDAD3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-17 08:17:54.714749 :CE8DDAD4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-17 08:17:54.714749 :CE8DDAD5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-17 08:17:54.715243 :CE8DDAD6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-17 08:17:54.715285 :CE8DDADE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 22828, W000)