Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250607180537\orcl_w000_13096_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:36827M/63366M, Ph+PgF:43479M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13096, image: ORACLE.EXE (W000) *** 2025-06-07 18:05:37.396 *** SESSION ID:(177.64813) 2025-06-07 18:05:37.396 *** 2025-06-07 18:05:37.396 Process diagnostic dump for ORACLE.EXE (W000), OS id=13096, pid: 22, proc_ser: 180, sid: 177, sess_ser: 64813 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=2.603840 sec, exc=2.603840 sec, total=2.603840 sec wait times: max=5.000000 sec, heur=2 min 17 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000025 sec since current wait 0: 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.009710 sec, exc=5.009710 sec, total=5.009710 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 1: 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.003207 sec, exc=5.003207 sec, total=5.003207 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 2: 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.000304 sec, exc=5.000304 sec, total=5.000304 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 3: 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.000403 sec, exc=5.000403 sec, total=5.000403 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 4: 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.001438 sec, exc=5.001438 sec, total=5.001438 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.013530 sec, exc=5.013530 sec, total=5.013530 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.014735 sec, exc=5.014735 sec, total=5.014735 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.014726 sec, exc=5.014726 sec, total=5.014726 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.004625 sec, exc=5.004625 sec, total=5.004625 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=18 seq_num=19 snap_id=1 wait times: snap=5.004624 sec, exc=5.004624 sec, total=5.004624 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 64813 --------------------------------------------------- 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, 18:03:37 - 18:05:37] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-07 18:05:37.396 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13096, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-07 15:33:47.686738 :A191233B:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-06-07 15:33:47.686755 :A1912340:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-06-07 15:33:47.686757 :A1912341:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=16, exc=16, tot=16 2025-06-07 15:43:03.435196 :A191DA94:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 15:43:03.830561 :A191DAF6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 15:43:03.826 2025-06-07 15:43:03.830564 :A191DAF7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14240 pso_num=22 pso_serial#=167 2025-06-07 15:43:03.830699 :A191DAF8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14240 osp_idx=0 osp_ver=274364 osp_pg=0 (spawn #261596) 2025-06-07 15:43:03.830700 :A191DAF9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 15:43:03.830701 :A191DAFA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=17 time=2286742485 2025-06-07 15:43:03.830701 :A191DAFB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 15:43:03.830701 :A191DAFC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 15:43:03.830702 :A191DAFD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 15:43:03.830702 :A191DAFE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 15:43:03.830703 :A191DAFF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 15:43:03.831194 :A191DB00: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-06-07 15:43:03.831241 :A191DB0A: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-06-07 15:53:04.605652 :A192A08E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 15:53:05.032253 :A192A0CA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 15:53:05.027 2025-06-07 15:53:05.032256 :A192A0CB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13496 pso_num=22 pso_serial#=168 2025-06-07 15:53:05.032392 :A192A0CC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13496 osp_idx=0 osp_ver=274365 osp_pg=0 (spawn #261618) 2025-06-07 15:53:05.032392 :A192A0CD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 15:53:05.032393 :A192A0CE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=18 time=2287343672 2025-06-07 15:53:05.032393 :A192A0CF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 15:53:05.032394 :A192A0D0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 15:53:05.032394 :A192A0D1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 15:53:05.032395 :A192A0D2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 15:53:05.032395 :A192A0D3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 15:53:05.032894 :A192A0D4: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-06-07 15:53:05.032942 :A192A0DE: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-06-07 16:03:05.839849 :A1936C20:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 16:03:06.219582 :A1936C67:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 16:03:06.215 2025-06-07 16:03:06.219585 :A1936C68:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9904 pso_num=22 pso_serial#=169 2025-06-07 16:03:06.219723 :A1936C69:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9904 osp_idx=0 osp_ver=274366 osp_pg=0 (spawn #261645) 2025-06-07 16:03:06.219724 :A1936C6A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 16:03:06.219724 :A1936C6B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=19 time=2287944860 2025-06-07 16:03:06.219724 :A1936C6C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 16:03:06.219725 :A1936C6D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 16:03:06.219725 :A1936C6E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 16:03:06.219725 :A1936C6F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 16:03:06.219726 :A1936C70:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 16:03:06.220229 :A1936C71: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-06-07 16:03:06.220278 :A1936C78: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-06-07 16:07:53.504887 :A193D2B9: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-06-07 16:13:07.241957 :A19438FB: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-06-07 16:23:08.040642 :A195003E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 16:23:08.342153 :A1950084:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 16:23:08.337 2025-06-07 16:23:08.342155 :A1950085:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14292 pso_num=22 pso_serial#=170 2025-06-07 16:23:08.342294 :A1950086:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14292 osp_idx=0 osp_ver=274367 osp_pg=0 (spawn #261689) 2025-06-07 16:23:08.342295 :A1950087:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 16:23:08.342295 :A1950088:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=20 time=2289146985 2025-06-07 16:23:08.342296 :A1950089:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 16:23:08.342296 :A195008A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 16:23:08.342297 :A195008B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 16:23:08.342297 :A195008C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 16:23:08.342297 :A195008D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 16:23:08.342788 :A195008E: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-06-07 16:23:08.342830 :A1950095: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-06-07 16:33:09.243504 :A195C58F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 16:33:09.482705 :A195C5C6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 16:33:09.478 2025-06-07 16:33:09.482707 :A195C5C7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12316 pso_num=22 pso_serial#=171 2025-06-07 16:33:09.482845 :A195C5C8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12316 osp_idx=0 osp_ver=274368 osp_pg=0 (spawn #261712) 2025-06-07 16:33:09.482846 :A195C5C9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 16:33:09.482846 :A195C5CA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=21 time=2289748125 2025-06-07 16:33:09.482846 :A195C5CB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 16:33:09.482847 :A195C5CC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 16:33:09.482847 :A195C5CD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 16:33:09.482847 :A195C5CE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 16:33:09.482848 :A195C5CF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 16:33:09.483332 :A195C5D0: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-06-07 16:33:09.483376 :A195C5D7: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-06-07 16:43:10.296391 :A1968C01:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 16:43:10.582366 :A1968C57:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 16:43:10.577 2025-06-07 16:43:10.582368 :A1968C58:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13284 pso_num=22 pso_serial#=172 2025-06-07 16:43:10.582508 :A1968C59:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13284 osp_idx=0 osp_ver=274369 osp_pg=0 (spawn #261735) 2025-06-07 16:43:10.582508 :A1968C5A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 16:43:10.582509 :A1968C5B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=22 time=2290349235 2025-06-07 16:43:10.582509 :A1968C5C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 16:43:10.582510 :A1968C5D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 16:43:10.582510 :A1968C5E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 16:43:10.582510 :A1968C5F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 16:43:10.582511 :A1968C60:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 16:43:10.583012 :A1968C61: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-06-07 16:43:10.583075 :A1968C6B: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-06-07 16:53:11.484157 :A19751DA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 16:53:11.676423 :A1975224:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 16:53:11.671 2025-06-07 16:53:11.676425 :A1975225:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14268 pso_num=22 pso_serial#=173 2025-06-07 16:53:11.676558 :A1975226:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14268 osp_idx=0 osp_ver=274370 osp_pg=0 (spawn #261757) 2025-06-07 16:53:11.676559 :A1975227:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 16:53:11.676559 :A1975228:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=23 time=2290950329 2025-06-07 16:53:11.676560 :A1975229:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 16:53:11.676560 :A197522A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 16:53:11.676560 :A197522B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 16:53:11.676561 :A197522C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 16:53:11.676561 :A197522D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 16:53:11.677104 :A197522E: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-06-07 16:53:11.677148 :A1975235: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-06-07 17:03:12.535455 :A1981D9E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 17:03:12.790376 :A1981DE8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 17:03:12.785 2025-06-07 17:03:12.790379 :A1981DE9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12656 pso_num=22 pso_serial#=174 2025-06-07 17:03:12.790521 :A1981DEA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12656 osp_idx=0 osp_ver=274371 osp_pg=0 (spawn #261783) 2025-06-07 17:03:12.790522 :A1981DEB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 17:03:12.790523 :A1981DEC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=24 time=2291551438 2025-06-07 17:03:12.790523 :A1981DED:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 17:03:12.790524 :A1981DEE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 17:03:12.790524 :A1981DEF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 17:03:12.790525 :A1981DF0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 17:03:12.790526 :A1981DF1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 17:03:12.791012 :A1981DF2: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-06-07 17:03:12.791059 :A1981DFA: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-06-07 17:13:13.689849 :A198EA93:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 17:13:13.929020 :A198EACE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 17:13:13.924 2025-06-07 17:13:13.929023 :A198EACF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7880 pso_num=22 pso_serial#=175 2025-06-07 17:13:13.929161 :A198EAD0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7880 osp_idx=0 osp_ver=274372 osp_pg=0 (spawn #261806) 2025-06-07 17:13:13.929162 :A198EAD1:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 17:13:13.929162 :A198EAD2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=25 time=2292152579 2025-06-07 17:13:13.929163 :A198EAD3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 17:13:13.929163 :A198EAD4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 17:13:13.929163 :A198EAD5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 17:13:13.929164 :A198EAD6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 17:13:13.929164 :A198EAD7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 17:13:13.929694 :A198EAD8: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-06-07 17:13:13.929736 :A198EADF: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-06-07 17:23:14.742570 :A199B0F4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 17:23:15.060613 :A199B12A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 17:23:15.055 2025-06-07 17:23:15.060615 :A199B12B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9288 pso_num=22 pso_serial#=176 2025-06-07 17:23:15.060766 :A199B12C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9288 osp_idx=0 osp_ver=274373 osp_pg=0 (spawn #261828) 2025-06-07 17:23:15.060766 :A199B12D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 17:23:15.060767 :A199B12E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=26 time=2292753704 2025-06-07 17:23:15.060767 :A199B12F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 17:23:15.060768 :A199B130:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 17:23:15.060768 :A199B131:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 17:23:15.060769 :A199B132:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 17:23:15.060769 :A199B133:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 17:23:15.061330 :A199B134: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-06-07 17:23:15.061402 :A199B13E: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-06-07 17:33:15.906762 :A19A776F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 17:33:16.255232 :A19A77BB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 17:33:16.251 2025-06-07 17:33:16.255234 :A19A77BC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12004 pso_num=22 pso_serial#=177 2025-06-07 17:33:16.255368 :A19A77BD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12004 osp_idx=0 osp_ver=274374 osp_pg=0 (spawn #261851) 2025-06-07 17:33:16.255369 :A19A77BE:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 17:33:16.255370 :A19A77BF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=27 time=2293354907 2025-06-07 17:33:16.255370 :A19A77C0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 17:33:16.255370 :A19A77C1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 17:33:16.255371 :A19A77C2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 17:33:16.255371 :A19A77C3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 17:33:16.255371 :A19A77C4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 17:33:16.255862 :A19A77C5: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-06-07 17:33:16.255909 :A19A77CC: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-06-07 17:43:17.058007 :A19B3D9D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 17:43:17.328252 :A19B3DD3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 17:43:17.323 2025-06-07 17:43:17.328254 :A19B3DD4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16072 pso_num=22 pso_serial#=178 2025-06-07 17:43:17.328386 :A19B3DD5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16072 osp_idx=0 osp_ver=274375 osp_pg=0 (spawn #261874) 2025-06-07 17:43:17.328387 :A19B3DD6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 17:43:17.328387 :A19B3DD7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=28 time=2293955969 2025-06-07 17:43:17.328388 :A19B3DD8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 17:43:17.328388 :A19B3DD9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 17:43:17.328389 :A19B3DDA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 17:43:17.328389 :A19B3DDB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 17:43:17.328389 :A19B3DDC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 17:43:17.328852 :A19B3DDD: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-06-07 17:43:17.328898 :A19B3DE4: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-06-07 17:53:18.147736 :A19C027B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 17:53:18.496252 :A19C02C3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 17:53:18.491 2025-06-07 17:53:18.496254 :A19C02C4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15768 pso_num=22 pso_serial#=179 2025-06-07 17:53:18.496396 :A19C02C5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15768 osp_idx=0 osp_ver=274376 osp_pg=0 (spawn #261896) 2025-06-07 17:53:18.496397 :A19C02C6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 17:53:18.496397 :A19C02C7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=29 time=2294557141 2025-06-07 17:53:18.496398 :A19C02C8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 17:53:18.496398 :A19C02C9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 17:53:18.496398 :A19C02CA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 17:53:18.496399 :A19C02CB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 17:53:18.496399 :A19C02CC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 17:53:18.496897 :A19C02CD: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-06-07 17:53:18.496941 :A19C02D4: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-06-07 18:03:19.365577 :A19CC8E2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 18:03:19.651538 :A19CC917:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 18:03:19.647 2025-06-07 18:03:19.651540 :A19CC918:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13096 pso_num=22 pso_serial#=180 2025-06-07 18:03:19.651676 :A19CC919:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13096 osp_idx=0 osp_ver=274377 osp_pg=0 (spawn #261922) 2025-06-07 18:03:19.651677 :A19CC91A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 18:03:19.651677 :A19CC91B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=30 time=2295158297 2025-06-07 18:03:19.651677 :A19CC91C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 18:03:19.651678 :A19CC91D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 18:03:19.651679 :A19CC91E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 18:03:19.651679 :A19CC91F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 18:03:19.651679 :A19CC920:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 18:03:19.652231 :A19CC921: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-06-07 18:03:19.652274 :A19CC929:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 13096, W000)