Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510180122\orcl_w000_2860_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:37494M/63366M, Ph+PgF:44866M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 2860, image: ORACLE.EXE (W000) *** 2025-05-10 18:01:22.473 *** SESSION ID:(209.33057) 2025-05-10 18:01:22.473 *** 2025-05-10 18:01:22.473 Process diagnostic dump for ORACLE.EXE (W000), OS id=2860, pid: 26, proc_ser: 98, sid: 209, sess_ser: 33057 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=80 seq_num=81 snap_id=1 wait times: snap=1.858382 sec, exc=1.858382 sec, total=1.858382 sec wait times: max=5.000000 sec, heur=6 min 37 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.000024 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=79 seq_num=80 snap_id=1 wait times: snap=5.007582 sec, exc=5.007582 sec, total=5.007582 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=78 seq_num=79 snap_id=1 wait times: snap=5.005435 sec, exc=5.005435 sec, total=5.005435 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.014723 sec, exc=5.014723 sec, total=5.014723 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=76 seq_num=77 snap_id=1 wait times: snap=5.014743 sec, exc=5.014743 sec, total=5.014743 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=75 seq_num=76 snap_id=1 wait times: snap=5.004623 sec, exc=5.004623 sec, total=5.004623 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=74 seq_num=75 snap_id=1 wait times: snap=5.004640 sec, exc=5.004640 sec, total=5.004640 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=73 seq_num=74 snap_id=1 wait times: snap=5.009637 sec, exc=5.009637 sec, total=5.009637 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=72 seq_num=73 snap_id=1 wait times: snap=5.010645 sec, exc=5.010645 sec, total=5.010645 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=71 seq_num=72 snap_id=1 wait times: snap=5.013805 sec, exc=5.013805 sec, total=5.013805 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=70 seq_num=71 snap_id=1 wait times: snap=5.004623 sec, exc=5.004623 sec, total=5.004623 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time Sampled Session History of session 209 serial 33057 --------------------------------------------------- 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, 17:59:22 - 18:01:22] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 18:01:22.473 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 2860, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 15:24:24.683453 :9544E512:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 15:24:24.683453 :9544E513:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 15:24:24.683950 :9544E514:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 15:24:24.683996 :9544E51B:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 15:34:25.487834 :9545A95D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 15:34:26.023811 :9545A9CE:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 15:34:26.019 2025-05-10 15:34:26.023813 :9545A9CF:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13168 pso_num=26 pso_serial#=85 2025-05-10 15:34:26.023948 :9545A9D0:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13168 osp_idx=24 osp_ver=244884 osp_pg=0 (spawn #168162) 2025-05-10 15:34:26.023948 :9545A9D1:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 15:34:26.023949 :9545A9D2:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=14 time=4162043187 2025-05-10 15:34:26.023949 :9545A9D3:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 15:34:26.023950 :9545A9D4:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 15:34:26.023950 :9545A9D5:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 15:34:26.023950 :9545A9D6:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 15:34:26.023951 :9545A9D7:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 15:34:26.024432 :9545A9D8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 15:34:26.024478 :9545A9E0:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 15:44:26.806844 :95467828:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 15:44:27.249062 :9546788D:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 15:44:27.244 2025-05-10 15:44:27.249064 :9546788E:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10748 pso_num=26 pso_serial#=86 2025-05-10 15:44:27.249203 :9546788F:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10748 osp_idx=24 osp_ver=244885 osp_pg=0 (spawn #168185) 2025-05-10 15:44:27.249204 :95467890:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 15:44:27.249204 :95467891:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=15 time=4162644421 2025-05-10 15:44:27.249205 :95467892:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 15:44:27.249205 :95467893:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 15:44:27.249205 :95467894:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 15:44:27.249206 :95467895:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 15:44:27.249206 :95467896:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 15:44:27.249709 :95467897:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 15:44:27.249756 :9546789E:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 15:54:28.181677 :95473D8D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 15:54:28.717547 :95473E02:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 15:54:28.712 2025-05-10 15:54:28.717549 :95473E03:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=3752 pso_num=26 pso_serial#=87 2025-05-10 15:54:28.717686 :95473E04:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=3752 osp_idx=24 osp_ver=244886 osp_pg=0 (spawn #168208) 2025-05-10 15:54:28.717687 :95473E05:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 15:54:28.717687 :95473E06:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=16 time=4163245890 2025-05-10 15:54:28.717687 :95473E07:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 15:54:28.717688 :95473E08:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 15:54:28.717688 :95473E09:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 15:54:28.717688 :95473E0A:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 15:54:28.717689 :95473E0B:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 15:54:28.718175 :95473E0C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 15:54:28.718223 :95473E14:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 16:00:10.493516 :9547AED1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-10 16:04:30.124777 :95480486:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-10 16:14:31.088904 :9548D2C5:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 16:14:31.562349 :9548D338:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 16:14:31.557 2025-05-10 16:14:31.562351 :9548D339:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=7872 pso_num=26 pso_serial#=88 2025-05-10 16:14:31.562490 :9548D33A:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=7872 osp_idx=24 osp_ver=244887 osp_pg=0 (spawn #168258) 2025-05-10 16:14:31.562491 :9548D33B:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 16:14:31.562491 :9548D33C:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=17 time=4164448734 2025-05-10 16:14:31.562492 :9548D33D:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 16:14:31.562492 :9548D33E:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 16:14:31.562493 :9548D33F:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 16:14:31.562493 :9548D340:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 16:14:31.562494 :9548D341:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 16:14:31.562984 :9548D342:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 16:14:31.563034 :9548D34C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 16:24:32.462564 :954996D7:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 16:24:33.027028 :95499755:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 16:24:33.022 2025-05-10 16:24:33.027030 :95499756:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10604 pso_num=26 pso_serial#=89 2025-05-10 16:24:33.027167 :95499757:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10604 osp_idx=24 osp_ver=244888 osp_pg=0 (spawn #168281) 2025-05-10 16:24:33.027168 :95499758:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 16:24:33.027169 :95499759:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=18 time=4165050187 2025-05-10 16:24:33.027169 :9549975A:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 16:24:33.027169 :9549975B:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 16:24:33.027170 :9549975C:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 16:24:33.027170 :9549975D:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 16:24:33.027170 :9549975E:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 16:24:33.027672 :9549975F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 16:24:33.027715 :95499767:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 16:34:33.873057 :954A5C36:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 16:34:34.356742 :954A5C96:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 16:34:34.352 2025-05-10 16:34:34.356744 :954A5C97:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13264 pso_num=26 pso_serial#=90 2025-05-10 16:34:34.356883 :954A5C98:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13264 osp_idx=24 osp_ver=244889 osp_pg=0 (spawn #168303) 2025-05-10 16:34:34.356884 :954A5C99:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 16:34:34.356884 :954A5C9A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=19 time=4165651515 2025-05-10 16:34:34.356884 :954A5C9B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 16:34:34.356885 :954A5C9C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 16:34:34.356885 :954A5C9D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 16:34:34.356886 :954A5C9E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 16:34:34.356886 :954A5C9F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 16:34:34.357411 :954A5CA0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 16:34:34.357456 :954A5CA7:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 16:44:35.291331 :954B2182:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 16:44:35.750226 :954B21E3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 16:44:35.745 2025-05-10 16:44:35.750228 :954B21E4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10436 pso_num=26 pso_serial#=91 2025-05-10 16:44:35.750368 :954B21E5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10436 osp_idx=24 osp_ver=244890 osp_pg=0 (spawn #168326) 2025-05-10 16:44:35.750369 :954B21E6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 16:44:35.750370 :954B21E7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=20 time=4166252921 2025-05-10 16:44:35.750370 :954B21E8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 16:44:35.750370 :954B21E9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 16:44:35.750370 :954B21EA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 16:44:35.750371 :954B21EB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 16:44:35.750371 :954B21EC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 16:44:35.750875 :954B21ED:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 16:44:35.750920 :954B21F5:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 16:54:36.728300 :954BE68E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 16:54:37.133750 :954BE700:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 16:54:37.129 2025-05-10 16:54:37.133752 :954BE701:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12924 pso_num=26 pso_serial#=92 2025-05-10 16:54:37.133895 :954BE702:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12924 osp_idx=24 osp_ver=244891 osp_pg=0 (spawn #168349) 2025-05-10 16:54:37.133895 :954BE703:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 16:54:37.133896 :954BE704:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=21 time=4166854296 2025-05-10 16:54:37.133896 :954BE705:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 16:54:37.133896 :954BE706:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 16:54:37.133897 :954BE707:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 16:54:37.133897 :954BE708:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 16:54:37.133897 :954BE709:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 16:54:37.134410 :954BE70A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 16:54:37.134456 :954BE712:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 17:04:38.083199 :954CAFDC:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 17:04:38.494123 :954CB04F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 17:04:38.489 2025-05-10 17:04:38.494125 :954CB050:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10992 pso_num=26 pso_serial#=93 2025-05-10 17:04:38.494262 :954CB051:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10992 osp_idx=24 osp_ver=244892 osp_pg=0 (spawn #168376) 2025-05-10 17:04:38.494263 :954CB052:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 17:04:38.494263 :954CB053:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=22 time=4167455656 2025-05-10 17:04:38.494264 :954CB054:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 17:04:38.494264 :954CB055:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 17:04:38.494264 :954CB056:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 17:04:38.494265 :954CB057:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 17:04:38.494265 :954CB058:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 17:04:38.494816 :954CB059:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 17:04:38.494861 :954CB062:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 17:14:39.449195 :954D7AAD:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 17:14:39.875898 :954D7B13:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 17:14:39.871 2025-05-10 17:14:39.875900 :954D7B14:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12136 pso_num=26 pso_serial#=94 2025-05-10 17:14:39.876042 :954D7B15:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12136 osp_idx=24 osp_ver=244893 osp_pg=0 (spawn #168399) 2025-05-10 17:14:39.876042 :954D7B16:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 17:14:39.876043 :954D7B17:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=23 time=4168057046 2025-05-10 17:14:39.876043 :954D7B18:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 17:14:39.876043 :954D7B19:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 17:14:39.876044 :954D7B1A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 17:14:39.876044 :954D7B1B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 17:14:39.876044 :954D7B1C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 17:14:39.876538 :954D7B1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 17:14:39.876585 :954D7B25:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 17:24:40.781214 :954E3F63:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 17:24:41.129675 :954E3FC3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 17:24:41.125 2025-05-10 17:24:41.129677 :954E3FC4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11864 pso_num=26 pso_serial#=95 2025-05-10 17:24:41.129815 :954E3FC5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11864 osp_idx=24 osp_ver=244894 osp_pg=0 (spawn #168422) 2025-05-10 17:24:41.129815 :954E3FC6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 17:24:41.129816 :954E3FC7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=24 time=4168658296 2025-05-10 17:24:41.129816 :954E3FC8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 17:24:41.129817 :954E3FC9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 17:24:41.129817 :954E3FCA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 17:24:41.129817 :954E3FCB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 17:24:41.129818 :954E3FCC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 17:24:41.130306 :954E3FCD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 17:24:41.130351 :954E3FD5:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 17:34:42.018886 :954F040E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 17:34:42.367321 :954F0480:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 17:34:42.362 2025-05-10 17:34:42.367323 :954F0481:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12596 pso_num=26 pso_serial#=96 2025-05-10 17:34:42.367460 :954F0482:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12596 osp_idx=24 osp_ver=244895 osp_pg=0 (spawn #168444) 2025-05-10 17:34:42.367461 :954F0483:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 17:34:42.367462 :954F0484:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=25 time=4169259531 2025-05-10 17:34:42.367462 :954F0485:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 17:34:42.367463 :954F0486:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 17:34:42.367463 :954F0487:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 17:34:42.367465 :954F0488:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 17:34:42.367465 :954F0489:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 17:34:42.367965 :954F048A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 17:34:42.368015 :954F0492:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 17:44:43.273110 :954FC8F6:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 17:44:43.712175 :954FC9A7:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 17:44:43.707 2025-05-10 17:44:43.712177 :954FC9A8:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13092 pso_num=26 pso_serial#=97 2025-05-10 17:44:43.712313 :954FC9A9:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13092 osp_idx=24 osp_ver=244896 osp_pg=0 (spawn #168467) 2025-05-10 17:44:43.712314 :954FC9AA:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 17:44:43.712314 :954FC9AB:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=26 time=4169860875 2025-05-10 17:44:43.712315 :954FC9AC:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 17:44:43.712315 :954FC9AD:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 17:44:43.712316 :954FC9AE:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 17:44:43.712316 :954FC9AF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 17:44:43.712316 :954FC9B0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 17:44:43.712818 :954FC9B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 17:44:43.712864 :954FC9B9:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 17:54:44.681307 :95508D38:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 17:54:45.014068 :95508DD1:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 17:54:45.009 2025-05-10 17:54:45.014070 :95508DD2:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2860 pso_num=26 pso_serial#=98 2025-05-10 17:54:45.014203 :95508DD3:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2860 osp_idx=24 osp_ver=244897 osp_pg=0 (spawn #168490) 2025-05-10 17:54:45.014204 :95508DD4:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 17:54:45.014204 :95508DD5:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=27 time=4170462187 2025-05-10 17:54:45.014205 :95508DD6:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 17:54:45.014205 :95508DD7:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 17:54:45.014205 :95508DD8:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 17:54:45.014206 :95508DD9:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 17:54:45.014206 :95508DDA:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 17:54:45.014697 :95508DDB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 17:54:45.014741 :95508DE2:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 2860, W000)