Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250615220925\orcl_w000_15404_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:36633M/63366M, Ph+PgF:43105M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 15404, image: ORACLE.EXE (W000) *** 2025-06-15 22:09:26.013 *** SESSION ID:(201.25103) 2025-06-15 22:09:26.013 *** 2025-06-15 22:09:26.013 Process diagnostic dump for ORACLE.EXE (W000), OS id=15404, pid: 25, proc_ser: 82, sid: 201, sess_ser: 25103 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=4.261044 sec, exc=4.261044 sec, total=4.261044 sec wait times: max=5.000000 sec, heur=2 min 24 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.000027 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=5.000352 sec, exc=5.000352 sec, total=5.000352 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.002108 sec, exc=5.002108 sec, total=5.002108 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.008719 sec, exc=5.008719 sec, total=5.008719 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=29 seq_num=30 snap_id=1 wait times: snap=5.010152 sec, exc=5.010152 sec, total=5.010152 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=5.014746 sec, exc=5.014746 sec, total=5.014746 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=5.004551 sec, exc=5.004551 sec, total=5.004551 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000075 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.008445 sec, exc=5.008445 sec, total=5.008445 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.000582 sec, exc=5.000582 sec, total=5.000582 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=5.000913 sec, exc=5.000913 sec, total=5.000913 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.004605 sec, exc=5.004605 sec, total=5.004605 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time Sampled Session History of session 201 serial 25103 --------------------------------------------------- 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, 22:07:26 - 22:09:26] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-15 22:09:26.013 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 15404, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-15 19:36:28.384590 :A5248106:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15072 osp_idx=23 osp_ver=158536 osp_pg=0 (spawn #288825) 2025-06-15 19:36:28.384591 :A5248107:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 19:36:28.384592 :A5248108:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=164 time=2991931579 2025-06-15 19:36:28.384592 :A5248109:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 19:36:28.384593 :A524810A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 19:36:28.384593 :A524810B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 19:36:28.384593 :A524810C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 19:36:28.384594 :A524810D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 19:36:28.385099 :A524810E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 19:36:28.385147 :A5248115:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 19:40:50.988556 :A524D918:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 19:46:29.696096 :A525496C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 19:56:30.504802 :A5261233:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 19:56:31.066478 :A526129A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 19:56:31.062 2025-06-15 19:56:31.066480 :A526129B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3236 pso_num=25 pso_serial#=70 2025-06-15 19:56:31.066671 :A526129C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=3236 osp_idx=23 osp_ver=158537 osp_pg=0 (spawn #288869) 2025-06-15 19:56:31.066671 :A526129D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 19:56:31.066672 :A526129E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=165 time=2993134250 2025-06-15 19:56:31.066672 :A526129F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 19:56:31.066673 :A52612A0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 19:56:31.066673 :A52612A1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 19:56:31.066673 :A52612A2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 19:56:31.066673 :A52612A3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 19:56:31.067174 :A52612A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 19:56:31.067223 :A52612AE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 20:06:31.882916 :A526E45A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 20:06:32.278102 :A526E49B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 20:06:32.273 2025-06-15 20:06:32.278105 :A526E49C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3448 pso_num=25 pso_serial#=71 2025-06-15 20:06:32.278238 :A526E49D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=3448 osp_idx=23 osp_ver=158538 osp_pg=0 (spawn #288895) 2025-06-15 20:06:32.278238 :A526E49E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 20:06:32.278239 :A526E49F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=166 time=2993735469 2025-06-15 20:06:32.278239 :A526E4A0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 20:06:32.278240 :A526E4A1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 20:06:32.278240 :A526E4A2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 20:06:32.278240 :A526E4A3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 20:06:32.278241 :A526E4A4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 20:06:32.278717 :A526E4A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 20:06:32.278761 :A526E4AC:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 20:16:33.128314 :A527B007:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 20:16:33.554914 :A527B055:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 20:16:33.550 2025-06-15 20:16:33.554916 :A527B056:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17112 pso_num=25 pso_serial#=72 2025-06-15 20:16:33.555063 :A527B057:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17112 osp_idx=23 osp_ver=158539 osp_pg=0 (spawn #288917) 2025-06-15 20:16:33.555064 :A527B058:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 20:16:33.555065 :A527B059:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=167 time=2994336750 2025-06-15 20:16:33.555065 :A527B05A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 20:16:33.555065 :A527B05B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 20:16:33.555066 :A527B05C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 20:16:33.555066 :A527B05D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 20:16:33.555067 :A527B05E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 20:16:33.555577 :A527B05F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 20:16:33.555622 :A527B067:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 20:26:34.390858 :A5287958:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 20:26:34.749384 :A528798F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 20:26:34.744 2025-06-15 20:26:34.749386 :A5287990:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17036 pso_num=25 pso_serial#=73 2025-06-15 20:26:34.749525 :A5287991:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17036 osp_idx=23 osp_ver=158540 osp_pg=0 (spawn #288940) 2025-06-15 20:26:34.749526 :A5287992:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 20:26:34.749527 :A5287993:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=168 time=2994937938 2025-06-15 20:26:34.749527 :A5287994:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 20:26:34.749527 :A5287995:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 20:26:34.749528 :A5287996:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 20:26:34.749528 :A5287997:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 20:26:34.749528 :A5287998:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 20:26:34.750017 :A5287999:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 20:26:34.750064 :A52879A1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 20:36:35.557085 :A5294398:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 20:36:36.014960 :A52943D1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 20:36:36.010 2025-06-15 20:36:36.014962 :A52943D2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15660 pso_num=25 pso_serial#=74 2025-06-15 20:36:36.015099 :A52943D3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15660 osp_idx=23 osp_ver=158541 osp_pg=0 (spawn #288963) 2025-06-15 20:36:36.015100 :A52943D4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 20:36:36.015100 :A52943D5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=169 time=2995539204 2025-06-15 20:36:36.015101 :A52943D6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 20:36:36.015101 :A52943D7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 20:36:36.015102 :A52943D8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 20:36:36.015102 :A52943D9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 20:36:36.015102 :A52943DA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 20:36:36.015600 :A52943DB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 20:36:36.015644 :A52943E2:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 20:46:36.954153 :A52A0DF2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 20:46:37.130990 :A52A0E30:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 20:46:37.126 2025-06-15 20:46:37.130992 :A52A0E31:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9584 pso_num=25 pso_serial#=75 2025-06-15 20:46:37.131129 :A52A0E32:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9584 osp_idx=23 osp_ver=158542 osp_pg=0 (spawn #288985) 2025-06-15 20:46:37.131130 :A52A0E33:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 20:46:37.131130 :A52A0E34:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=170 time=2996140329 2025-06-15 20:46:37.131130 :A52A0E35:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 20:46:37.131131 :A52A0E36:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 20:46:37.131131 :A52A0E37:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 20:46:37.131131 :A52A0E38:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 20:46:37.131132 :A52A0E39:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 20:46:37.131620 :A52A0E3A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 20:46:37.131673 :A52A0E44:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 20:56:37.993773 :A52AD7F4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 20:56:38.326475 :A52AD82E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 20:56:38.322 2025-06-15 20:56:38.326476 :A52AD82F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14196 pso_num=25 pso_serial#=76 2025-06-15 20:56:38.326613 :A52AD830:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14196 osp_idx=23 osp_ver=158543 osp_pg=0 (spawn #289008) 2025-06-15 20:56:38.326614 :A52AD831:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 20:56:38.326614 :A52AD832:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=171 time=2996741516 2025-06-15 20:56:38.326615 :A52AD833:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 20:56:38.326615 :A52AD834:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 20:56:38.326615 :A52AD835:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 20:56:38.326615 :A52AD836:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 20:56:38.326616 :A52AD837:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 20:56:38.327096 :A52AD838:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 20:56:38.327140 :A52AD840:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 21:06:39.216695 :A52BAA0D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 21:06:39.471442 :A52BAA4A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 21:06:39.466 2025-06-15 21:06:39.471444 :A52BAA4B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15496 pso_num=25 pso_serial#=77 2025-06-15 21:06:39.471583 :A52BAA4C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15496 osp_idx=23 osp_ver=158544 osp_pg=0 (spawn #289034) 2025-06-15 21:06:39.471583 :A52BAA4D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 21:06:39.471584 :A52BAA4E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=172 time=2997342657 2025-06-15 21:06:39.471584 :A52BAA4F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 21:06:39.471584 :A52BAA50:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 21:06:39.471585 :A52BAA51:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 21:06:39.471585 :A52BAA52:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 21:06:39.471585 :A52BAA53:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 21:06:39.472081 :A52BAA54:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 21:06:39.472129 :A52BAA5C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 21:16:40.305115 :A52C757D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 21:16:40.637943 :A52C75B9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 21:16:40.633 2025-06-15 21:16:40.637945 :A52C75BA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16012 pso_num=25 pso_serial#=78 2025-06-15 21:16:40.638083 :A52C75BB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16012 osp_idx=23 osp_ver=158545 osp_pg=0 (spawn #289056) 2025-06-15 21:16:40.638084 :A52C75BC:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 21:16:40.638085 :A52C75BD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=173 time=2997943829 2025-06-15 21:16:40.638085 :A52C75BE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 21:16:40.638086 :A52C75BF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 21:16:40.638086 :A52C75C0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 21:16:40.638086 :A52C75C1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 21:16:40.638086 :A52C75C2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 21:16:40.638589 :A52C75C3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 21:16:40.638636 :A52C75CB:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 21:26:41.578194 :A52D3E2B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 21:26:41.833044 :A52D3E6A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 21:26:41.828 2025-06-15 21:26:41.833046 :A52D3E6B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17020 pso_num=25 pso_serial#=79 2025-06-15 21:26:41.833194 :A52D3E6C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17020 osp_idx=23 osp_ver=158546 osp_pg=0 (spawn #289079) 2025-06-15 21:26:41.833195 :A52D3E6D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 21:26:41.833196 :A52D3E6E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=174 time=2998545016 2025-06-15 21:26:41.833196 :A52D3E6F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 21:26:41.833196 :A52D3E70:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 21:26:41.833197 :A52D3E71:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 21:26:41.833197 :A52D3E72:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 21:26:41.833197 :A52D3E73:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 21:26:41.833713 :A52D3E74:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 21:26:41.833762 :A52D3E7B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 21:36:42.663081 :A52E08BA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 21:36:42.964791 :A52E08F8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 21:36:42.959 2025-06-15 21:36:42.964793 :A52E08F9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14976 pso_num=25 pso_serial#=80 2025-06-15 21:36:42.964931 :A52E08FA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14976 osp_idx=23 osp_ver=158547 osp_pg=0 (spawn #289102) 2025-06-15 21:36:42.964932 :A52E08FB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 21:36:42.964932 :A52E08FC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=175 time=2999146157 2025-06-15 21:36:42.964933 :A52E08FD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 21:36:42.964933 :A52E08FE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 21:36:42.964933 :A52E08FF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 21:36:42.964934 :A52E0900:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 21:36:42.964934 :A52E0901:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 21:36:42.965439 :A52E0902:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 21:36:42.965482 :A52E090A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 21:40:51.669413 :A52E5C53:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 21:46:44.118504 :A52ED184:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 21:56:45.073997 :A52F9A57:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 21:56:45.297472 :A52F9A90:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 21:56:45.293 2025-06-15 21:56:45.297474 :A52F9A91:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16940 pso_num=25 pso_serial#=81 2025-06-15 21:56:45.297613 :A52F9A92:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16940 osp_idx=23 osp_ver=158548 osp_pg=0 (spawn #289146) 2025-06-15 21:56:45.297614 :A52F9A93:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 21:56:45.297615 :A52F9A94:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=176 time=3000348485 2025-06-15 21:56:45.297615 :A52F9A95:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 21:56:45.297615 :A52F9A96:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 21:56:45.297616 :A52F9A97:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 21:56:45.297616 :A52F9A98:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 21:56:45.297616 :A52F9A99:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 21:56:45.298113 :A52F9A9A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 21:56:45.298157 :A52F9AA2:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 22:06:46.202578 :A5306BDD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-15 22:06:46.582396 :A5306C1A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-15 22:06:46.578 2025-06-15 22:06:46.582398 :A5306C1B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15404 pso_num=25 pso_serial#=82 2025-06-15 22:06:46.582533 :A5306C1C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15404 osp_idx=23 osp_ver=158549 osp_pg=0 (spawn #289172) 2025-06-15 22:06:46.582534 :A5306C1D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-15 22:06:46.582534 :A5306C1E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=177 time=3000949766 2025-06-15 22:06:46.582535 :A5306C1F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-15 22:06:46.582535 :A5306C20:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-15 22:06:46.582535 :A5306C21:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-15 22:06:46.582536 :A5306C22:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-15 22:06:46.582536 :A5306C23:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-15 22:06:46.583024 :A5306C24:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-15 22:06:46.583067 :A5306C2B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-06-15 22:07:01.593229 :A5307104:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-15 22:07:01.593250 :A530710E:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-15 22:07:01.593252 :A530710F:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=19, exc=19, tot=19 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 15404, W000)