Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250827220006\orcl_w000_20680_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:35157M/63366M, Ph+PgF:40155M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 20680, image: ORACLE.EXE (W000) *** 2025-08-27 22:00:06.648 *** SESSION ID:(177.64711) 2025-08-27 22:00:06.648 *** 2025-08-27 22:00:06.648 Process diagnostic dump for ORACLE.EXE (W000), OS id=20680, pid: 22, proc_ser: 17, sid: 177, sess_ser: 64711 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=3.613856 sec, exc=3.613856 sec, total=3.613856 sec wait times: max=5.000000 sec, heur=1 min 48 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.000026 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.014730 sec, exc=5.014730 sec, total=5.014730 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.004622 sec, exc=5.004622 sec, total=5.004622 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.002958 sec, exc=5.002958 sec, total=5.002958 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.000279 sec, exc=5.000279 sec, total=5.000279 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=17 seq_num=18 snap_id=1 wait times: snap=5.012870 sec, exc=5.012870 sec, total=5.012870 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=5.010137 sec, exc=5.010137 sec, total=5.010137 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=5.009202 sec, exc=5.009202 sec, total=5.009202 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=5.004621 sec, exc=5.004621 sec, total=5.004621 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=5.004631 sec, exc=5.004631 sec, total=5.004631 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=5.004637 sec, exc=5.004637 sec, total=5.004637 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time Sampled Session History of session 177 serial 64711 --------------------------------------------------- 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 --------------------------------------------------- [109 samples, 21:58:17 - 22:00:06] idle wait at each sample [session created at: 21:58:17] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-27 22:00:06.648 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 20680, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-27 19:37:59.728489 :C573BDB2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 19:38:00.055749 :C573BE10:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 19:38:00.051 2025-08-27 19:38:00.055751 :C573BE11:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23316 pso_num=22 pso_serial#=4 2025-08-27 19:38:00.055895 :C573BE12:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23316 osp_idx=0 osp_ver=551896 osp_pg=0 (spawn #532159) 2025-08-27 19:38:00.055896 :C573BE13: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-27 19:38:00.055897 :C573BE14:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=8 time=709131362 2025-08-27 19:38:00.055898 :C573BE15:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 19:38:00.055898 :C573BE16:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 19:38:00.055898 :C573BE17:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 19:38:00.055899 :C573BE18:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 19:38:00.055899 :C573BE19:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 19:38:00.056457 :C573BE1A: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-27 19:38:00.056501 :C573BE24: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-27 19:48:00.976316 :C5747EE6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 19:48:01.278283 :C5747FDE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 19:48:01.273 2025-08-27 19:48:01.278285 :C5747FDF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21836 pso_num=22 pso_serial#=5 2025-08-27 19:48:01.278426 :C5747FE0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21836 osp_idx=0 osp_ver=551897 osp_pg=0 (spawn #532181) 2025-08-27 19:48:01.278427 :C5747FE1: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-27 19:48:01.278427 :C5747FE2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=9 time=709732580 2025-08-27 19:48:01.278427 :C5747FE3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 19:48:01.278428 :C5747FE4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 19:48:01.278428 :C5747FE5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 19:48:01.278428 :C5747FE6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 19:48:01.278429 :C5747FE7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 19:48:01.278954 :C5747FE8: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-27 19:48:01.279001 :C5747FF0: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-27 19:58:02.182590 :C5754072:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 19:58:02.499892 :C5754135:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 19:58:02.495 2025-08-27 19:58:02.499895 :C5754136:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22152 pso_num=22 pso_serial#=6 2025-08-27 19:58:02.500047 :C5754137:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22152 osp_idx=0 osp_ver=551898 osp_pg=0 (spawn #532204) 2025-08-27 19:58:02.500048 :C5754138: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-27 19:58:02.500048 :C5754139:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=10 time=710333799 2025-08-27 19:58:02.500049 :C575413A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 19:58:02.500049 :C575413B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 19:58:02.500049 :C575413C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 19:58:02.500050 :C575413D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 19:58:02.500050 :C575413E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 19:58:02.500566 :C575413F: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-27 19:58:02.500618 :C5754145: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-27 20:08:03.356096 :C5760AC0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 20:08:03.730445 :C5760B39:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 20:08:03.725 2025-08-27 20:08:03.730447 :C5760B3A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21804 pso_num=22 pso_serial#=7 2025-08-27 20:08:03.730593 :C5760B3B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21804 osp_idx=0 osp_ver=551899 osp_pg=0 (spawn #532230) 2025-08-27 20:08:03.730594 :C5760B3C: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-27 20:08:03.730595 :C5760B3D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=11 time=710935033 2025-08-27 20:08:03.730595 :C5760B3E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 20:08:03.730595 :C5760B3F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 20:08:03.730596 :C5760B40:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 20:08:03.730596 :C5760B41:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 20:08:03.730596 :C5760B42:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 20:08:03.731102 :C5760B43: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-27 20:08:03.731149 :C5760B4D: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-27 20:16:40.784760 :C576B2C9: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-27 20:18:05.068129 :C576D1BE: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-27 20:28:05.989890 :C57794B1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 20:28:06.291384 :C577951F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 20:28:06.286 2025-08-27 20:28:06.291385 :C5779520:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20168 pso_num=22 pso_serial#=8 2025-08-27 20:28:06.291523 :C5779521:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20168 osp_idx=0 osp_ver=551900 osp_pg=0 (spawn #532274) 2025-08-27 20:28:06.291524 :C5779522: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-27 20:28:06.291524 :C5779523:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=12 time=712137596 2025-08-27 20:28:06.291525 :C5779524:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 20:28:06.291526 :C5779525:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 20:28:06.291526 :C5779526:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 20:28:06.291527 :C5779527:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 20:28:06.291527 :C5779528:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 20:28:06.292036 :C5779529: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-27 20:28:06.292085 :C5779530: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-27 20:38:07.305247 :C5785965:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 20:38:07.638828 :C57859BB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 20:38:07.633 2025-08-27 20:38:07.638830 :C57859BC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19272 pso_num=22 pso_serial#=9 2025-08-27 20:38:07.639000 :C57859BD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19272 osp_idx=0 osp_ver=551901 osp_pg=0 (spawn #532297) 2025-08-27 20:38:07.639000 :C57859BE: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-27 20:38:07.639001 :C57859BF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=13 time=712738940 2025-08-27 20:38:07.639002 :C57859C0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 20:38:07.639002 :C57859C1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 20:38:07.639003 :C57859C2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 20:38:07.639003 :C57859C3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 20:38:07.639003 :C57859C4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 20:38:07.639536 :C57859C5: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-27 20:38:07.639593 :C57859CF: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-27 20:48:08.511271 :C5791D29:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 20:48:08.859927 :C5791D8F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 20:48:08.855 2025-08-27 20:48:08.859929 :C5791D90:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23148 pso_num=22 pso_serial#=10 2025-08-27 20:48:08.860064 :C5791D91:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23148 osp_idx=0 osp_ver=551902 osp_pg=0 (spawn #532320) 2025-08-27 20:48:08.860065 :C5791D92: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-27 20:48:08.860066 :C5791D93:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=14 time=713340158 2025-08-27 20:48:08.860066 :C5791D94:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 20:48:08.860066 :C5791D95:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 20:48:08.860066 :C5791D96:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 20:48:08.860067 :C5791D97:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 20:48:08.860067 :C5791D98:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 20:48:08.860593 :C5791D99: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-27 20:48:08.860644 :C5791D9F: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-27 20:58:09.733955 :C579E227:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 20:58:10.192008 :C579E284:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 20:58:10.187 2025-08-27 20:58:10.192010 :C579E285:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21804 pso_num=22 pso_serial#=11 2025-08-27 20:58:10.192157 :C579E286:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21804 osp_idx=0 osp_ver=551903 osp_pg=0 (spawn #532343) 2025-08-27 20:58:10.192157 :C579E287: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-27 20:58:10.192158 :C579E288:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=15 time=713941502 2025-08-27 20:58:10.192159 :C579E289:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 20:58:10.192159 :C579E28A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 20:58:10.192160 :C579E28B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 20:58:10.192160 :C579E28C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 20:58:10.192160 :C579E28D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 20:58:10.192668 :C579E28E: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-27 20:58:10.192716 :C579E296: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-27 21:08:11.113100 :C57AAD0E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 21:08:11.461713 :C57AAD5D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 21:08:11.457 2025-08-27 21:08:11.461715 :C57AAD5E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20004 pso_num=22 pso_serial#=12 2025-08-27 21:08:11.461850 :C57AAD5F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20004 osp_idx=0 osp_ver=551904 osp_pg=0 (spawn #532369) 2025-08-27 21:08:11.461851 :C57AAD60: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-27 21:08:11.461852 :C57AAD61:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=16 time=714542768 2025-08-27 21:08:11.461852 :C57AAD62:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 21:08:11.461852 :C57AAD63:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 21:08:11.461853 :C57AAD64:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 21:08:11.461853 :C57AAD65:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 21:08:11.461853 :C57AAD66:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 21:08:11.462342 :C57AAD67: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-27 21:08:11.462386 :C57AAD70: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-27 21:18:12.399268 :C57B73A5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 21:18:12.794646 :C57B73F9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 21:18:12.789 2025-08-27 21:18:12.794648 :C57B73FA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23032 pso_num=22 pso_serial#=13 2025-08-27 21:18:12.794782 :C57B73FB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23032 osp_idx=0 osp_ver=551905 osp_pg=0 (spawn #532391) 2025-08-27 21:18:12.794783 :C57B73FC: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-27 21:18:12.794783 :C57B73FD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=17 time=715144096 2025-08-27 21:18:12.794784 :C57B73FE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 21:18:12.794784 :C57B73FF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 21:18:12.794785 :C57B7400:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 21:18:12.794785 :C57B7401:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 21:18:12.794787 :C57B7402:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 21:18:12.795328 :C57B7403: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-27 21:18:12.795379 :C57B740D: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-27 21:18:27.790512 :C57B786E: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-27 21:18:27.790545 :C57B787B: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-27 21:18:27.790546 :C57B787C:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=32, exc=32, tot=32 2025-08-27 21:28:13.630069 :C57C36BA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 21:28:14.072330 :C57C3713:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 21:28:14.067 2025-08-27 21:28:14.072332 :C57C3714:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21584 pso_num=22 pso_serial#=14 2025-08-27 21:28:14.072466 :C57C3715:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21584 osp_idx=0 osp_ver=551906 osp_pg=0 (spawn #532414) 2025-08-27 21:28:14.072467 :C57C3716: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-27 21:28:14.072468 :C57C3717:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=18 time=715745377 2025-08-27 21:28:14.072468 :C57C3718:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 21:28:14.072468 :C57C3719:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 21:28:14.072469 :C57C371A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 21:28:14.072469 :C57C371B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 21:28:14.072469 :C57C371C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 21:28:14.072964 :C57C371D: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-27 21:28:14.073014 :C57C3724: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-27 21:38:14.904338 :C57CFAF3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 21:38:15.284089 :C57CFB43:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 21:38:15.279 2025-08-27 21:38:15.284091 :C57CFB44:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22444 pso_num=22 pso_serial#=15 2025-08-27 21:38:15.284227 :C57CFB45:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22444 osp_idx=0 osp_ver=551907 osp_pg=0 (spawn #532437) 2025-08-27 21:38:15.284228 :C57CFB46: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-27 21:38:15.284228 :C57CFB47:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=19 time=716346596 2025-08-27 21:38:15.284229 :C57CFB48:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 21:38:15.284230 :C57CFB49:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 21:38:15.284230 :C57CFB4A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 21:38:15.284230 :C57CFB4B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 21:38:15.284231 :C57CFB4C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 21:38:15.284736 :C57CFB4D: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-27 21:38:15.284780 :C57CFB54: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-27 21:48:16.160961 :C57DBDE0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 21:48:16.665960 :C57DBE3F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 21:48:16.660 2025-08-27 21:48:16.665962 :C57DBE40:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20816 pso_num=22 pso_serial#=16 2025-08-27 21:48:16.666106 :C57DBE41:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20816 osp_idx=0 osp_ver=551908 osp_pg=0 (spawn #532459) 2025-08-27 21:48:16.666107 :C57DBE42: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-27 21:48:16.666108 :C57DBE43:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=20 time=716947971 2025-08-27 21:48:16.666108 :C57DBE44:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 21:48:16.666108 :C57DBE45:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 21:48:16.666109 :C57DBE46:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 21:48:16.666109 :C57DBE47:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 21:48:16.666109 :C57DBE48:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 21:48:16.666633 :C57DBE49: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-27 21:48:16.666674 :C57DBE50: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-27 21:58:17.507979 :C57E81C8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-27 21:58:17.908452 :C57E821C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-27 21:58:17.903 2025-08-27 21:58:17.908454 :C57E821D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20680 pso_num=22 pso_serial#=17 2025-08-27 21:58:17.908589 :C57E821E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20680 osp_idx=0 osp_ver=551909 osp_pg=0 (spawn #532482) 2025-08-27 21:58:17.908590 :C57E821F: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-27 21:58:17.908590 :C57E8220:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=21 time=717549205 2025-08-27 21:58:17.908590 :C57E8221:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 21:58:17.908591 :C57E8222:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 21:58:17.908591 :C57E8223:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 21:58:17.908591 :C57E8224:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 21:58:17.908592 :C57E8225:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 21:58:17.909123 :C57E8226: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-27 21:58:17.909176 :C57E822E: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: 20680, W000)