Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250831081748\orcl_w000_7196_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:35070M/63366M, Ph+PgF:40024M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 7196, image: ORACLE.EXE (W000) *** 2025-08-31 08:17:48.141 *** SESSION ID:(177.13407) 2025-08-31 08:17:48.141 *** 2025-08-31 08:17:48.141 Process diagnostic dump for ORACLE.EXE (W000), OS id=7196, pid: 22, proc_ser: 215, sid: 177, sess_ser: 13407 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=112 seq_num=113 snap_id=1 wait times: snap=1.784175 sec, exc=1.784175 sec, total=1.784175 sec wait times: max=5.000000 sec, heur=9 min 17 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.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=111 seq_num=112 snap_id=1 wait times: snap=5.014709 sec, exc=5.014709 sec, total=5.014709 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000044 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=110 seq_num=111 snap_id=1 wait times: snap=5.010150 sec, exc=5.010150 sec, total=5.010150 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=109 seq_num=110 snap_id=1 wait times: snap=5.001740 sec, exc=5.001740 sec, total=5.001740 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=108 seq_num=109 snap_id=1 wait times: snap=5.001380 sec, exc=5.001380 sec, total=5.001380 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=107 seq_num=108 snap_id=1 wait times: snap=5.000313 sec, exc=5.000313 sec, total=5.000313 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=106 seq_num=107 snap_id=1 wait times: snap=5.002535 sec, exc=5.002535 sec, total=5.002535 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 6: 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.005899 sec, exc=5.005899 sec, total=5.005899 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: 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.010175 sec, exc=5.010175 sec, total=5.010175 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: 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.014718 sec, exc=5.014718 sec, total=5.014718 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 9: 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.004623 sec, exc=5.004623 sec, total=5.004623 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time Sampled Session History of session 177 serial 13407 --------------------------------------------------- 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:15:48 - 08:17:48] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-31 08:17:48.141 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 7196, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-31 05:58:14.299202 :C6F7C49E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23152 (legacy spawn) 2025-08-31 05:58:14.305772 :C6F7C49F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-31 05:58:14.305938 :C6F7C4A8:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-31 05:58:14.306740 :C6F7C4A9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 05:58:14.648297 :C6F7C4FF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 05:58:14.643 2025-08-31 05:58:14.648299 :C6F7C500:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20136 pso_num=22 pso_serial#=203 2025-08-31 05:58:14.648443 :C6F7C501:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20136 osp_idx=0 osp_ver=557960 osp_pg=0 (spawn #543595) 2025-08-31 05:58:14.648444 :C6F7C502:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 05:58:14.648444 :C6F7C503:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=239 time=1005545955 2025-08-31 05:58:14.648445 :C6F7C504:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 05:58:14.648445 :C6F7C505:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 05:58:14.648445 :C6F7C506:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 05:58:14.648446 :C6F7C507:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 05:58:14.648446 :C6F7C508:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 05:58:14.648966 :C6F7C509: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-08-31 05:58:14.649013 :C6F7C510: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-08-31 06:08:15.494946 :C6F89E79:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 06:08:15.921449 :C6F89EE4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 06:08:15.917 2025-08-31 06:08:15.921451 :C6F89EE5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19212 pso_num=22 pso_serial#=204 2025-08-31 06:08:15.921588 :C6F89EE6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19212 osp_idx=0 osp_ver=557961 osp_pg=0 (spawn #543627) 2025-08-31 06:08:15.921588 :C6F89EE7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 06:08:15.921589 :C6F89EE8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=240 time=1006147221 2025-08-31 06:08:15.921589 :C6F89EE9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 06:08:15.921590 :C6F89EEA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 06:08:15.921590 :C6F89EEB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 06:08:15.921590 :C6F89EEC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 06:08:15.921591 :C6F89EED:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 06:08:15.922106 :C6F89EEE: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-08-31 06:08:15.922151 :C6F89EF6: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-08-31 06:18:16.701617 :C6F967C4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 06:18:17.222035 :C6F96829:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 06:18:17.217 2025-08-31 06:18:17.222037 :C6F9682A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21840 pso_num=22 pso_serial#=205 2025-08-31 06:18:17.222172 :C6F9682B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21840 osp_idx=0 osp_ver=557962 osp_pg=0 (spawn #543650) 2025-08-31 06:18:17.222172 :C6F9682C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 06:18:17.222172 :C6F9682D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=241 time=1006748533 2025-08-31 06:18:17.222172 :C6F9682E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 06:18:17.222173 :C6F9682F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 06:18:17.222173 :C6F96830:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 06:18:17.222174 :C6F96831:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 06:18:17.222174 :C6F96832:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 06:18:17.222659 :C6F96833: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-08-31 06:18:17.222704 :C6F9683B: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-08-31 06:18:32.243834 :C6F96D03:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-08-31 06:18:32.243841 :C6F96D04:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-08-31 06:18:32.243841 :C6F96D06:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=10, exc=10, tot=10 2025-08-31 06:18:32.243852 :C6F96D0A: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-08-31 06:18:47.268911 :C6F9719E:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=9 seq_num=10 snap_id=1 2025-08-31 06:18:47.268937 :C6F971AA:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=9 seq_num=10 snap_id=1 2025-08-31 06:18:47.268939 :C6F971AB:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=25, exc=25, tot=25 2025-08-31 06:28:18.075556 :C6FA2C8C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 06:28:18.377590 :C6FA2CE1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 06:28:18.372 2025-08-31 06:28:18.377592 :C6FA2CE2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22952 pso_num=22 pso_serial#=206 2025-08-31 06:28:18.377742 :C6FA2CE3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22952 osp_idx=0 osp_ver=557963 osp_pg=0 (spawn #543672) 2025-08-31 06:28:18.377743 :C6FA2CE4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 06:28:18.377744 :C6FA2CE5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=242 time=1007349674 2025-08-31 06:28:18.377744 :C6FA2CE6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 06:28:18.377744 :C6FA2CE7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 06:28:18.377744 :C6FA2CE8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 06:28:18.377744 :C6FA2CE9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 06:28:18.377745 :C6FA2CEA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 06:28:18.378262 :C6FA2CEB: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-08-31 06:28:18.378310 :C6FA2CF2: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-08-31 06:38:19.216975 :C6FAF26A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 06:38:19.612561 :C6FAF2BB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 06:38:19.607 2025-08-31 06:38:19.612563 :C6FAF2BC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22628 pso_num=22 pso_serial#=207 2025-08-31 06:38:19.612702 :C6FAF2BD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22628 osp_idx=0 osp_ver=557964 osp_pg=0 (spawn #543695) 2025-08-31 06:38:19.612702 :C6FAF2BE:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 06:38:19.612703 :C6FAF2BF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=243 time=1007950924 2025-08-31 06:38:19.612703 :C6FAF2C0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 06:38:19.612704 :C6FAF2C1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 06:38:19.612704 :C6FAF2C2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 06:38:19.612704 :C6FAF2C3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 06:38:19.612705 :C6FAF2C4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 06:38:19.613199 :C6FAF2C5: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-08-31 06:38:19.613246 :C6FAF2CF: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-08-31 06:48:20.421184 :C6FBB5F1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 06:48:20.795386 :C6FBB646:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 06:48:20.790 2025-08-31 06:48:20.795389 :C6FBB647:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19228 pso_num=22 pso_serial#=208 2025-08-31 06:48:20.795538 :C6FBB648:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19228 osp_idx=0 osp_ver=557965 osp_pg=0 (spawn #543718) 2025-08-31 06:48:20.795539 :C6FBB649:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 06:48:20.795539 :C6FBB64A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=244 time=1008552096 2025-08-31 06:48:20.795540 :C6FBB64B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 06:48:20.795540 :C6FBB64C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 06:48:20.795540 :C6FBB64D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 06:48:20.795541 :C6FBB64E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 06:48:20.795541 :C6FBB64F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 06:48:20.796043 :C6FBB650: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-08-31 06:48:20.796087 :C6FBB657: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-08-31 06:58:21.648611 :C6FC7AD0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 06:58:22.200263 :C6FC7B23:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 06:58:22.196 2025-08-31 06:58:22.200265 :C6FC7B24:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22244 pso_num=22 pso_serial#=209 2025-08-31 06:58:22.200400 :C6FC7B25:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22244 osp_idx=0 osp_ver=557966 osp_pg=0 (spawn #543740) 2025-08-31 06:58:22.200401 :C6FC7B26:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 06:58:22.200401 :C6FC7B27:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=245 time=1009153502 2025-08-31 06:58:22.200402 :C6FC7B28:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 06:58:22.200402 :C6FC7B29:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 06:58:22.200402 :C6FC7B2A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 06:58:22.200403 :C6FC7B2B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 06:58:22.200403 :C6FC7B2C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 06:58:22.200886 :C6FC7B2D: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-08-31 06:58:22.200930 :C6FC7B35: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-08-31 07:08:23.020642 :C6FD4A43:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 07:08:23.447368 :C6FD4A85:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 07:08:23.443 2025-08-31 07:08:23.447370 :C6FD4A86:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22492 pso_num=22 pso_serial#=210 2025-08-31 07:08:23.447502 :C6FD4A87:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22492 osp_idx=0 osp_ver=557967 osp_pg=0 (spawn #543766) 2025-08-31 07:08:23.447503 :C6FD4A88:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 07:08:23.447503 :C6FD4A89:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=246 time=1009754752 2025-08-31 07:08:23.447504 :C6FD4A8A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 07:08:23.447504 :C6FD4A8B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 07:08:23.447505 :C6FD4A8C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 07:08:23.447505 :C6FD4A8D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 07:08:23.447505 :C6FD4A8E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 07:08:23.448004 :C6FD4A8F: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-08-31 07:08:23.448048 :C6FD4A96: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-08-31 07:18:15.379772 :C6FE0CD8: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-08-31 07:18:24.789095 :C6FE1127: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-08-31 07:28:25.680320 :C6FED75F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 07:28:25.934793 :C6FED79D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 07:28:25.930 2025-08-31 07:28:25.934795 :C6FED79E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23096 pso_num=22 pso_serial#=211 2025-08-31 07:28:25.934933 :C6FED79F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23096 osp_idx=0 osp_ver=557968 osp_pg=0 (spawn #543810) 2025-08-31 07:28:25.934934 :C6FED7A0:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 07:28:25.934934 :C6FED7A1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=247 time=1010957237 2025-08-31 07:28:25.934935 :C6FED7A2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 07:28:25.934935 :C6FED7A3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 07:28:25.934936 :C6FED7A4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 07:28:25.934936 :C6FED7A5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 07:28:25.934936 :C6FED7A6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 07:28:25.935426 :C6FED7A7: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-08-31 07:28:25.935486 :C6FED7B1: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-08-31 07:38:26.648731 :C6FF9DFE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 07:38:27.038722 :C6FF9E47:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 07:38:27.033 2025-08-31 07:38:27.038725 :C6FF9E48:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23216 pso_num=22 pso_serial#=212 2025-08-31 07:38:27.038870 :C6FF9E49:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23216 osp_idx=0 osp_ver=557969 osp_pg=0 (spawn #543833) 2025-08-31 07:38:27.038870 :C6FF9E4A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 07:38:27.038871 :C6FF9E4B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=248 time=1011558346 2025-08-31 07:38:27.038871 :C6FF9E4C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 07:38:27.038872 :C6FF9E4D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 07:38:27.038872 :C6FF9E4E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 07:38:27.038872 :C6FF9E4F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 07:38:27.038873 :C6FF9E50:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 07:38:27.039387 :C6FF9E51: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-08-31 07:38:27.039446 :C6FF9E5A: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-08-31 07:48:27.871983 :C70064E2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 07:48:28.173823 :C7006526:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 07:48:28.168 2025-08-31 07:48:28.173825 :C7006527:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6008 pso_num=22 pso_serial#=213 2025-08-31 07:48:28.173970 :C7006528:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6008 osp_idx=0 osp_ver=557970 osp_pg=0 (spawn #543856) 2025-08-31 07:48:28.173971 :C7006529:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 07:48:28.173971 :C700652A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=249 time=1012159471 2025-08-31 07:48:28.173971 :C700652B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 07:48:28.173971 :C700652C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 07:48:28.173972 :C700652D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 07:48:28.173972 :C700652E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 07:48:28.173972 :C700652F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 07:48:28.174470 :C7006530: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-08-31 07:48:28.174514 :C7006536: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-08-31 07:58:29.045318 :C7012B6C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 07:58:29.393758 :C7012BB9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 07:58:29.389 2025-08-31 07:58:29.393760 :C7012BBA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20840 pso_num=22 pso_serial#=214 2025-08-31 07:58:29.393903 :C7012BBB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20840 osp_idx=0 osp_ver=557971 osp_pg=0 (spawn #543878) 2025-08-31 07:58:29.393904 :C7012BBC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 07:58:29.393904 :C7012BBD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=250 time=1012760705 2025-08-31 07:58:29.393904 :C7012BBE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 07:58:29.393905 :C7012BBF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 07:58:29.393905 :C7012BC0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 07:58:29.393905 :C7012BC1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 07:58:29.393906 :C7012BC2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 07:58:29.394434 :C7012BC3: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-08-31 07:58:29.394482 :C7012BCC: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-08-31 07:59:44.529722 :C7014455:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=16 seq_num=17 snap_id=1 2025-08-31 07:59:44.529727 :C7014457:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=16 seq_num=17 snap_id=1 2025-08-31 07:59:44.529728 :C7014459:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=6, exc=6, tot=6 2025-08-31 07:59:44.529737 :C7014465: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-08-31 08:08:30.187327 :C701FCED:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 08:08:30.535806 :C701FD29:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 08:08:30.531 2025-08-31 08:08:30.535808 :C701FD2A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7196 pso_num=22 pso_serial#=215 2025-08-31 08:08:30.535943 :C701FD2B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7196 osp_idx=0 osp_ver=557972 osp_pg=0 (spawn #543904) 2025-08-31 08:08:30.535944 :C701FD2C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 08:08:30.535945 :C701FD2D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=251 time=1013361846 2025-08-31 08:08:30.535945 :C701FD2E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 08:08:30.535946 :C701FD2F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 08:08:30.535946 :C701FD30:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 08:08:30.535946 :C701FD31:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 08:08:30.535946 :C701FD32:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 08:08:30.536427 :C701FD33: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-08-31 08:08:30.536474 :C701FD3B: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: 7196, W000)