Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250715220007\orcl_w000_12796_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:36294M/63366M, Ph+PgF:42237M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 12796, image: ORACLE.EXE (W000) *** 2025-07-15 22:00:07.681 *** SESSION ID:(177.53805) 2025-07-15 22:00:07.681 *** 2025-07-15 22:00:07.681 Process diagnostic dump for ORACLE.EXE (W000), OS id=12796, pid: 22, proc_ser: 43, sid: 177, sess_ser: 53805 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=1.099440 sec, exc=1.099440 sec, total=1.099440 sec wait times: max=5.000000 sec, heur=1 min 56 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.000030 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.014762 sec, exc=5.014762 sec, total=5.014762 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000039 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.015240 sec, exc=5.015240 sec, total=5.015240 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.003224 sec, exc=5.003224 sec, total=5.003224 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=20 seq_num=21 snap_id=1 wait times: snap=5.012935 sec, exc=5.012935 sec, total=5.012935 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.009188 sec, exc=5.009188 sec, total=5.009188 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.010129 sec, exc=5.010129 sec, total=5.010129 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000039 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.014731 sec, exc=5.014731 sec, total=5.014731 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=5.001696 sec, exc=5.001696 sec, total=5.001696 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=5.001273 sec, exc=5.001273 sec, total=5.001273 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=5.000258 sec, exc=5.000258 sec, total=5.000258 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time Sampled Session History of session 177 serial 53805 --------------------------------------------------- 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 --------------------------------------------------- [117 samples, 21:58:11 - 22:00:07] idle wait at each sample [session created at: 21:58:11] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-15 22:00:07.681 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 12796, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-15 19:27:51.363911 :B271F6D2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 19:27:51.363911 :B271F6D3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 19:27:51.364406 :B271F6D4: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-07-15 19:27:51.364454 :B271F6DE: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-07-15 19:37:52.275846 :B272BD2F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 19:37:52.624340 :B272BD7A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 19:37:52.619 2025-07-15 19:37:52.624342 :B272BD7B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13012 pso_num=22 pso_serial#=30 2025-07-15 19:37:52.624481 :B272BD7C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13012 osp_idx=0 osp_ver=408357 osp_pg=0 (spawn #388839) 2025-07-15 19:37:52.624482 :B272BD7D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 19:37:52.624482 :B272BD7E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=116 time=1289048517 2025-07-15 19:37:52.624482 :B272BD7F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 19:37:52.624483 :B272BD80:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 19:37:52.624483 :B272BD81:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 19:37:52.624485 :B272BD82:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 19:37:52.624485 :B272BD83:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 19:37:52.625002 :B272BD84: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-07-15 19:37:52.625046 :B272BD8C: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-07-15 19:47:53.568229 :B273835B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 19:47:54.009252 :B27383BB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 19:47:54.005 2025-07-15 19:47:54.009254 :B27383BC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9112 pso_num=22 pso_serial#=31 2025-07-15 19:47:54.009393 :B27383BD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9112 osp_idx=0 osp_ver=408358 osp_pg=0 (spawn #388860) 2025-07-15 19:47:54.009394 :B27383BE:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 19:47:54.009394 :B27383BF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=117 time=1289649908 2025-07-15 19:47:54.009395 :B27383C0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 19:47:54.009395 :B27383C1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 19:47:54.009395 :B27383C2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 19:47:54.009396 :B27383C3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 19:47:54.009396 :B27383C4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 19:47:54.009893 :B27383C5: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-07-15 19:47:54.009939 :B27383CC: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-07-15 19:57:54.860217 :B274486A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 19:57:55.380601 :B27448D8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 19:57:55.376 2025-07-15 19:57:55.380603 :B27448D9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2848 pso_num=22 pso_serial#=32 2025-07-15 19:57:55.380734 :B27448DA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2848 osp_idx=0 osp_ver=408359 osp_pg=0 (spawn #388883) 2025-07-15 19:57:55.380734 :B27448DB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 19:57:55.380735 :B27448DC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=118 time=1290251283 2025-07-15 19:57:55.380735 :B27448DD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 19:57:55.380735 :B27448DE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 19:57:55.380736 :B27448DF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 19:57:55.380736 :B27448E0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 19:57:55.380737 :B27448E1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 19:57:55.381216 :B27448E2: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-07-15 19:57:55.381263 :B27448E9: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-07-15 20:07:56.240939 :B27518C6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 20:07:56.668660 :B2751921:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 20:07:56.663 2025-07-15 20:07:56.668662 :B2751922:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9276 pso_num=22 pso_serial#=33 2025-07-15 20:07:56.668803 :B2751923:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9276 osp_idx=0 osp_ver=408360 osp_pg=0 (spawn #388909) 2025-07-15 20:07:56.668803 :B2751924:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 20:07:56.668804 :B2751925:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=119 time=1290852564 2025-07-15 20:07:56.668804 :B2751926:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 20:07:56.668804 :B2751927:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 20:07:56.668805 :B2751928:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 20:07:56.668805 :B2751929:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 20:07:56.668806 :B275192A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 20:07:56.669297 :B275192B: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-07-15 20:07:56.669347 :B2751933: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-07-15 20:17:57.618246 :B275DDCF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 20:17:58.023756 :B275DE3D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 20:17:58.018 2025-07-15 20:17:58.023759 :B275DE3E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18340 pso_num=22 pso_serial#=34 2025-07-15 20:17:58.023907 :B275DE3F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18340 osp_idx=0 osp_ver=408361 osp_pg=0 (spawn #388931) 2025-07-15 20:17:58.023908 :B275DE40:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 20:17:58.023908 :B275DE41:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=120 time=1291453923 2025-07-15 20:17:58.023908 :B275DE42:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 20:17:58.023909 :B275DE43:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 20:17:58.023909 :B275DE44:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 20:17:58.023909 :B275DE45:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 20:17:58.023910 :B275DE46:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 20:17:58.024408 :B275DE47: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-07-15 20:17:58.024454 :B275DE4E: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-07-15 20:27:58.914274 :B276A3AB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 20:27:59.294167 :B276A410:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 20:27:59.289 2025-07-15 20:27:59.294169 :B276A411:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17364 pso_num=22 pso_serial#=35 2025-07-15 20:27:59.294313 :B276A412:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17364 osp_idx=0 osp_ver=408362 osp_pg=0 (spawn #388954) 2025-07-15 20:27:59.294314 :B276A413:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 20:27:59.294314 :B276A414:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=121 time=1292055189 2025-07-15 20:27:59.294315 :B276A415:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 20:27:59.294315 :B276A416:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 20:27:59.294315 :B276A417:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 20:27:59.294316 :B276A418:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 20:27:59.294316 :B276A419:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 20:27:59.294830 :B276A41A: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-07-15 20:27:59.294875 :B276A421: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-07-15 20:38:00.189505 :B2776904:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 20:38:00.631780 :B277693B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 20:38:00.627 2025-07-15 20:38:00.631782 :B277693C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17248 pso_num=22 pso_serial#=36 2025-07-15 20:38:00.631920 :B277693D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17248 osp_idx=0 osp_ver=408363 osp_pg=0 (spawn #388977) 2025-07-15 20:38:00.631921 :B277693E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 20:38:00.631921 :B277693F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=122 time=1292656533 2025-07-15 20:38:00.631921 :B2776940:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 20:38:00.631922 :B2776941:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 20:38:00.631922 :B2776942:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 20:38:00.631922 :B2776943:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 20:38:00.631923 :B2776944:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 20:38:00.632417 :B2776945: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-07-15 20:38:00.632460 :B277694E: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-07-15 20:48:01.547353 :B2782E86:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 20:48:02.037230 :B2782EC1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 20:48:02.031 2025-07-15 20:48:02.037233 :B2782EC2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18044 pso_num=22 pso_serial#=37 2025-07-15 20:48:02.037379 :B2782EC3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18044 osp_idx=0 osp_ver=408364 osp_pg=0 (spawn #388999) 2025-07-15 20:48:02.037379 :B2782EC4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 20:48:02.037380 :B2782EC5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=123 time=1293257923 2025-07-15 20:48:02.037380 :B2782EC6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 20:48:02.037381 :B2782EC7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 20:48:02.037381 :B2782EC8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 20:48:02.037381 :B2782EC9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 20:48:02.037382 :B2782ECA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 20:48:02.037952 :B2782ECB: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-07-15 20:48:02.038026 :B2782ED5: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-07-15 20:58:02.981082 :B278F321:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 20:58:03.376415 :B278F365:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 20:58:03.372 2025-07-15 20:58:03.376417 :B278F366:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14620 pso_num=22 pso_serial#=38 2025-07-15 20:58:03.376548 :B278F367:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14620 osp_idx=0 osp_ver=408365 osp_pg=0 (spawn #389022) 2025-07-15 20:58:03.376549 :B278F368:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 20:58:03.376549 :B278F369:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=124 time=1293859267 2025-07-15 20:58:03.376549 :B278F36A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 20:58:03.376550 :B278F36B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 20:58:03.376550 :B278F36C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 20:58:03.376551 :B278F36D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 20:58:03.376551 :B278F36E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 20:58:03.377041 :B278F36F: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-07-15 20:58:03.377087 :B278F376: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-07-15 21:08:04.279174 :B279C3E4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 21:08:04.658874 :B279C41D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 21:08:04.653 2025-07-15 21:08:04.658876 :B279C41E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9724 pso_num=22 pso_serial#=39 2025-07-15 21:08:04.659014 :B279C41F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9724 osp_idx=0 osp_ver=408366 osp_pg=0 (spawn #389048) 2025-07-15 21:08:04.659015 :B279C420:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 21:08:04.659015 :B279C421:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=125 time=1294460548 2025-07-15 21:08:04.659015 :B279C422:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 21:08:04.659016 :B279C423:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 21:08:04.659016 :B279C424:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 21:08:04.659016 :B279C425:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 21:08:04.659017 :B279C426:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 21:08:04.659512 :B279C427: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-07-15 21:08:04.659560 :B279C42E: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-07-15 21:16:47.058100 :B27A6EA0: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-07-15 21:18:06.033866 :B27A8AB3: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-07-15 21:28:06.930454 :B27B4FAB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 21:28:07.403874 :B27B4FE1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 21:28:07.399 2025-07-15 21:28:07.403877 :B27B4FE2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13092 pso_num=22 pso_serial#=40 2025-07-15 21:28:07.404016 :B27B4FE3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13092 osp_idx=0 osp_ver=408367 osp_pg=0 (spawn #389092) 2025-07-15 21:28:07.404017 :B27B4FE4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 21:28:07.404018 :B27B4FE5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=126 time=1295663298 2025-07-15 21:28:07.404018 :B27B4FE6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 21:28:07.404018 :B27B4FE7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 21:28:07.404019 :B27B4FE8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 21:28:07.404019 :B27B4FE9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 21:28:07.404020 :B27B4FEA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 21:28:07.404512 :B27B4FEB: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-07-15 21:28:07.404556 :B27B4FF3: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-07-15 21:38:08.341164 :B27C14FE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 21:38:08.642835 :B27C1546:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 21:38:08.637 2025-07-15 21:38:08.642837 :B27C1547:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15876 pso_num=22 pso_serial#=41 2025-07-15 21:38:08.642977 :B27C1548:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15876 osp_idx=0 osp_ver=408368 osp_pg=0 (spawn #389115) 2025-07-15 21:38:08.642977 :B27C1549:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 21:38:08.642978 :B27C154A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=127 time=1296264533 2025-07-15 21:38:08.642978 :B27C154B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 21:38:08.642979 :B27C154C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 21:38:08.642979 :B27C154D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 21:38:08.642980 :B27C154E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 21:38:08.642980 :B27C154F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 21:38:08.643478 :B27C1550: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-07-15 21:38:08.643524 :B27C1557: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-07-15 21:48:09.662103 :B27CDA36:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 21:48:10.073131 :B27CDA77:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 21:48:10.068 2025-07-15 21:48:10.073134 :B27CDA78:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13012 pso_num=22 pso_serial#=42 2025-07-15 21:48:10.073309 :B27CDA79:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13012 osp_idx=0 osp_ver=408369 osp_pg=0 (spawn #389137) 2025-07-15 21:48:10.073310 :B27CDA7A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 21:48:10.073311 :B27CDA7B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=128 time=1296865970 2025-07-15 21:48:10.073311 :B27CDA7C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 21:48:10.073311 :B27CDA7D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 21:48:10.073312 :B27CDA7E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 21:48:10.073312 :B27CDA7F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 21:48:10.073312 :B27CDA80:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 21:48:10.073823 :B27CDA81: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-07-15 21:48:10.073867 :B27CDA88: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-07-15 21:58:11.091725 :B27DA022:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-15 21:58:11.409031 :B27DA060:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-15 21:58:11.404 2025-07-15 21:58:11.409033 :B27DA061:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12796 pso_num=22 pso_serial#=43 2025-07-15 21:58:11.409168 :B27DA062:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12796 osp_idx=0 osp_ver=408370 osp_pg=0 (spawn #389160) 2025-07-15 21:58:11.409169 :B27DA063:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-15 21:58:11.409169 :B27DA064:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=129 time=1297467298 2025-07-15 21:58:11.409170 :B27DA065:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-15 21:58:11.409170 :B27DA066:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-15 21:58:11.409170 :B27DA067:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-15 21:58:11.409171 :B27DA068:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-15 21:58:11.409171 :B27DA069:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-15 21:58:11.409660 :B27DA06A: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-07-15 21:58:11.409705 :B27DA071:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 12796, W000)