Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250511140405\orcl_w000_9512_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:37501M/63366M, Ph+PgF:44893M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 9512, image: ORACLE.EXE (W000) *** 2025-05-11 14:04:05.109 *** SESSION ID:(209.37497) 2025-05-11 14:04:05.109 *** 2025-05-11 14:04:05.109 Process diagnostic dump for ORACLE.EXE (W000), OS id=9512, pid: 26, proc_ser: 241, sid: 209, sess_ser: 37497 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=81 seq_num=82 snap_id=1 wait times: snap=2.370122 sec, exc=2.370122 sec, total=2.370122 sec wait times: max=5.000000 sec, heur=6 min 42 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=80 seq_num=81 snap_id=1 wait times: snap=5.011392 sec, exc=5.011392 sec, total=5.011392 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=79 seq_num=80 snap_id=1 wait times: snap=5.002077 sec, exc=5.002077 sec, total=5.002077 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=78 seq_num=79 snap_id=1 wait times: snap=5.004620 sec, exc=5.004620 sec, total=5.004620 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.004221 sec, exc=5.004221 sec, total=5.004221 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=76 seq_num=77 snap_id=1 wait times: snap=5.002130 sec, exc=5.002130 sec, total=5.002130 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=75 seq_num=76 snap_id=1 wait times: snap=5.001400 sec, exc=5.001400 sec, total=5.001400 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=74 seq_num=75 snap_id=1 wait times: snap=5.000277 sec, exc=5.000277 sec, total=5.000277 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=73 seq_num=74 snap_id=1 wait times: snap=5.010489 sec, exc=5.010489 sec, total=5.010489 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=72 seq_num=73 snap_id=1 wait times: snap=5.006315 sec, exc=5.006315 sec, total=5.006315 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=71 seq_num=72 snap_id=1 wait times: snap=5.014719 sec, exc=5.014719 sec, total=5.014719 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 209 serial 37497 --------------------------------------------------- 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, 14:02:05 - 14:04:05] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-11 14:04:05.109 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 9512, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-11 11:36:19.074226 :95A2E258:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 11:37:03.735026 :95A2F0A7:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 11:37:03.730 2025-05-11 11:37:03.735028 :95A2F0A8:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11916 pso_num=26 pso_serial#=228 2025-05-11 11:37:03.735164 :95A2F0A9:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11916 osp_idx=24 osp_ver=247067 osp_pg=0 (spawn #171003) 2025-05-11 11:37:03.735164 :95A2F0AA:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 11:37:03.735165 :95A2F0AB:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=242 time=4234200906 2025-05-11 11:37:03.735165 :95A2F0AC:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 11:37:03.735166 :95A2F0AD:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 11:37:03.735166 :95A2F0AE:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 11:37:03.735166 :95A2F0AF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 11:37:03.735167 :95A2F0B0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 11:37:03.735660 :95A2F0B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 11:37:03.735705 :95A2F0B9:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 11:47:04.686617 :95A3B3FB:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 11:47:05.035048 :95A3B442:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 11:47:05.030 2025-05-11 11:47:05.035050 :95A3B443:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=5024 pso_num=26 pso_serial#=229 2025-05-11 11:47:05.035197 :95A3B444:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=5024 osp_idx=24 osp_ver=247068 osp_pg=0 (spawn #171026) 2025-05-11 11:47:05.035198 :95A3B445:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 11:47:05.035198 :95A3B446:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=243 time=4234802203 2025-05-11 11:47:05.035199 :95A3B447:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 11:47:05.035199 :95A3B448:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 11:47:05.035199 :95A3B449:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 11:47:05.035200 :95A3B44A:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 11:47:05.035200 :95A3B44B:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 11:47:05.035729 :95A3B44C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 11:47:05.035777 :95A3B454:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 11:57:05.979218 :95A47681:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 11:57:06.324617 :95A476CA:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 11:57:06.320 2025-05-11 11:57:06.324619 :95A476CB:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11920 pso_num=26 pso_serial#=230 2025-05-11 11:57:06.324761 :95A476CC:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11920 osp_idx=24 osp_ver=247069 osp_pg=0 (spawn #171049) 2025-05-11 11:57:06.324762 :95A476CD:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 11:57:06.324762 :95A476CE:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=244 time=4235403484 2025-05-11 11:57:06.324762 :95A476CF:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 11:57:06.324763 :95A476D0:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 11:57:06.324764 :95A476D1:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 11:57:06.324764 :95A476D2:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 11:57:06.324764 :95A476D3:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 11:57:06.325270 :95A476D4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 11:57:06.325318 :95A476DB:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 12:07:07.208758 :95A54217:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 12:07:07.604095 :95A54269:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 12:07:07.599 2025-05-11 12:07:07.604097 :95A5426A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11648 pso_num=26 pso_serial#=231 2025-05-11 12:07:07.604237 :95A5426B:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11648 osp_idx=24 osp_ver=247070 osp_pg=0 (spawn #171076) 2025-05-11 12:07:07.604237 :95A5426C:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 12:07:07.604238 :95A5426D:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=245 time=4236004765 2025-05-11 12:07:07.604238 :95A5426E:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 12:07:07.604239 :95A5426F:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 12:07:07.604239 :95A54270:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 12:07:07.604239 :95A54271:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 12:07:07.604240 :95A54272:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 12:07:07.604729 :95A54273:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 12:07:07.604774 :95A5427B:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 12:17:08.467385 :95A60500:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 12:17:08.925394 :95A60551:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 12:17:08.920 2025-05-11 12:17:08.925396 :95A60552:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12064 pso_num=26 pso_serial#=232 2025-05-11 12:17:08.925543 :95A60553:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12064 osp_idx=24 osp_ver=247071 osp_pg=0 (spawn #171099) 2025-05-11 12:17:08.925543 :95A60554:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 12:17:08.925544 :95A60555:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=246 time=4236606093 2025-05-11 12:17:08.925544 :95A60556:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 12:17:08.925544 :95A60557:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 12:17:08.925545 :95A60558:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 12:17:08.925545 :95A60559:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 12:17:08.925545 :95A6055A:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 12:17:08.926075 :95A6055B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 12:17:08.926119 :95A60562:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 12:25:32.680661 :95A6AB4E:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 12:27:10.246847 :95A6CB67:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 12:37:11.166185 :95A78ED8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 12:37:11.639247 :95A78F1E:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 12:37:11.635 2025-05-11 12:37:11.639249 :95A78F1F:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11708 pso_num=26 pso_serial#=233 2025-05-11 12:37:11.639423 :95A78F20:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11708 osp_idx=24 osp_ver=247072 osp_pg=0 (spawn #171144) 2025-05-11 12:37:11.639423 :95A78F21:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 12:37:11.639424 :95A78F22:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=247 time=4237808812 2025-05-11 12:37:11.639424 :95A78F23:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 12:37:11.639424 :95A78F24:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 12:37:11.639425 :95A78F25:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 12:37:11.639425 :95A78F26:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 12:37:11.639425 :95A78F27:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 12:37:11.639939 :95A78F28:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 12:37:11.639987 :95A78F32:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 12:47:12.513206 :95A8526E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 12:47:12.846183 :95A852E6:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 12:47:12.841 2025-05-11 12:47:12.846185 :95A852E7:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12508 pso_num=26 pso_serial#=234 2025-05-11 12:47:12.846324 :95A852E8:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12508 osp_idx=24 osp_ver=247073 osp_pg=0 (spawn #171167) 2025-05-11 12:47:12.846325 :95A852E9:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 12:47:12.846326 :95A852EA:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=248 time=4238410015 2025-05-11 12:47:12.846326 :95A852EB:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 12:47:12.846327 :95A852EC:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 12:47:12.846327 :95A852ED:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 12:47:12.846327 :95A852EE:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 12:47:12.846328 :95A852EF:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 12:47:12.846845 :95A852F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 12:47:12.846893 :95A852F7:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 12:47:42.892679 :95A85C46:db_trace:ksl2.c@2477:kslwtbctx(): [10005:26:209] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-11 12:47:42.892707 :95A85C50:db_trace:ksl2.c@2611:kslwtectx(): [10005:26:209] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-11 12:47:42.892709 :95A85C53:db_trace:ksl2.c@2619:kslwtectx(): [10005:26:209] KSL WAIT END wait times (usecs) - snap=32, exc=32, tot=32 2025-05-11 12:57:13.719201 :95A915DF:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 12:57:14.161398 :95A91650:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 12:57:14.156 2025-05-11 12:57:14.161400 :95A91651:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9112 pso_num=26 pso_serial#=235 2025-05-11 12:57:14.161541 :95A91652:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9112 osp_idx=24 osp_ver=247074 osp_pg=0 (spawn #171190) 2025-05-11 12:57:14.161542 :95A91653:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 12:57:14.161542 :95A91654:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=249 time=4239011328 2025-05-11 12:57:14.161542 :95A91655:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 12:57:14.161543 :95A91656:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 12:57:14.161543 :95A91657:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 12:57:14.161544 :95A91658:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 12:57:14.161544 :95A91659:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 12:57:14.162043 :95A9165A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 12:57:14.162087 :95A91662:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 13:07:15.068095 :95A9E3F8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 13:07:15.463358 :95A9E46F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 13:07:15.458 2025-05-11 13:07:15.463360 :95A9E470:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9960 pso_num=26 pso_serial#=236 2025-05-11 13:07:15.463494 :95A9E471:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9960 osp_idx=24 osp_ver=247075 osp_pg=0 (spawn #171218) 2025-05-11 13:07:15.463495 :95A9E472:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 13:07:15.463495 :95A9E473:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=250 time=4239612625 2025-05-11 13:07:15.463495 :95A9E474:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 13:07:15.463496 :95A9E475:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 13:07:15.463496 :95A9E476:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 13:07:15.463497 :95A9E477:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 13:07:15.463497 :95A9E478:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 13:07:15.464008 :95A9E479:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 13:07:15.464053 :95A9E481:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 13:17:16.327711 :95AAA694:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 13:17:16.754427 :95AAA6DD:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 13:17:16.749 2025-05-11 13:17:16.754430 :95AAA6DE:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=8936 pso_num=26 pso_serial#=237 2025-05-11 13:17:16.754574 :95AAA6DF:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=8936 osp_idx=24 osp_ver=247076 osp_pg=0 (spawn #171241) 2025-05-11 13:17:16.754574 :95AAA6E0:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 13:17:16.754575 :95AAA6E1:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=251 time=4240213921 2025-05-11 13:17:16.754575 :95AAA6E2:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 13:17:16.754575 :95AAA6E3:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 13:17:16.754576 :95AAA6E4:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 13:17:16.754576 :95AAA6E5:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 13:17:16.754576 :95AAA6E6:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 13:17:16.755081 :95AAA6E7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 13:17:16.755124 :95AAA6EE:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 13:27:17.686600 :95AB6C67:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 13:27:18.066460 :95AB6CAE:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 13:27:18.061 2025-05-11 13:27:18.066461 :95AB6CAF:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11536 pso_num=26 pso_serial#=238 2025-05-11 13:27:18.066604 :95AB6CB0:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11536 osp_idx=24 osp_ver=247077 osp_pg=0 (spawn #171264) 2025-05-11 13:27:18.066604 :95AB6CB1:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 13:27:18.066605 :95AB6CB2:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=252 time=4240815234 2025-05-11 13:27:18.066605 :95AB6CB3:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 13:27:18.066606 :95AB6CB4:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 13:27:18.066606 :95AB6CB5:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 13:27:18.066607 :95AB6CB6:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 13:27:18.066607 :95AB6CB7:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 13:27:18.067115 :95AB6CB8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 13:27:18.067164 :95AB6CC0:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 13:37:18.960740 :95AC2FBF:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 13:37:19.434275 :95AC3029:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 13:37:19.430 2025-05-11 13:37:19.434276 :95AC302A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13244 pso_num=26 pso_serial#=239 2025-05-11 13:37:19.434411 :95AC302B:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13244 osp_idx=24 osp_ver=247078 osp_pg=0 (spawn #171286) 2025-05-11 13:37:19.434412 :95AC302C:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 13:37:19.434413 :95AC302D:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=253 time=4241416593 2025-05-11 13:37:19.434413 :95AC302E:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 13:37:19.434414 :95AC302F:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 13:37:19.434415 :95AC3030:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 13:37:19.434415 :95AC3031:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 13:37:19.434415 :95AC3032:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 13:37:19.434939 :95AC3033:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 13:37:19.434994 :95AC303C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 13:47:20.260852 :95ACF346:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 13:47:20.812213 :95ACF3A2:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 13:47:20.808 2025-05-11 13:47:20.812215 :95ACF3A3:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=8392 pso_num=26 pso_serial#=240 2025-05-11 13:47:20.812346 :95ACF3A4:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=8392 osp_idx=24 osp_ver=247079 osp_pg=0 (spawn #171309) 2025-05-11 13:47:20.812347 :95ACF3A5:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 13:47:20.812347 :95ACF3A6:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=254 time=4242017984 2025-05-11 13:47:20.812348 :95ACF3A7:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 13:47:20.812348 :95ACF3A8:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 13:47:20.812348 :95ACF3A9:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 13:47:20.812349 :95ACF3AA:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 13:47:20.812349 :95ACF3AB:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 13:47:20.812841 :95ACF3AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 13:47:20.812886 :95ACF3B4:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-11 13:57:21.735738 :95ADB68F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 13:57:22.188163 :95ADB6F2:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 13:57:22.183 2025-05-11 13:57:22.188166 :95ADB6F3:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9512 pso_num=26 pso_serial#=241 2025-05-11 13:57:22.188305 :95ADB6F4:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9512 osp_idx=24 osp_ver=247080 osp_pg=0 (spawn #171332) 2025-05-11 13:57:22.188306 :95ADB6F5:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 13:57:22.188306 :95ADB6F6:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=255 time=4242619359 2025-05-11 13:57:22.188306 :95ADB6F7:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 13:57:22.188307 :95ADB6F8:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 13:57:22.188307 :95ADB6F9:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 13:57:22.188308 :95ADB6FA:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 13:57:22.188308 :95ADB6FB:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 13:57:22.188796 :95ADB6FC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 13:57:22.188841 :95ADB704:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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 26 (osid: 9512, W000)