Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250628080319\orcl_w000_1740_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:36368M/63366M, Ph+PgF:42475M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 1740, image: ORACLE.EXE (W000) *** 2025-06-28 08:03:19.782 *** SESSION ID:(177.52981) 2025-06-28 08:03:19.782 *** 2025-06-28 08:03:19.782 Process diagnostic dump for ORACLE.EXE (W000), OS id=1740, pid: 22, proc_ser: 63, sid: 177, sess_ser: 52981 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=119 seq_num=120 snap_id=1 wait times: snap=2.840608 sec, exc=2.840608 sec, total=2.840608 sec wait times: max=5.000000 sec, heur=3 min 8 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.000021 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=118 seq_num=119 snap_id=1 wait times: snap=5.002863 sec, exc=5.002863 sec, total=5.002863 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=117 seq_num=118 snap_id=1 wait times: snap=5.014750 sec, exc=5.014750 sec, total=5.014750 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=116 seq_num=117 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.000022 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=115 seq_num=116 snap_id=1 wait times: snap=5.004622 sec, exc=5.004622 sec, total=5.004622 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=114 seq_num=115 snap_id=1 wait times: snap=5.015241 sec, exc=5.015241 sec, total=5.015241 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=113 seq_num=114 snap_id=1 wait times: snap=5.003705 sec, exc=5.003705 sec, total=5.003705 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=112 seq_num=113 snap_id=1 wait times: snap=5.013798 sec, exc=5.013798 sec, total=5.013798 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=111 seq_num=112 snap_id=1 wait times: snap=5.010661 sec, exc=5.010661 sec, total=5.010661 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=110 seq_num=111 snap_id=1 wait times: snap=5.004641 sec, exc=5.004641 sec, total=5.004641 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=109 seq_num=110 snap_id=1 wait times: snap=5.014729 sec, exc=5.014729 sec, total=5.014729 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time Sampled Session History of session 177 serial 52981 --------------------------------------------------- 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, 08:01:19 - 08:03:19] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-28 08:03:19.782 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 1740, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-28 05:43:15.981316 :AAA380D9: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-28 05:43:15.981316 :AAA380DA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=142 time=4065139172 2025-06-28 05:43:15.981316 :AAA380DB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:43:15.981317 :AAA380DC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:43:15.981318 :AAA380DD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:43:15.981318 :AAA380DE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:43:15.981318 :AAA380DF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:43:15.981813 :AAA380E0: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-28 05:43:15.981863 :AAA380E6: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-28 05:53:16.809110 :AAA445F3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 05:53:17.173407 :AAA44638:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 05:53:17.168 2025-06-28 05:53:17.173409 :AAA44639:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17988 pso_num=22 pso_serial#=49 2025-06-28 05:53:17.173547 :AAA4463A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17988 osp_idx=0 osp_ver=352531 osp_pg=0 (spawn #330256) 2025-06-28 05:53:17.173548 :AAA4463B: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-28 05:53:17.173548 :AAA4463C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=143 time=4065740360 2025-06-28 05:53:17.173549 :AAA4463D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:53:17.173549 :AAA4463E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:53:17.173550 :AAA4463F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:53:17.173550 :AAA44640:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:53:17.173550 :AAA44641:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:53:17.174060 :AAA44642: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-28 05:53:17.174123 :AAA44648: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-28 05:55:14.831462 :AAA46C67: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-28 06:03:18.330046 :AAA5187E: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-28 06:13:19.191788 :AAA5E740:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 06:13:19.634028 :AAA5E7AE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 06:13:19.629 2025-06-28 06:13:19.634030 :AAA5E7AF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17004 pso_num=22 pso_serial#=50 2025-06-28 06:13:19.634166 :AAA5E7B0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17004 osp_idx=0 osp_ver=352532 osp_pg=0 (spawn #330310) 2025-06-28 06:13:19.634167 :AAA5E7B1: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-28 06:13:19.634167 :AAA5E7B2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=144 time=4066942829 2025-06-28 06:13:19.634168 :AAA5E7B3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 06:13:19.634168 :AAA5E7B4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 06:13:19.634168 :AAA5E7B5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 06:13:19.634169 :AAA5E7B6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 06:13:19.634169 :AAA5E7B7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 06:13:19.634659 :AAA5E7B8: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-28 06:13:19.634707 :AAA5E7C0: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-28 06:23:20.474563 :AAA6AFFD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 06:23:20.692755 :AAA6B01C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 06:23:20.680 2025-06-28 06:23:20.692757 :AAA6B01D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=3624 pso_num=22 pso_serial#=51 2025-06-28 06:23:20.692893 :AAA6B01E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=3624 (legacy spawn) 2025-06-28 06:23:20.699364 :AAA6B01F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-28 06:23:20.699533 :AAA6B025:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-28 06:23:20.700332 :AAA6B029:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 06:23:20.708993 :AAA6B02C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 06:23:20.695 2025-06-28 06:23:20.708996 :AAA6B02D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16720 pso_num=22 pso_serial#=52 2025-06-28 06:23:20.709141 :AAA6B02E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=16720 (legacy spawn) 2025-06-28 06:23:20.715562 :AAA6B02F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-28 06:23:20.715727 :AAA6B038:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-28 06:23:20.716543 :AAA6B039:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 06:23:20.887464 :AAA6B072:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 06:23:20.883 2025-06-28 06:23:20.887467 :AAA6B073:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10112 pso_num=22 pso_serial#=53 2025-06-28 06:23:20.887605 :AAA6B074:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10112 osp_idx=0 osp_ver=352535 osp_pg=0 (spawn #330332) 2025-06-28 06:23:20.887605 :AAA6B075: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-28 06:23:20.887606 :AAA6B076:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=145 time=4067544079 2025-06-28 06:23:20.887606 :AAA6B077:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 06:23:20.887607 :AAA6B078:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 06:23:20.887607 :AAA6B079:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 06:23:20.887607 :AAA6B07A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 06:23:20.887608 :AAA6B07B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 06:23:20.888113 :AAA6B07C: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-28 06:23:20.888166 :AAA6B082: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-28 06:33:21.681474 :AAA7797F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 06:33:22.139851 :AAA779E6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 06:33:22.134 2025-06-28 06:33:22.139853 :AAA779E7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10556 pso_num=22 pso_serial#=54 2025-06-28 06:33:22.140002 :AAA779E8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10556 osp_idx=0 osp_ver=352536 osp_pg=0 (spawn #330355) 2025-06-28 06:33:22.140004 :AAA779E9: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-28 06:33:22.140004 :AAA779EA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=146 time=4068145329 2025-06-28 06:33:22.140005 :AAA779EB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 06:33:22.140005 :AAA779EC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 06:33:22.140005 :AAA779ED:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 06:33:22.140006 :AAA779EE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 06:33:22.140006 :AAA779EF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 06:33:22.140527 :AAA779F0: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-28 06:33:22.140576 :AAA779F6: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-28 06:43:22.967698 :AAA842FE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 06:43:23.425537 :AAA8435C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 06:43:23.421 2025-06-28 06:43:23.425538 :AAA8435D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16996 pso_num=22 pso_serial#=55 2025-06-28 06:43:23.425685 :AAA8435E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16996 osp_idx=0 osp_ver=352537 osp_pg=0 (spawn #330378) 2025-06-28 06:43:23.425686 :AAA8435F: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-28 06:43:23.425686 :AAA84360:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=147 time=4068746610 2025-06-28 06:43:23.425686 :AAA84361:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 06:43:23.425687 :AAA84362:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 06:43:23.425687 :AAA84363:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 06:43:23.425688 :AAA84364:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 06:43:23.425688 :AAA84365:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 06:43:23.426225 :AAA84366: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-28 06:43:23.426267 :AAA8436E: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-28 06:53:24.301410 :AAA90C50:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 06:53:24.743782 :AAA90C9F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 06:53:24.738 2025-06-28 06:53:24.743784 :AAA90CA0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16076 pso_num=22 pso_serial#=56 2025-06-28 06:53:24.743929 :AAA90CA1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16076 osp_idx=0 osp_ver=352538 osp_pg=0 (spawn #330400) 2025-06-28 06:53:24.743929 :AAA90CA2: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-28 06:53:24.743929 :AAA90CA3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=148 time=4069347938 2025-06-28 06:53:24.743930 :AAA90CA4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 06:53:24.743930 :AAA90CA5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 06:53:24.743931 :AAA90CA6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 06:53:24.743931 :AAA90CA7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 06:53:24.743931 :AAA90CA8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 06:53:24.744444 :AAA90CA9: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-28 06:53:24.744491 :AAA90CB3: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-28 07:03:25.632409 :AAA9D8C4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 07:03:26.105903 :AAA9D914:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 07:03:26.101 2025-06-28 07:03:26.105906 :AAA9D915:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16980 pso_num=22 pso_serial#=57 2025-06-28 07:03:26.106049 :AAA9D916:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16980 osp_idx=0 osp_ver=352539 osp_pg=0 (spawn #330427) 2025-06-28 07:03:26.106049 :AAA9D917: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-28 07:03:26.106050 :AAA9D918:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=149 time=4069949297 2025-06-28 07:03:26.106050 :AAA9D919:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 07:03:26.106051 :AAA9D91A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 07:03:26.106051 :AAA9D91B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 07:03:26.106051 :AAA9D91C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 07:03:26.106052 :AAA9D91D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 07:03:26.106550 :AAA9D91E: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-28 07:03:26.106602 :AAA9D926: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-28 07:13:26.923562 :AAAAAA98:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 07:13:27.428259 :AAAAAB07:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 07:13:27.423 2025-06-28 07:13:27.428262 :AAAAAB08:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12108 pso_num=22 pso_serial#=58 2025-06-28 07:13:27.428398 :AAAAAB09:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12108 osp_idx=0 osp_ver=352540 osp_pg=0 (spawn #330450) 2025-06-28 07:13:27.428398 :AAAAAB0A: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-28 07:13:27.428399 :AAAAAB0B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=150 time=4070550625 2025-06-28 07:13:27.428399 :AAAAAB0C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 07:13:27.428399 :AAAAAB0D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 07:13:27.428400 :AAAAAB0E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 07:13:27.428400 :AAAAAB0F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 07:13:27.428400 :AAAAAB10:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 07:13:27.428885 :AAAAAB11: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-28 07:13:27.428935 :AAAAAB1A: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-28 07:23:28.308384 :AAAB73E0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 07:23:28.739076 :AAAB7411:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 07:23:28.730 2025-06-28 07:23:28.739078 :AAAB7412:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17876 pso_num=22 pso_serial#=59 2025-06-28 07:23:28.739213 :AAAB7413:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=17876 (legacy spawn) 2025-06-28 07:23:28.745584 :AAAB7414:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-28 07:23:28.745767 :AAAB7419:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-28 07:23:28.746577 :AAAB741E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 07:23:28.797710 :AAAB7459:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 07:23:28.793 2025-06-28 07:23:28.797712 :AAAB745A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17820 pso_num=22 pso_serial#=60 2025-06-28 07:23:28.797848 :AAAB745B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17820 osp_idx=0 osp_ver=352542 osp_pg=0 (spawn #330472) 2025-06-28 07:23:28.797849 :AAAB745C: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-28 07:23:28.797849 :AAAB745D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=151 time=4071151985 2025-06-28 07:23:28.797849 :AAAB745E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 07:23:28.797850 :AAAB745F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 07:23:28.797850 :AAAB7460:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 07:23:28.797850 :AAAB7461:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 07:23:28.797851 :AAAB7462:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 07:23:28.798376 :AAAB7463: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-28 07:23:28.798430 :AAAB7469: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-28 07:33:29.602042 :AAAC3D40:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 07:33:30.023207 :AAAC3D83:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 07:33:30.018 2025-06-28 07:33:30.023208 :AAAC3D84:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9528 pso_num=22 pso_serial#=61 2025-06-28 07:33:30.023348 :AAAC3D85:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9528 osp_idx=0 osp_ver=352543 osp_pg=0 (spawn #330495) 2025-06-28 07:33:30.023349 :AAAC3D86: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-28 07:33:30.023349 :AAAC3D87:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=152 time=4071753219 2025-06-28 07:33:30.023349 :AAAC3D88:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 07:33:30.023350 :AAAC3D89:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 07:33:30.023350 :AAAC3D8A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 07:33:30.023350 :AAAC3D8B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 07:33:30.023350 :AAAC3D8C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 07:33:30.023858 :AAAC3D8D: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-28 07:33:30.023902 :AAAC3D95: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-28 07:43:30.787602 :AAAD06E4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 07:43:31.276637 :AAAD074F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 07:43:31.272 2025-06-28 07:43:31.276639 :AAAD0750:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16600 pso_num=22 pso_serial#=62 2025-06-28 07:43:31.276773 :AAAD0751:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16600 osp_idx=0 osp_ver=352544 osp_pg=0 (spawn #330518) 2025-06-28 07:43:31.276774 :AAAD0752: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-28 07:43:31.276774 :AAAD0753:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=153 time=4072354469 2025-06-28 07:43:31.276775 :AAAD0754:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 07:43:31.276775 :AAAD0755:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 07:43:31.276775 :AAAD0756:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 07:43:31.276776 :AAAD0757:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 07:43:31.276776 :AAAD0758:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 07:43:31.277258 :AAAD0759: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-28 07:43:31.277306 :AAAD0760: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-28 07:53:32.068062 :AAADD248:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-28 07:53:32.416543 :AAADD28D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-28 07:53:32.411 2025-06-28 07:53:32.416545 :AAADD28E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=1740 pso_num=22 pso_serial#=63 2025-06-28 07:53:32.416718 :AAADD28F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=1740 osp_idx=0 osp_ver=352545 osp_pg=0 (spawn #330540) 2025-06-28 07:53:32.416719 :AAADD290: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-28 07:53:32.416720 :AAADD291:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=154 time=4072955610 2025-06-28 07:53:32.416720 :AAADD292:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 07:53:32.416721 :AAADD293:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 07:53:32.416721 :AAADD294:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 07:53:32.416721 :AAADD295:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 07:53:32.416722 :AAADD296:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 07:53:32.417246 :AAADD297: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-28 07:53:32.417296 :AAADD2A1: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-28 08:00:11.696005 :AAAE57AA: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 1740, W000)