Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250515080242\orcl_w000_7552_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:37388M/63366M, Ph+PgF:44630M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 7552, image: ORACLE.EXE (W000) *** 2025-05-15 08:02:42.826 *** SESSION ID:(177.60281) 2025-05-15 08:02:42.826 *** 2025-05-15 08:02:42.826 Process diagnostic dump for ORACLE.EXE (W000), OS id=7552, pid: 22, proc_ser: 86, sid: 177, sess_ser: 60281 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=41 seq_num=42 snap_id=1 wait times: snap=2.754692 sec, exc=2.754692 sec, total=2.754692 sec wait times: max=5.000000 sec, heur=2.754692 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.002098 sec since current wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x1, filetype=0x2 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000095 sec, exc=0.000095 sec, total=0.000095 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000184 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=39 seq_num=40 snap_id=1 wait times: snap=1.978914 sec, exc=1.978914 sec, total=1.978914 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000083 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=38 seq_num=39 snap_id=1 wait times: snap=5.001093 sec, exc=5.001093 sec, total=5.001093 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=37 seq_num=38 snap_id=1 wait times: snap=5.004595 sec, exc=5.004595 sec, total=5.004595 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000044 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=36 seq_num=37 snap_id=1 wait times: snap=5.014744 sec, exc=5.014744 sec, total=5.014744 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=35 seq_num=36 snap_id=1 wait times: snap=5.014719 sec, exc=5.014719 sec, total=5.014719 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=5.005153 sec, exc=5.005153 sec, total=5.005153 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=5.011588 sec, exc=5.011588 sec, total=5.011588 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=5.003103 sec, exc=5.003103 sec, total=5.003103 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.008672 sec, exc=5.008672 sec, total=5.008672 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 60281 --------------------------------------------------- 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:00:42 - 08:02:42] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-15 08:02:42.826 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 7552, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-15 05:29:07.034865 :97439AFC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 05:29:07.035380 :97439AFD: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-05-15 05:29:07.035423 :97439B04: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-05-15 05:39:07.960696 :974465D8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 05:39:08.559129 :9744663A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 05:39:08.554 2025-05-15 05:39:08.559130 :9744663B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9580 pso_num=22 pso_serial#=73 2025-05-15 05:39:08.559275 :9744663C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9580 osp_idx=0 osp_ver=194893 osp_pg=0 (spawn #183554) 2025-05-15 05:39:08.559276 :9744663D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 05:39:08.559276 :9744663E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=114 time=263358422 2025-05-15 05:39:08.559276 :9744663F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 05:39:08.559277 :97446640:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 05:39:08.559277 :97446641:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 05:39:08.559277 :97446642:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 05:39:08.559278 :97446643:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 05:39:08.559775 :97446644: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-05-15 05:39:08.559817 :9744664B: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-05-15 05:49:09.541455 :974530B6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 05:49:09.936747 :97453115:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 05:49:09.932 2025-05-15 05:49:09.936750 :97453116:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6652 pso_num=22 pso_serial#=74 2025-05-15 05:49:09.936880 :97453117:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6652 osp_idx=0 osp_ver=194894 osp_pg=0 (spawn #183577) 2025-05-15 05:49:09.936880 :97453118:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 05:49:09.936880 :97453119:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=115 time=263959813 2025-05-15 05:49:09.936881 :9745311A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 05:49:09.936881 :9745311B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 05:49:09.936882 :9745311C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 05:49:09.936882 :9745311D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 05:49:09.936883 :9745311E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 05:49:09.937469 :9745311F: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-05-15 05:49:09.937512 :97453127: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-05-15 05:59:10.838358 :9745F943:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 05:59:11.374536 :9745F99D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 05:59:11.370 2025-05-15 05:59:11.374538 :9745F99E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12944 pso_num=22 pso_serial#=75 2025-05-15 05:59:11.374677 :9745F99F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12944 osp_idx=0 osp_ver=194895 osp_pg=0 (spawn #183600) 2025-05-15 05:59:11.374677 :9745F9A0:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 05:59:11.374678 :9745F9A1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=116 time=264561250 2025-05-15 05:59:11.374678 :9745F9A2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 05:59:11.374678 :9745F9A3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 05:59:11.374679 :9745F9A4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 05:59:11.374679 :9745F9A5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 05:59:11.374679 :9745F9A6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 05:59:11.375180 :9745F9A7: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-05-15 05:59:11.375232 :9745F9AE: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-05-15 06:01:14.033904 :974624E7: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-05-15 06:09:12.814728 :9746CE1A: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-05-15 06:19:13.734491 :97479603:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 06:19:14.363945 :97479642:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 06:19:14.359 2025-05-15 06:19:14.363947 :97479643:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12980 pso_num=22 pso_serial#=76 2025-05-15 06:19:14.364077 :97479644:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12980 osp_idx=0 osp_ver=194896 osp_pg=0 (spawn #183647) 2025-05-15 06:19:14.364079 :97479645:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 06:19:14.364079 :97479646:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=117 time=265764235 2025-05-15 06:19:14.364079 :97479647:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 06:19:14.364080 :97479648:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 06:19:14.364080 :97479649:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 06:19:14.364080 :9747964A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 06:19:14.364081 :9747964B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 06:19:14.364555 :9747964C: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-05-15 06:19:14.364602 :97479656: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-05-15 06:29:15.273303 :97485EEC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 06:29:15.809326 :97485F35:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 06:29:15.804 2025-05-15 06:29:15.809328 :97485F36:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10636 pso_num=22 pso_serial#=77 2025-05-15 06:29:15.809466 :97485F37:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10636 osp_idx=0 osp_ver=194897 osp_pg=0 (spawn #183670) 2025-05-15 06:29:15.809467 :97485F38:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 06:29:15.809468 :97485F39:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=118 time=266365672 2025-05-15 06:29:15.809468 :97485F3A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 06:29:15.809468 :97485F3B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 06:29:15.809469 :97485F3C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 06:29:15.809469 :97485F3D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 06:29:15.809470 :97485F3E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 06:29:15.809949 :97485F3F: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-05-15 06:29:15.809994 :97485F46: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-05-15 06:39:16.763320 :97492800:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 06:39:17.205551 :9749282E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 06:39:17.201 2025-05-15 06:39:17.205553 :9749282F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9460 pso_num=22 pso_serial#=78 2025-05-15 06:39:17.205689 :97492830:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9460 osp_idx=0 osp_ver=194898 osp_pg=0 (spawn #183693) 2025-05-15 06:39:17.205689 :97492831:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 06:39:17.205690 :97492832:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=119 time=266967079 2025-05-15 06:39:17.205690 :97492833:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 06:39:17.205691 :97492834:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 06:39:17.205691 :97492835:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 06:39:17.205691 :97492836:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 06:39:17.205692 :97492837:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 06:39:17.206193 :97492838: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-05-15 06:39:17.206239 :97492840: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-05-15 06:49:18.082444 :9749F0D1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 06:49:18.600989 :9749F111:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 06:49:18.596 2025-05-15 06:49:18.600992 :9749F112:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11720 pso_num=22 pso_serial#=79 2025-05-15 06:49:18.601126 :9749F113:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11720 osp_idx=0 osp_ver=194899 osp_pg=0 (spawn #183716) 2025-05-15 06:49:18.601127 :9749F114:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 06:49:18.601128 :9749F115:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=120 time=267568469 2025-05-15 06:49:18.601128 :9749F116:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 06:49:18.601128 :9749F117:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 06:49:18.601129 :9749F118:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 06:49:18.601129 :9749F119:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 06:49:18.601130 :9749F11A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 06:49:18.601621 :9749F11B: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-05-15 06:49:18.601665 :9749F122: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-05-15 06:59:19.577345 :974AB8D5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 06:59:19.972632 :974AB90E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 06:59:19.967 2025-05-15 06:59:19.972633 :974AB90F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13096 pso_num=22 pso_serial#=80 2025-05-15 06:59:19.972768 :974AB910:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13096 osp_idx=0 osp_ver=194900 osp_pg=0 (spawn #183739) 2025-05-15 06:59:19.972768 :974AB911:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 06:59:19.972769 :974AB912:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=121 time=268169844 2025-05-15 06:59:19.972769 :974AB913:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 06:59:19.972769 :974AB914:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 06:59:19.972770 :974AB915:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 06:59:19.972770 :974AB916:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 06:59:19.972770 :974AB917:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 06:59:19.973257 :974AB918: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-05-15 06:59:19.973305 :974AB91E: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-05-15 07:09:20.959707 :974B8C00:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 07:09:21.292581 :974B8C40:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 07:09:21.287 2025-05-15 07:09:21.292583 :974B8C41:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12144 pso_num=22 pso_serial#=81 2025-05-15 07:09:21.292722 :974B8C42:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12144 osp_idx=0 osp_ver=194901 osp_pg=0 (spawn #183764) 2025-05-15 07:09:21.292722 :974B8C43:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 07:09:21.292723 :974B8C44:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=122 time=268771157 2025-05-15 07:09:21.292723 :974B8C45:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 07:09:21.292723 :974B8C46:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 07:09:21.292724 :974B8C47:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 07:09:21.292724 :974B8C48:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 07:09:21.292724 :974B8C49:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 07:09:21.293214 :974B8C4A: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-05-15 07:09:21.293257 :974B8C51: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-05-15 07:19:22.180572 :974C549A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 07:19:22.591573 :974C54DC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 07:19:22.586 2025-05-15 07:19:22.591575 :974C54DD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11536 pso_num=22 pso_serial#=82 2025-05-15 07:19:22.591720 :974C54DE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11536 osp_idx=0 osp_ver=194902 osp_pg=0 (spawn #183787) 2025-05-15 07:19:22.591720 :974C54DF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 07:19:22.591721 :974C54E0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=123 time=269372454 2025-05-15 07:19:22.591721 :974C54E1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 07:19:22.591722 :974C54E2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 07:19:22.591722 :974C54E3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 07:19:22.591722 :974C54E4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 07:19:22.591722 :974C54E5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 07:19:22.592224 :974C54E6: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-05-15 07:19:22.592269 :974C54EF: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-05-15 07:29:23.502818 :974D1D15:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 07:29:23.935338 :974D1D72:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 07:29:23.934 2025-05-15 07:29:23.935340 :974D1D73:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12136 pso_num=22 pso_serial#=83 2025-05-15 07:29:23.935483 :974D1D74:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12136 osp_idx=0 osp_ver=194903 osp_pg=0 (spawn #183810) 2025-05-15 07:29:23.935484 :974D1D75:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 07:29:23.935484 :974D1D76:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=124 time=269973797 2025-05-15 07:29:23.935485 :974D1D77:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 07:29:23.935485 :974D1D78:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 07:29:23.935485 :974D1D79:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 07:29:23.935486 :974D1D7A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 07:29:23.935486 :974D1D7B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 07:29:23.935987 :974D1D7C: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-05-15 07:29:23.936036 :974D1D86: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-05-15 07:39:24.948797 :974DE5AD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 07:39:25.266138 :974DE5F1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 07:39:25.261 2025-05-15 07:39:25.266141 :974DE5F2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13264 pso_num=22 pso_serial#=84 2025-05-15 07:39:25.266273 :974DE5F3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13264 osp_idx=0 osp_ver=194904 osp_pg=0 (spawn #183832) 2025-05-15 07:39:25.266274 :974DE5F4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 07:39:25.266276 :974DE5F5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=125 time=270575141 2025-05-15 07:39:25.266276 :974DE5F6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 07:39:25.266277 :974DE5F7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 07:39:25.266277 :974DE5F8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 07:39:25.266277 :974DE5F9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 07:39:25.266277 :974DE5FA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 07:39:25.266837 :974DE5FB: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-05-15 07:39:25.266881 :974DE603: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-05-15 07:49:26.207560 :974EAEC8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 07:49:26.571494 :974EAF15:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 07:49:26.566 2025-05-15 07:49:26.571496 :974EAF16:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12448 pso_num=22 pso_serial#=85 2025-05-15 07:49:26.571629 :974EAF17:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12448 osp_idx=0 osp_ver=194905 osp_pg=0 (spawn #183855) 2025-05-15 07:49:26.571630 :974EAF18:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 07:49:26.571630 :974EAF19:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=126 time=271176438 2025-05-15 07:49:26.571631 :974EAF1A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 07:49:26.571631 :974EAF1B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 07:49:26.571631 :974EAF1C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 07:49:26.571632 :974EAF1D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 07:49:26.571632 :974EAF1E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 07:49:26.572118 :974EAF1F: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-05-15 07:49:26.572183 :974EAF29: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-05-15 07:59:27.449955 :974F7683:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-15 07:59:27.814090 :974F76C4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-15 07:59:27.809 2025-05-15 07:59:27.814092 :974F76C5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7552 pso_num=22 pso_serial#=86 2025-05-15 07:59:27.814225 :974F76C6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7552 osp_idx=0 osp_ver=194906 osp_pg=0 (spawn #183878) 2025-05-15 07:59:27.814225 :974F76C7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 07:59:27.814225 :974F76C8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=127 time=271777688 2025-05-15 07:59:27.814226 :974F76C9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 07:59:27.814226 :974F76CA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 07:59:27.814226 :974F76CB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 07:59:27.814227 :974F76CC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 07:59:27.814227 :974F76CD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 07:59:27.814709 :974F76CE: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-05-15 07:59:27.814753 :974F76D6: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-05-15 08:02:40.073489 :974FF17E: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: 7552, W000)