Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250813220008\orcl_w000_21156_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:35519M/63366M, Ph+PgF:40899M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 21156, image: ORACLE.EXE (W000) *** 2025-08-13 22:00:09.003 *** SESSION ID:(177.37879) 2025-08-13 22:00:09.003 *** 2025-08-13 22:00:09.003 Process diagnostic dump for ORACLE.EXE (W000), OS id=21156, pid: 22, proc_ser: 32, sid: 177, sess_ser: 37879 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=70 seq_num=71 snap_id=1 wait times: snap=4.909118 sec, exc=4.909118 sec, total=4.909118 sec wait times: max=5.000000 sec, heur=5 min 50 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=69 seq_num=70 snap_id=1 wait times: snap=5.014732 sec, exc=5.014732 sec, total=5.014732 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=68 seq_num=69 snap_id=1 wait times: snap=5.004661 sec, exc=5.004661 sec, total=5.004661 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=67 seq_num=68 snap_id=1 wait times: snap=5.014720 sec, exc=5.014720 sec, total=5.014720 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=66 seq_num=67 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.000026 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=65 seq_num=66 snap_id=1 wait times: snap=5.004608 sec, exc=5.004608 sec, total=5.004608 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=64 seq_num=65 snap_id=1 wait times: snap=5.001712 sec, exc=5.001712 sec, total=5.001712 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=63 seq_num=64 snap_id=1 wait times: snap=5.009725 sec, exc=5.009725 sec, total=5.009725 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=62 seq_num=63 snap_id=1 wait times: snap=5.014804 sec, exc=5.014804 sec, total=5.014804 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=61 seq_num=62 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.000025 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=60 seq_num=61 snap_id=1 wait times: snap=5.004631 sec, exc=5.004631 sec, total=5.004631 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 177 serial 37879 --------------------------------------------------- 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:09 - 22:00:09] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-13 22:00:09.004 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 21156, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-13 19:23:58.252453 :BF4C30DF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20796 osp_idx=0 osp_ver=512641 osp_pg=0 (spawn #485449) 2025-08-13 19:23:58.252454 :BF4C30E0:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 19:23:58.252455 :BF4C30E1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=192 time=3793707564 2025-08-13 19:23:58.252455 :BF4C30E2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 19:23:58.252455 :BF4C30E3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 19:23:58.252456 :BF4C30E4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 19:23:58.252456 :BF4C30E5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 19:23:58.252456 :BF4C30E6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 19:23:58.252959 :BF4C30E7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 19:23:58.253006 :BF4C30EF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 19:33:59.150493 :BF4CF4E4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 19:33:59.608805 :BF4CF53B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 19:33:59.603 2025-08-13 19:33:59.608808 :BF4CF53C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19536 pso_num=22 pso_serial#=20 2025-08-13 19:33:59.608940 :BF4CF53D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19536 osp_idx=0 osp_ver=512642 osp_pg=0 (spawn #485472) 2025-08-13 19:33:59.608941 :BF4CF53E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 19:33:59.608941 :BF4CF53F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=193 time=3794308908 2025-08-13 19:33:59.608942 :BF4CF540:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 19:33:59.608942 :BF4CF541:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 19:33:59.608943 :BF4CF542:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 19:33:59.608943 :BF4CF543:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 19:33:59.608943 :BF4CF544:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 19:33:59.609479 :BF4CF545:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 19:33:59.609522 :BF4CF54C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 19:35:26.029797 :BF4D1099:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-08-13 19:44:00.895470 :BF4DB87A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-08-13 19:54:01.786928 :BF4E7CFE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 19:54:02.322881 :BF4E7D4D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 19:54:02.317 2025-08-13 19:54:02.322883 :BF4E7D4E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12980 pso_num=22 pso_serial#=21 2025-08-13 19:54:02.323014 :BF4E7D4F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12980 osp_idx=0 osp_ver=512643 osp_pg=0 (spawn #485516) 2025-08-13 19:54:02.323014 :BF4E7D50:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 19:54:02.323015 :BF4E7D51:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=194 time=3795511626 2025-08-13 19:54:02.323015 :BF4E7D52:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 19:54:02.323016 :BF4E7D53:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 19:54:02.323016 :BF4E7D54:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 19:54:02.323016 :BF4E7D55:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 19:54:02.323016 :BF4E7D56:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 19:54:02.323559 :BF4E7D57:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 19:54:02.323619 :BF4E7D5D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 20:04:03.288952 :BF4F4207:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 20:04:03.778046 :BF4F4267:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 20:04:03.773 2025-08-13 20:04:03.778048 :BF4F4268:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18636 pso_num=22 pso_serial#=22 2025-08-13 20:04:03.778194 :BF4F4269:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18636 osp_idx=0 osp_ver=512644 osp_pg=0 (spawn #485542) 2025-08-13 20:04:03.778195 :BF4F426A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 20:04:03.778196 :BF4F426B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=195 time=3796113079 2025-08-13 20:04:03.778196 :BF4F426C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 20:04:03.778196 :BF4F426D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 20:04:03.778197 :BF4F426E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 20:04:03.778197 :BF4F426F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 20:04:03.778197 :BF4F4270:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 20:04:03.778692 :BF4F4271:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 20:04:03.778737 :BF4F4279:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 20:14:04.636124 :BF500F89:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 20:14:05.125283 :BF500FE1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 20:14:05.120 2025-08-13 20:14:05.125285 :BF500FE2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19676 pso_num=22 pso_serial#=23 2025-08-13 20:14:05.125419 :BF500FE3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19676 osp_idx=0 osp_ver=512645 osp_pg=0 (spawn #485565) 2025-08-13 20:14:05.125419 :BF500FE4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 20:14:05.125420 :BF500FE5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=196 time=3796714439 2025-08-13 20:14:05.125420 :BF500FE6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 20:14:05.125421 :BF500FE7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 20:14:05.125421 :BF500FE8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 20:14:05.125421 :BF500FE9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 20:14:05.125422 :BF500FEA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 20:14:05.125913 :BF500FEB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 20:14:05.125962 :BF500FF2:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 20:24:06.046569 :BF50D36C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 20:24:06.629638 :BF50D3C3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 20:24:06.624 2025-08-13 20:24:06.629640 :BF50D3C4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19324 pso_num=22 pso_serial#=24 2025-08-13 20:24:06.629782 :BF50D3C5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19324 osp_idx=0 osp_ver=512646 osp_pg=0 (spawn #485588) 2025-08-13 20:24:06.629783 :BF50D3C6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 20:24:06.629783 :BF50D3C7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=197 time=3797315939 2025-08-13 20:24:06.629784 :BF50D3C8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 20:24:06.629784 :BF50D3C9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 20:24:06.629784 :BF50D3CA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 20:24:06.629784 :BF50D3CB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 20:24:06.629785 :BF50D3CC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 20:24:06.630294 :BF50D3CD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 20:24:06.630336 :BF50D3D4:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 20:24:21.657373 :BF50D89F:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-08-13 20:24:21.657378 :BF50D8A1:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-08-13 20:24:21.657380 :BF50D8A3:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=6, exc=6, tot=6 2025-08-13 20:24:21.657390 :BF50D8AB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 20:34:07.467257 :BF5197BA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 20:34:07.972114 :BF519828:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 20:34:07.967 2025-08-13 20:34:07.972116 :BF519829:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21236 pso_num=22 pso_serial#=25 2025-08-13 20:34:07.972254 :BF51982A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21236 osp_idx=0 osp_ver=512647 osp_pg=0 (spawn #485611) 2025-08-13 20:34:07.972254 :BF51982B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 20:34:07.972255 :BF51982C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=198 time=3797917283 2025-08-13 20:34:07.972255 :BF51982D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 20:34:07.972256 :BF51982E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 20:34:07.972256 :BF51982F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 20:34:07.972256 :BF519830:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 20:34:07.972257 :BF519831:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 20:34:07.972735 :BF519832:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 20:34:07.972786 :BF51983C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 20:44:08.896594 :BF525B2E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 20:44:09.351734 :BF525B83:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 20:44:09.347 2025-08-13 20:44:09.351737 :BF525B84:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20256 pso_num=22 pso_serial#=26 2025-08-13 20:44:09.351870 :BF525B85:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20256 osp_idx=0 osp_ver=512648 osp_pg=0 (spawn #485633) 2025-08-13 20:44:09.351870 :BF525B86:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 20:44:09.351871 :BF525B87:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=199 time=3798518658 2025-08-13 20:44:09.351871 :BF525B88:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 20:44:09.351872 :BF525B89:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 20:44:09.351872 :BF525B8A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 20:44:09.351872 :BF525B8B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 20:44:09.351873 :BF525B8C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 20:44:09.352417 :BF525B8D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 20:44:09.352460 :BF525B94:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 20:54:10.211929 :BF531F50:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 20:54:10.763508 :BF531FAC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 20:54:10.759 2025-08-13 20:54:10.763510 :BF531FAD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17856 pso_num=22 pso_serial#=27 2025-08-13 20:54:10.763650 :BF531FAE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17856 osp_idx=0 osp_ver=512649 osp_pg=0 (spawn #485656) 2025-08-13 20:54:10.763651 :BF531FAF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 20:54:10.763651 :BF531FB0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=200 time=3799120064 2025-08-13 20:54:10.763651 :BF531FB1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 20:54:10.763652 :BF531FB2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 20:54:10.763652 :BF531FB3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 20:54:10.763652 :BF531FB4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 20:54:10.763653 :BF531FB5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 20:54:10.764147 :BF531FB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 20:54:10.764191 :BF531FBD:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 21:04:11.675062 :BF53E591:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 21:04:12.041206 :BF53E5EC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 21:04:12.041 2025-08-13 21:04:12.041208 :BF53E5ED:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11816 pso_num=22 pso_serial#=28 2025-08-13 21:04:12.041340 :BF53E5EE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11816 osp_idx=0 osp_ver=512650 osp_pg=0 (spawn #485681) 2025-08-13 21:04:12.041341 :BF53E5EF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 21:04:12.041341 :BF53E5F0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=201 time=3799721345 2025-08-13 21:04:12.041341 :BF53E5F1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 21:04:12.041342 :BF53E5F2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 21:04:12.041342 :BF53E5F3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 21:04:12.041342 :BF53E5F4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 21:04:12.041342 :BF53E5F5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 21:04:12.041820 :BF53E5F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 21:04:12.041863 :BF53E5FE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 21:14:13.009948 :BF54B479:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 21:14:13.545979 :BF54B4DC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 21:14:13.541 2025-08-13 21:14:13.545981 :BF54B4DD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15732 pso_num=22 pso_serial#=29 2025-08-13 21:14:13.546119 :BF54B4DE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15732 osp_idx=0 osp_ver=512651 osp_pg=0 (spawn #485704) 2025-08-13 21:14:13.546120 :BF54B4DF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 21:14:13.546120 :BF54B4E0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=202 time=3800322845 2025-08-13 21:14:13.546120 :BF54B4E1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 21:14:13.546121 :BF54B4E2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 21:14:13.546121 :BF54B4E3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 21:14:13.546121 :BF54B4E4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 21:14:13.546122 :BF54B4E5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 21:14:13.546609 :BF54B4E6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 21:14:13.546654 :BF54B4EF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 21:24:14.482940 :BF5579D1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 21:24:14.816103 :BF557A28:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 21:24:14.811 2025-08-13 21:24:14.816105 :BF557A29:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20204 pso_num=22 pso_serial#=30 2025-08-13 21:24:14.816268 :BF557A2A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20204 osp_idx=0 osp_ver=512652 osp_pg=0 (spawn #485727) 2025-08-13 21:24:14.816268 :BF557A2B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 21:24:14.816269 :BF557A2C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=203 time=3800924126 2025-08-13 21:24:14.816269 :BF557A2D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 21:24:14.816270 :BF557A2E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 21:24:14.816270 :BF557A2F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 21:24:14.816271 :BF557A30:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 21:24:14.816271 :BF557A31:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 21:24:14.816773 :BF557A32:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 21:24:14.816822 :BF557A3A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 21:34:15.727188 :BF563F96:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 21:34:16.107284 :BF564027:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 21:34:16.102 2025-08-13 21:34:16.107286 :BF564028:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12076 pso_num=22 pso_serial#=31 2025-08-13 21:34:16.107483 :BF564029:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12076 osp_idx=0 osp_ver=512653 osp_pg=0 (spawn #485750) 2025-08-13 21:34:16.107484 :BF56402A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 21:34:16.107484 :BF56402B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=204 time=3801525408 2025-08-13 21:34:16.107484 :BF56402C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 21:34:16.107485 :BF56402D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 21:34:16.107485 :BF56402E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 21:34:16.107485 :BF56402F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 21:34:16.107485 :BF564030:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 21:34:16.108024 :BF564031:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 21:34:16.108080 :BF564037:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-13 21:35:26.730673 :BF5656E2:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-08-13 21:44:17.358752 :BF57053E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-08-13 21:54:18.225276 :BF57CAEA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-13 21:54:18.589429 :BF57CB4F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-13 21:54:18.585 2025-08-13 21:54:18.589431 :BF57CB50:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21156 pso_num=22 pso_serial#=32 2025-08-13 21:54:18.589571 :BF57CB51:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21156 osp_idx=0 osp_ver=512654 osp_pg=0 (spawn #485794) 2025-08-13 21:54:18.589571 :BF57CB52:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-13 21:54:18.589572 :BF57CB53:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=205 time=3802727892 2025-08-13 21:54:18.589572 :BF57CB54:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-13 21:54:18.589573 :BF57CB55:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-13 21:54:18.589573 :BF57CB56:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-13 21:54:18.589573 :BF57CB57:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-13 21:54:18.589574 :BF57CB58:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-13 21:54:18.590071 :BF57CB59:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-13 21:54:18.590119 :BF57CB61: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: 21156, W000)