Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250523220010\orcl_w000_13400_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:37321M/63366M, Ph+PgF:44395M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13400, image: ORACLE.EXE (W000) *** 2025-05-23 22:00:10.678 *** SESSION ID:(177.7351) 2025-05-23 22:00:10.678 *** 2025-05-23 22:00:10.678 Process diagnostic dump for ORACLE.EXE (W000), OS id=13400, pid: 22, proc_ser: 7, sid: 177, sess_ser: 7351 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=36 seq_num=37 snap_id=1 wait times: snap=2.239280 sec, exc=2.239280 sec, total=2.239280 sec wait times: max=5.000000 sec, heur=2 min 22 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=35 seq_num=36 snap_id=1 wait times: snap=5.010599 sec, exc=5.010599 sec, total=5.010599 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=34 seq_num=35 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.000027 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=5.014722 sec, exc=5.014722 sec, total=5.014722 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 3: 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.005142 sec, exc=5.005142 sec, total=5.005142 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 4: 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.003327 sec, exc=5.003327 sec, total=5.003327 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=30 seq_num=31 snap_id=1 wait times: snap=5.014699 sec, exc=5.014699 sec, total=5.014699 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 6: 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.003883 sec, exc=5.003883 sec, total=5.003883 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 7: 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.004629 sec, exc=5.004629 sec, total=5.004629 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 8: 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.014758 sec, exc=5.014758 sec, total=5.014758 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 9: 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.004635 sec, exc=5.004635 sec, total=5.004635 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time Sampled Session History of session 177 serial 7351 --------------------------------------------------- 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, 21:58:10 - 22:00:10] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-23 22:00:10.678 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13400, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-23 19:26:57.646713 :9B0D7B46:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13412 osp_idx=0 osp_ver=228219 osp_pg=0 (spawn #212154) 2025-05-23 19:26:57.646714 :9B0D7B47:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 19:26:57.646714 :9B0D7B48:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=205 time=1004189907 2025-05-23 19:26:57.646714 :9B0D7B49:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 19:26:57.646715 :9B0D7B4A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 19:26:57.646715 :9B0D7B4B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 19:26:57.646716 :9B0D7B4C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 19:26:57.646716 :9B0D7B4D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 19:26:57.647277 :9B0D7B4E: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-05-23 19:26:57.647320 :9B0D7B56: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-05-23 19:36:58.585352 :9B0E3DCE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 19:36:59.152530 :9B0E3E1D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 19:36:59.147 2025-05-23 19:36:59.152531 :9B0E3E1E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14280 pso_num=22 pso_serial#=250 2025-05-23 19:36:59.152662 :9B0E3E1F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14280 osp_idx=0 osp_ver=228220 osp_pg=0 (spawn #212174) 2025-05-23 19:36:59.152663 :9B0E3E20:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 19:36:59.152663 :9B0E3E21:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=206 time=1004791407 2025-05-23 19:36:59.152663 :9B0E3E22:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 19:36:59.152664 :9B0E3E23:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 19:36:59.152664 :9B0E3E24:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 19:36:59.152664 :9B0E3E25:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 19:36:59.152665 :9B0E3E26:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 19:36:59.153154 :9B0E3E27: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-05-23 19:36:59.153200 :9B0E3E2E: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-05-23 19:39:27.530841 :9B0E6DBB: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-05-23 19:47:00.630499 :9B0F0126: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-05-23 19:57:01.593014 :9B0FC3D7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 19:57:02.097651 :9B0FC423:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 19:57:02.092 2025-05-23 19:57:02.097653 :9B0FC424:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9648 pso_num=22 pso_serial#=251 2025-05-23 19:57:02.097790 :9B0FC425:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9648 osp_idx=0 osp_ver=228221 osp_pg=0 (spawn #212219) 2025-05-23 19:57:02.097791 :9B0FC426:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 19:57:02.097792 :9B0FC427:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=207 time=1005994344 2025-05-23 19:57:02.097792 :9B0FC428:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 19:57:02.097792 :9B0FC429:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 19:57:02.097793 :9B0FC42A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 19:57:02.097793 :9B0FC42B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 19:57:02.097794 :9B0FC42C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 19:57:02.098294 :9B0FC42D: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-05-23 19:57:02.098339 :9B0FC435: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-05-23 20:07:03.043638 :9B108D9E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 20:07:03.407855 :9B108DEE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 20:07:03.403 2025-05-23 20:07:03.407858 :9B108DEF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13024 pso_num=22 pso_serial#=252 2025-05-23 20:07:03.408002 :9B108DF0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13024 osp_idx=0 osp_ver=228222 osp_pg=0 (spawn #212244) 2025-05-23 20:07:03.408003 :9B108DF1:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 20:07:03.408004 :9B108DF2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=208 time=1006595657 2025-05-23 20:07:03.408004 :9B108DF3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 20:07:03.408005 :9B108DF4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 20:07:03.408005 :9B108DF5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 20:07:03.408005 :9B108DF6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 20:07:03.408006 :9B108DF7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 20:07:03.408506 :9B108DF8: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-05-23 20:07:03.408552 :9B108DFF: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-05-23 20:17:04.347899 :9B11505A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 20:17:04.837001 :9B1150A8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 20:17:04.832 2025-05-23 20:17:04.837003 :9B1150A9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11092 pso_num=22 pso_serial#=253 2025-05-23 20:17:04.837143 :9B1150AA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11092 osp_idx=0 osp_ver=228223 osp_pg=0 (spawn #212267) 2025-05-23 20:17:04.837143 :9B1150AB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 20:17:04.837144 :9B1150AC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=209 time=1007197094 2025-05-23 20:17:04.837144 :9B1150AD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 20:17:04.837145 :9B1150AE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 20:17:04.837145 :9B1150AF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 20:17:04.837145 :9B1150B0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 20:17:04.837145 :9B1150B1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 20:17:04.837640 :9B1150B2: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-05-23 20:17:04.837687 :9B1150BC: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-05-23 20:27:05.766935 :9B1215A8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 20:27:06.177976 :9B1215F0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 20:27:06.173 2025-05-23 20:27:06.177978 :9B1215F1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13532 pso_num=22 pso_serial#=254 2025-05-23 20:27:06.178140 :9B1215F2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13532 osp_idx=0 osp_ver=228224 osp_pg=0 (spawn #212290) 2025-05-23 20:27:06.178141 :9B1215F3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 20:27:06.178141 :9B1215F4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=210 time=1007798438 2025-05-23 20:27:06.178142 :9B1215F5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 20:27:06.178142 :9B1215F6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 20:27:06.178142 :9B1215F7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 20:27:06.178143 :9B1215F8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 20:27:06.178143 :9B1215F9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 20:27:06.178661 :9B1215FA: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-05-23 20:27:06.178707 :9B121601: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-05-23 20:37:07.203852 :9B12DA9E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 20:37:07.567848 :9B12DAD4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 20:37:07.563 2025-05-23 20:37:07.567851 :9B12DAD5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4660 pso_num=22 pso_serial#=255 2025-05-23 20:37:07.567990 :9B12DAD6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4660 osp_idx=0 osp_ver=228225 osp_pg=0 (spawn #212310) 2025-05-23 20:37:07.567991 :9B12DAD7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 20:37:07.567991 :9B12DAD8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=211 time=1008399829 2025-05-23 20:37:07.567992 :9B12DAD9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 20:37:07.567992 :9B12DADA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 20:37:07.567992 :9B12DADB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 20:37:07.567993 :9B12DADC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 20:37:07.567993 :9B12DADD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 20:37:07.568500 :9B12DADE: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-05-23 20:37:07.568551 :9B12DAE8: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-05-23 20:47:08.523597 :9B13A029:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 20:47:08.897861 :9B13A06E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 20:47:08.893 2025-05-23 20:47:08.897864 :9B13A06F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13612 pso_num=22 pso_serial#=1 2025-05-23 20:47:08.898003 :9B13A070:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13612 osp_idx=0 osp_ver=228226 osp_pg=0 (spawn #212333) 2025-05-23 20:47:08.898004 :9B13A071:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 20:47:08.898004 :9B13A072:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=212 time=1009001157 2025-05-23 20:47:08.898005 :9B13A073:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 20:47:08.898005 :9B13A074:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 20:47:08.898005 :9B13A075:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 20:47:08.898006 :9B13A076:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 20:47:08.898006 :9B13A077:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 20:47:08.898526 :9B13A078: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-05-23 20:47:08.898576 :9B13A07F: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-05-23 20:57:09.841545 :9B1464D4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 20:57:10.236797 :9B146547:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 20:57:10.232 2025-05-23 20:57:10.236799 :9B146548:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11320 pso_num=22 pso_serial#=2 2025-05-23 20:57:10.236935 :9B146549:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11320 osp_idx=0 osp_ver=228227 osp_pg=0 (spawn #212356) 2025-05-23 20:57:10.236937 :9B14654A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 20:57:10.236937 :9B14654B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=213 time=1009602485 2025-05-23 20:57:10.236938 :9B14654C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 20:57:10.236938 :9B14654D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 20:57:10.236938 :9B14654E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 20:57:10.236939 :9B14654F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 20:57:10.236939 :9B146550:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 20:57:10.237422 :9B146551: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-05-23 20:57:10.237474 :9B14655B: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-05-23 21:07:11.252741 :9B153304:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 21:07:11.491780 :9B15333A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 21:07:11.487 2025-05-23 21:07:11.491782 :9B15333B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12276 pso_num=22 pso_serial#=3 2025-05-23 21:07:11.491917 :9B15333C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12276 osp_idx=0 osp_ver=228228 osp_pg=0 (spawn #212381) 2025-05-23 21:07:11.491918 :9B15333D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 21:07:11.491918 :9B15333E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=214 time=1010203750 2025-05-23 21:07:11.491918 :9B15333F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 21:07:11.491919 :9B153340:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 21:07:11.491919 :9B153341:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 21:07:11.491919 :9B153342:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 21:07:11.491920 :9B153343:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 21:07:11.492401 :9B153344: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-05-23 21:07:11.492447 :9B15334B: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-05-23 21:17:12.577885 :9B15F7E9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 21:17:12.848260 :9B15F854:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 21:17:12.843 2025-05-23 21:17:12.848262 :9B15F855:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11628 pso_num=22 pso_serial#=4 2025-05-23 21:17:12.848402 :9B15F856:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11628 osp_idx=0 osp_ver=228229 osp_pg=0 (spawn #212404) 2025-05-23 21:17:12.848403 :9B15F857:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 21:17:12.848403 :9B15F858:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=215 time=1010805110 2025-05-23 21:17:12.848403 :9B15F859:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 21:17:12.848404 :9B15F85A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 21:17:12.848404 :9B15F85B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 21:17:12.848405 :9B15F85C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 21:17:12.848405 :9B15F85D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 21:17:12.848923 :9B15F85E: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-05-23 21:17:12.848973 :9B15F865: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-05-23 21:27:13.905989 :9B16BF94:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 21:27:14.176297 :9B16BFD0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 21:27:14.171 2025-05-23 21:27:14.176299 :9B16BFD1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13612 pso_num=22 pso_serial#=5 2025-05-23 21:27:14.176434 :9B16BFD2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13612 osp_idx=0 osp_ver=228230 osp_pg=0 (spawn #212427) 2025-05-23 21:27:14.176435 :9B16BFD3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 21:27:14.176435 :9B16BFD4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=216 time=1011406438 2025-05-23 21:27:14.176436 :9B16BFD5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 21:27:14.176436 :9B16BFD6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 21:27:14.176436 :9B16BFD7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 21:27:14.176437 :9B16BFD8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 21:27:14.176437 :9B16BFD9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 21:27:14.176933 :9B16BFDA: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-05-23 21:27:14.176981 :9B16BFE4: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-05-23 21:37:15.181555 :9B178281:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 21:37:15.530019 :9B1782D5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 21:37:15.525 2025-05-23 21:37:15.530021 :9B1782D6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=580 pso_num=22 pso_serial#=6 2025-05-23 21:37:15.530202 :9B1782D7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=580 osp_idx=0 osp_ver=228231 osp_pg=0 (spawn #212447) 2025-05-23 21:37:15.530203 :9B1782D8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 21:37:15.530203 :9B1782D9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=217 time=1012007782 2025-05-23 21:37:15.530204 :9B1782DA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 21:37:15.530204 :9B1782DB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 21:37:15.530204 :9B1782DC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 21:37:15.530205 :9B1782DD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 21:37:15.530205 :9B1782DE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 21:37:15.530714 :9B1782DF: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-05-23 21:37:15.530759 :9B1782E7: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-05-23 21:44:28.122464 :9B180D56: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-05-23 21:47:16.867897 :9B184352: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-05-23 21:57:17.787489 :9B1903ED:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-23 21:57:18.177400 :9B190464:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-23 21:57:18.172 2025-05-23 21:57:18.177402 :9B190465:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13400 pso_num=22 pso_serial#=7 2025-05-23 21:57:18.177545 :9B190466:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13400 osp_idx=0 osp_ver=228232 osp_pg=0 (spawn #212492) 2025-05-23 21:57:18.177545 :9B190467:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-23 21:57:18.177546 :9B190468:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=218 time=1013210438 2025-05-23 21:57:18.177546 :9B190469:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-23 21:57:18.177547 :9B19046A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-23 21:57:18.177547 :9B19046B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-23 21:57:18.177547 :9B19046C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-23 21:57:18.177548 :9B19046D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-23 21:57:18.178040 :9B19046E: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-05-23 21:57:18.178090 :9B190476: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-05-23 21:57:48.233201 :9B190DB7:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-23 21:57:48.233212 :9B190DC4:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-23 21:57:48.233213 :9B190DC5:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=11, exc=11, tot=11 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 13400, W000)