Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250822081034\orcl_w000_21128_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:35303M/63366M, Ph+PgF:40458M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 21128, image: ORACLE.EXE (W000) *** 2025-08-22 08:10:34.642 *** SESSION ID:(177.36885) 2025-08-22 08:10:34.642 *** 2025-08-22 08:10:34.642 Process diagnostic dump for ORACLE.EXE (W000), OS id=21128, pid: 22, proc_ser: 161, sid: 177, sess_ser: 36885 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=120 seq_num=121 snap_id=1 wait times: snap=2.570801 sec, exc=2.570801 sec, total=2.570801 sec wait times: max=5.000000 sec, heur=2.570801 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.002016 sec since current wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x1, filetype=0x2 wait_id=119 seq_num=120 snap_id=1 wait times: snap=0.000099 sec, exc=0.000099 sec, total=0.000099 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000176 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=118 seq_num=119 snap_id=1 wait times: snap=2.628558 sec, exc=2.628558 sec, total=2.628558 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 2: 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.010139 sec, exc=5.010139 sec, total=5.010139 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 3: 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.014736 sec, exc=5.014736 sec, total=5.014736 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 4: 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.004603 sec, exc=5.004603 sec, total=5.004603 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 5: 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.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.000034 sec of elapsed time 6: 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.007248 sec, exc=5.007248 sec, total=5.007248 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=112 seq_num=113 snap_id=1 wait times: snap=5.001446 sec, exc=5.001446 sec, total=5.001446 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: 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.012580 sec, exc=5.012580 sec, total=5.012580 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=110 seq_num=111 snap_id=1 wait times: snap=5.012388 sec, exc=5.012388 sec, total=5.012388 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time Sampled Session History of session 177 serial 36885 --------------------------------------------------- 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:08:34 - 08:10:34] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-22 08:10:34.642 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 21128, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-22 05:50:26.419691 :C30105FD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21804 osp_idx=0 osp_ver=540054 osp_pg=0 (spawn #513568) 2025-08-22 05:50:26.419691 :C30105FE: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-22 05:50:26.419692 :C30105FF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=140 time=227528424 2025-08-22 05:50:26.419692 :C3010600:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 05:50:26.419693 :C3010601:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 05:50:26.419693 :C3010602:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 05:50:26.419693 :C3010603:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 05:50:26.419693 :C3010604:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 05:50:26.420176 :C3010605: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-22 05:50:26.420218 :C301060E: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-22 06:00:27.270906 :C301CC03:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 06:00:27.760071 :C301CC45:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 06:00:27.755 2025-08-22 06:00:27.760073 :C301CC46:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22404 pso_num=22 pso_serial#=148 2025-08-22 06:00:27.760209 :C301CC47:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22404 osp_idx=0 osp_ver=540055 osp_pg=0 (spawn #513590) 2025-08-22 06:00:27.760210 :C301CC48: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-22 06:00:27.760210 :C301CC49:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=141 time=228129768 2025-08-22 06:00:27.760211 :C301CC4A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 06:00:27.760211 :C301CC4B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 06:00:27.760211 :C301CC4C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 06:00:27.760212 :C301CC4D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 06:00:27.760212 :C301CC4E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 06:00:27.760703 :C301CC4F: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-22 06:00:27.760747 :C301CC56: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-22 06:06:51.811234 :C30252C9: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-22 06:09:32.012121 :C30287D0:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=111 seq_num=112 snap_id=1 2025-08-22 06:09:32.012126 :C30287D1:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=111 seq_num=112 snap_id=1 2025-08-22 06:09:32.012126 :C30287D2:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=4, exc=4, tot=4 2025-08-22 06:09:32.012134 :C30287D7: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-22 06:10:29.150598 :C3029A6F: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-22 06:20:30.071650 :C3036288:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 06:20:30.466967 :C30362CD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 06:20:30.461 2025-08-22 06:20:30.466968 :C30362CE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18812 pso_num=22 pso_serial#=149 2025-08-22 06:20:30.467106 :C30362CF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18812 osp_idx=0 osp_ver=540056 osp_pg=0 (spawn #513638) 2025-08-22 06:20:30.467107 :C30362D0: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-22 06:20:30.467107 :C30362D1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=142 time=229332471 2025-08-22 06:20:30.467108 :C30362D2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 06:20:30.467108 :C30362D3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 06:20:30.467108 :C30362D4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 06:20:30.467109 :C30362D5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 06:20:30.467109 :C30362D6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 06:20:30.467615 :C30362D7: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-22 06:20:30.467656 :C30362DE: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-22 06:30:31.301459 :C304285E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 06:30:31.822208 :C304289A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 06:30:31.816 2025-08-22 06:30:31.822210 :C304289B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19396 pso_num=22 pso_serial#=150 2025-08-22 06:30:31.822355 :C304289C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19396 osp_idx=0 osp_ver=540057 osp_pg=0 (spawn #513660) 2025-08-22 06:30:31.822356 :C304289D: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-22 06:30:31.822357 :C304289E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=143 time=229933830 2025-08-22 06:30:31.822357 :C304289F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 06:30:31.822358 :C30428A0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 06:30:31.822358 :C30428A1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 06:30:31.822358 :C30428A2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 06:30:31.822359 :C30428A3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 06:30:31.822879 :C30428A4: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-22 06:30:31.822930 :C30428AC: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-22 06:40:32.829584 :C304EEC6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 06:40:33.219483 :C304EF0B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 06:40:33.214 2025-08-22 06:40:33.219485 :C304EF0C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14636 pso_num=22 pso_serial#=151 2025-08-22 06:40:33.219633 :C304EF0D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14636 osp_idx=0 osp_ver=540058 osp_pg=0 (spawn #513683) 2025-08-22 06:40:33.219634 :C304EF0E: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-22 06:40:33.219634 :C304EF0F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=144 time=230535237 2025-08-22 06:40:33.219635 :C304EF10:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 06:40:33.219635 :C304EF11:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 06:40:33.219635 :C304EF12:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 06:40:33.219636 :C304EF13:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 06:40:33.219636 :C304EF14:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 06:40:33.220135 :C304EF15: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-22 06:40:33.220178 :C304EF1C: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-22 06:50:34.102062 :C305B46F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 06:50:34.559921 :C305B4A3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 06:50:34.555 2025-08-22 06:50:34.559924 :C305B4A4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19680 pso_num=22 pso_serial#=152 2025-08-22 06:50:34.560056 :C305B4A5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19680 osp_idx=0 osp_ver=540059 osp_pg=0 (spawn #513706) 2025-08-22 06:50:34.560057 :C305B4A6: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-22 06:50:34.560058 :C305B4A7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=145 time=231136565 2025-08-22 06:50:34.560058 :C305B4A8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 06:50:34.560059 :C305B4A9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 06:50:34.560059 :C305B4AA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 06:50:34.560059 :C305B4AB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 06:50:34.560060 :C305B4AC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 06:50:34.560549 :C305B4AD: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-22 06:50:34.560591 :C305B4B6: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-22 07:00:35.409668 :C3067B25:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:00:35.867466 :C3067B6A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:00:35.862 2025-08-22 07:00:35.867468 :C3067B6B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4492 pso_num=22 pso_serial#=153 2025-08-22 07:00:35.867605 :C3067B6C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4492 osp_idx=0 osp_ver=540060 osp_pg=0 (spawn #513728) 2025-08-22 07:00:35.867606 :C3067B6D: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-22 07:00:35.867606 :C3067B6E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=146 time=231737877 2025-08-22 07:00:35.867607 :C3067B6F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 07:00:35.867607 :C3067B70:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 07:00:35.867607 :C3067B71:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 07:00:35.867607 :C3067B72:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 07:00:35.867607 :C3067B73:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 07:00:35.868101 :C3067B74: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-22 07:00:35.868148 :C3067B7A: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-22 07:10:36.733579 :C30748A1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:10:37.191552 :C30748DE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:10:37.187 2025-08-22 07:10:37.191554 :C30748DF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20460 pso_num=22 pso_serial#=154 2025-08-22 07:10:37.191703 :C30748E0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20460 osp_idx=0 osp_ver=540061 osp_pg=0 (spawn #513754) 2025-08-22 07:10:37.191704 :C30748E1: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-22 07:10:37.191704 :C30748E2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=147 time=232339205 2025-08-22 07:10:37.191704 :C30748E3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 07:10:37.191705 :C30748E4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 07:10:37.191705 :C30748E5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 07:10:37.191706 :C30748E6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 07:10:37.191706 :C30748E7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 07:10:37.192207 :C30748E8: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-22 07:10:37.192251 :C30748EF: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-22 07:20:38.082455 :C3081196:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:20:38.478081 :C30811D7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:20:38.472 2025-08-22 07:20:38.478083 :C30811D8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22316 pso_num=22 pso_serial#=155 2025-08-22 07:20:38.478227 :C30811D9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22316 osp_idx=0 osp_ver=540062 osp_pg=0 (spawn #513777) 2025-08-22 07:20:38.478228 :C30811DA: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-22 07:20:38.478228 :C30811DB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=148 time=232940487 2025-08-22 07:20:38.478228 :C30811DC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 07:20:38.478229 :C30811DD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 07:20:38.478229 :C30811DE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 07:20:38.478229 :C30811DF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 07:20:38.478230 :C30811E0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 07:20:38.478749 :C30811E1: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-22 07:20:38.478794 :C30811E8: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-22 07:30:39.368555 :C308D764:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:30:39.748166 :C308D799:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:30:39.743 2025-08-22 07:30:39.748168 :C308D79A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21668 pso_num=22 pso_serial#=156 2025-08-22 07:30:39.748306 :C308D79B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21668 osp_idx=0 osp_ver=540063 osp_pg=0 (spawn #513799) 2025-08-22 07:30:39.748307 :C308D79C: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-22 07:30:39.748307 :C308D79D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=149 time=233541752 2025-08-22 07:30:39.748307 :C308D79E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 07:30:39.748308 :C308D79F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 07:30:39.748308 :C308D7A0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 07:30:39.748308 :C308D7A1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 07:30:39.748308 :C308D7A2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 07:30:39.748798 :C308D7A3: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-22 07:30:39.748841 :C308D7A9: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-22 07:40:40.678469 :C3099DFA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:40:41.011420 :C3099E3A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:40:41.007 2025-08-22 07:40:41.011421 :C3099E3B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21076 pso_num=22 pso_serial#=157 2025-08-22 07:40:41.011564 :C3099E3C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21076 osp_idx=0 osp_ver=540064 osp_pg=0 (spawn #513822) 2025-08-22 07:40:41.011565 :C3099E3D: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-22 07:40:41.011565 :C3099E3E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=150 time=234143018 2025-08-22 07:40:41.011565 :C3099E3F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 07:40:41.011566 :C3099E40:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 07:40:41.011566 :C3099E41:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 07:40:41.011566 :C3099E42:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 07:40:41.011567 :C3099E43:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 07:40:41.012065 :C3099E44: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-22 07:40:41.012112 :C3099E4C: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-22 07:50:41.910716 :C30A641B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:50:42.028323 :C30A641E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:50:42.020 2025-08-22 07:50:42.028325 :C30A641F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20744 pso_num=22 pso_serial#=158 2025-08-22 07:50:42.028472 :C30A6420:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20744 (legacy spawn) 2025-08-22 07:50:42.034986 :C30A6421: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-08-22 07:50:42.035019 :C30A6424: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-08-22 07:50:42.035176 :C30A6427: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-08-22 07:50:42.036157 :C30A6438:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:50:42.050452 :C30A643B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:50:42.035 2025-08-22 07:50:42.050454 :C30A643C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22104 pso_num=22 pso_serial#=159 2025-08-22 07:50:42.050578 :C30A643D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22104 (legacy spawn) 2025-08-22 07:50:42.056735 :C30A643E: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-08-22 07:50:42.056912 :C30A6447: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-08-22 07:50:42.057702 :C30A6448:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 07:50:42.321820 :C30A6497:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 07:50:42.317 2025-08-22 07:50:42.321823 :C30A6498:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19784 pso_num=22 pso_serial#=160 2025-08-22 07:50:42.321961 :C30A6499:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19784 osp_idx=0 osp_ver=540067 osp_pg=0 (spawn #513845) 2025-08-22 07:50:42.321961 :C30A649A: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-22 07:50:42.321962 :C30A649B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=151 time=234744330 2025-08-22 07:50:42.321962 :C30A649C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 07:50:42.321962 :C30A649D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 07:50:42.321963 :C30A649E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 07:50:42.321963 :C30A649F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 07:50:42.321963 :C30A64A0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 07:50:42.322453 :C30A64A1: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-22 07:50:42.322510 :C30A64A7: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-22 08:00:43.103304 :C30B2AA7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-22 08:00:43.540035 :C30B2AF0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-22 08:00:43.535 2025-08-22 08:00:43.540037 :C30B2AF1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21128 pso_num=22 pso_serial#=161 2025-08-22 08:00:43.540172 :C30B2AF2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21128 osp_idx=0 osp_ver=540068 osp_pg=0 (spawn #513867) 2025-08-22 08:00:43.540173 :C30B2AF3: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-22 08:00:43.540173 :C30B2AF4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=152 time=235345549 2025-08-22 08:00:43.540174 :C30B2AF5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-22 08:00:43.540174 :C30B2AF6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-22 08:00:43.540175 :C30B2AF7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-22 08:00:43.540176 :C30B2AF8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-22 08:00:43.540177 :C30B2AF9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-22 08:00:43.540699 :C30B2AFA: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-22 08:00:43.540742 :C30B2B03: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-22 08:10:32.074810 :C30C2E85: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: 21128, W000)