Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510060006\orcl_w000_7460_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:37502M/63366M, Ph+PgF:44881M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 7460, image: ORACLE.EXE (W000) *** 2025-05-10 06:00:06.119 *** SESSION ID:(177.10089) 2025-05-10 06:00:06.119 *** 2025-05-10 06:00:06.119 Process diagnostic dump for ORACLE.EXE (W000), OS id=7460, pid: 22, proc_ser: 47, sid: 177, sess_ser: 10089 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=206 seq_num=207 snap_id=1 wait times: snap=1.232970 sec, exc=1.232970 sec, total=1.232970 sec wait times: max=5.000000 sec, heur=14 min 39 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.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=205 seq_num=206 snap_id=1 wait times: snap=5.014755 sec, exc=5.014755 sec, total=5.014755 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=204 seq_num=205 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.000026 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=203 seq_num=204 snap_id=1 wait times: snap=5.005151 sec, exc=5.005151 sec, total=5.005151 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=202 seq_num=203 snap_id=1 wait times: snap=5.003361 sec, exc=5.003361 sec, total=5.003361 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=201 seq_num=202 snap_id=1 wait times: snap=5.000405 sec, exc=5.000405 sec, total=5.000405 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=200 seq_num=201 snap_id=1 wait times: snap=5.007711 sec, exc=5.007711 sec, total=5.007711 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=199 seq_num=200 snap_id=1 wait times: snap=5.004627 sec, exc=5.004627 sec, total=5.004627 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=198 seq_num=199 snap_id=1 wait times: snap=5.014740 sec, exc=5.014740 sec, total=5.014740 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=197 seq_num=198 snap_id=1 wait times: snap=5.004613 sec, exc=5.004613 sec, total=5.004613 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=196 seq_num=197 snap_id=1 wait times: snap=5.014742 sec, exc=5.014742 sec, total=5.014742 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time Sampled Session History of session 177 serial 10089 --------------------------------------------------- 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, 05:58:06 - 06:00:06] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 06:00:06.119 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 7460, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 03:22:48.833165 :950C65B5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 03:22:48.833165 :950C65B6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 03:22:48.833719 :950C65B7: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-10 03:22:48.833765 :950C65BF: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-10 03:32:49.674947 :950D2DD3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 03:32:50.189764 :950D2E33:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 03:32:50.185 2025-05-10 03:32:50.189766 :950D2E34:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9780 pso_num=22 pso_serial#=34 2025-05-10 03:32:50.189904 :950D2E35:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9780 osp_idx=0 osp_ver=173434 osp_pg=0 (spawn #166451) 2025-05-10 03:32:50.189905 :950D2E36: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-10 03:32:50.189906 :950D2E37:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=124 time=4118747359 2025-05-10 03:32:50.189906 :950D2E38:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 03:32:50.189906 :950D2E39:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 03:32:50.189907 :950D2E3A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 03:32:50.189907 :950D2E3B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 03:32:50.189907 :950D2E3C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 03:32:50.190405 :950D2E3D: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-10 03:32:50.190448 :950D2E44: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-10 03:42:51.158920 :950DF3C0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 03:42:51.444844 :950DF430:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 03:42:51.440 2025-05-10 03:42:51.444846 :950DF431:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10624 pso_num=22 pso_serial#=35 2025-05-10 03:42:51.444983 :950DF432:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10624 osp_idx=0 osp_ver=173435 osp_pg=0 (spawn #166474) 2025-05-10 03:42:51.444983 :950DF433: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-10 03:42:51.444984 :950DF434:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=125 time=4119348609 2025-05-10 03:42:51.444984 :950DF435:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 03:42:51.444984 :950DF436:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 03:42:51.444985 :950DF437:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 03:42:51.444985 :950DF438:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 03:42:51.444985 :950DF439:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 03:42:51.445482 :950DF43A: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-10 03:42:51.445536 :950DF444: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-10 03:45:26.122964 :950E2781: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-10 03:52:52.695362 :950EBA5F: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-10 04:02:53.599787 :950F80BD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 04:02:53.995042 :950F813D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 04:02:53.990 2025-05-10 04:02:53.995045 :950F813E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2984 pso_num=22 pso_serial#=36 2025-05-10 04:02:53.995180 :950F813F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2984 osp_idx=0 osp_ver=173436 osp_pg=0 (spawn #166522) 2025-05-10 04:02:53.995180 :950F8140: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-10 04:02:53.995181 :950F8141:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=126 time=4120551156 2025-05-10 04:02:53.995181 :950F8142:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 04:02:53.995181 :950F8143:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 04:02:53.995182 :950F8144:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 04:02:53.995182 :950F8145:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 04:02:53.995182 :950F8146:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 04:02:53.995665 :950F8147: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-10 04:02:53.995711 :950F8150: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-10 04:12:54.887960 :95104EFE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 04:12:55.316613 :95104F6B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 04:12:55.312 2025-05-10 04:12:55.316615 :95104F6C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11752 pso_num=22 pso_serial#=37 2025-05-10 04:12:55.316756 :95104F6D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11752 osp_idx=0 osp_ver=173437 osp_pg=0 (spawn #166546) 2025-05-10 04:12:55.316757 :95104F6E: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-10 04:12:55.316757 :95104F6F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=127 time=4121152484 2025-05-10 04:12:55.316757 :95104F70:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 04:12:55.316758 :95104F71:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 04:12:55.316758 :95104F72:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 04:12:55.316759 :95104F73:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 04:12:55.316759 :95104F74:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 04:12:55.317255 :95104F75: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-10 04:12:55.317299 :95104F7D: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-10 04:22:56.205326 :9511144C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 04:22:56.756900 :951114C3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 04:22:56.752 2025-05-10 04:22:56.756902 :951114C4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11412 pso_num=22 pso_serial#=38 2025-05-10 04:22:56.757036 :951114C5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11412 osp_idx=0 osp_ver=173438 osp_pg=0 (spawn #166569) 2025-05-10 04:22:56.757037 :951114C6: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-10 04:22:56.757037 :951114C7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=128 time=4121753921 2025-05-10 04:22:56.757038 :951114C8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 04:22:56.757038 :951114C9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 04:22:56.757039 :951114CA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 04:22:56.757039 :951114CB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 04:22:56.757039 :951114CC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 04:22:56.757594 :951114CD: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-10 04:22:56.757638 :951114D6: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-10 04:32:57.539954 :9511DAD4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 04:32:58.070413 :9511DB33:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 04:32:58.065 2025-05-10 04:32:58.070414 :9511DB34:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13032 pso_num=22 pso_serial#=39 2025-05-10 04:32:58.070545 :9511DB35:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13032 osp_idx=0 osp_ver=173439 osp_pg=0 (spawn #166591) 2025-05-10 04:32:58.070546 :9511DB36: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-10 04:32:58.070546 :9511DB37:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=129 time=4122355234 2025-05-10 04:32:58.070547 :9511DB38:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 04:32:58.070547 :9511DB39:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 04:32:58.070548 :9511DB3A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 04:32:58.070548 :9511DB3B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 04:32:58.070548 :9511DB3C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 04:32:58.071092 :9511DB3D: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-10 04:32:58.071139 :9511DB44: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-10 04:42:58.957549 :95129FF5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 04:42:59.509163 :9512A060:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 04:42:59.504 2025-05-10 04:42:59.509165 :9512A061:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11376 pso_num=22 pso_serial#=40 2025-05-10 04:42:59.509305 :9512A062:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11376 osp_idx=0 osp_ver=173440 osp_pg=0 (spawn #166614) 2025-05-10 04:42:59.509305 :9512A063: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-10 04:42:59.509306 :9512A064:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=130 time=4122956671 2025-05-10 04:42:59.509306 :9512A065:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 04:42:59.509307 :9512A066:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 04:42:59.509307 :9512A067:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 04:42:59.509307 :9512A068:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 04:42:59.509308 :9512A069:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 04:42:59.509804 :9512A06A: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-10 04:42:59.509861 :9512A071: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-10 04:53:00.451955 :95136595:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 04:53:00.847386 :951365FB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 04:53:00.842 2025-05-10 04:53:00.847387 :951365FC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12816 pso_num=22 pso_serial#=41 2025-05-10 04:53:00.847521 :951365FD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12816 osp_idx=0 osp_ver=173441 osp_pg=0 (spawn #166637) 2025-05-10 04:53:00.847522 :951365FE: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-10 04:53:00.847523 :951365FF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=131 time=4123558015 2025-05-10 04:53:00.847523 :95136600:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 04:53:00.847523 :95136601:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 04:53:00.847524 :95136602:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 04:53:00.847524 :95136603:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 04:53:00.847524 :95136604:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 04:53:00.848018 :95136605: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-10 04:53:00.848073 :9513660C: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-10 05:03:01.688561 :95142C3E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 05:03:02.177664 :95142CA5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 05:03:02.173 2025-05-10 05:03:02.177666 :95142CA6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10124 pso_num=22 pso_serial#=42 2025-05-10 05:03:02.177803 :95142CA7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10124 osp_idx=0 osp_ver=173442 osp_pg=0 (spawn #166663) 2025-05-10 05:03:02.177803 :95142CA8: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-10 05:03:02.177804 :95142CA9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=132 time=4124159343 2025-05-10 05:03:02.177804 :95142CAA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:03:02.177804 :95142CAB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:03:02.177804 :95142CAC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:03:02.177805 :95142CAD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:03:02.177805 :95142CAE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:03:02.178289 :95142CAF: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-10 05:03:02.178330 :95142CB7: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-10 05:03:17.209613 :951431DD:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-05-10 05:03:17.209643 :951431E8:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-05-10 05:03:17.209644 :951431E9:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=29, exc=29, tot=29 2025-05-10 05:13:03.096405 :9514FA6E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 05:13:03.600930 :9514FAC8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 05:13:03.596 2025-05-10 05:13:03.600933 :9514FAC9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13224 pso_num=22 pso_serial#=43 2025-05-10 05:13:03.601081 :9514FACA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13224 osp_idx=0 osp_ver=173443 osp_pg=0 (spawn #166687) 2025-05-10 05:13:03.601082 :9514FACB: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-10 05:13:03.601082 :9514FACC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=133 time=4124760765 2025-05-10 05:13:03.601083 :9514FACD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:13:03.601083 :9514FACE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:13:03.601083 :9514FACF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:13:03.601084 :9514FAD0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:13:03.601084 :9514FAD1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:13:03.601566 :9514FAD2: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-10 05:13:03.601615 :9514FAD8: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-10 05:23:04.502373 :9515BF4F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 05:23:05.082938 :9515BF8C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 05:23:05.075 2025-05-10 05:23:05.082940 :9515BF8D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12628 pso_num=22 pso_serial#=44 2025-05-10 05:23:05.083076 :9515BF8E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12628 (legacy spawn) 2025-05-10 05:23:05.089510 :9515BF8F: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-05-10 05:23:05.089677 :9515BF98: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-05-10 05:23:05.090491 :9515BF99:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 05:23:05.142055 :9515BFDD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 05:23:05.137 2025-05-10 05:23:05.142058 :9515BFDE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11896 pso_num=22 pso_serial#=45 2025-05-10 05:23:05.142196 :9515BFDF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11896 osp_idx=0 osp_ver=173445 osp_pg=0 (spawn #166710) 2025-05-10 05:23:05.142196 :9515BFE0: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-10 05:23:05.142197 :9515BFE1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=134 time=4125362312 2025-05-10 05:23:05.142197 :9515BFE2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:23:05.142197 :9515BFE3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:23:05.142198 :9515BFE4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:23:05.142198 :9515BFE5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:23:05.142198 :9515BFE6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:23:05.142680 :9515BFE7: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-10 05:23:05.142735 :9515BFF1: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-10 05:33:06.027703 :951684E9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 05:33:06.485383 :95168558:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 05:33:06.480 2025-05-10 05:33:06.485385 :95168559:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11732 pso_num=22 pso_serial#=46 2025-05-10 05:33:06.485523 :9516855A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11732 osp_idx=0 osp_ver=173446 osp_pg=0 (spawn #166732) 2025-05-10 05:33:06.485523 :9516855B: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-10 05:33:06.485524 :9516855C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=135 time=4125963656 2025-05-10 05:33:06.485524 :9516855D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:33:06.485525 :9516855E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:33:06.485525 :9516855F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:33:06.485525 :95168560:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:33:06.485526 :95168561:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:33:06.486008 :95168562: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-10 05:33:06.486053 :95168569: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-10 05:43:07.304305 :95174B0B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-10 05:43:07.824627 :95174B8F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-10 05:43:07.819 2025-05-10 05:43:07.824629 :95174B90:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7460 pso_num=22 pso_serial#=47 2025-05-10 05:43:07.824769 :95174B91:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7460 osp_idx=0 osp_ver=173447 osp_pg=0 (spawn #166755) 2025-05-10 05:43:07.824770 :95174B92: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-10 05:43:07.824770 :95174B93:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=136 time=4126564984 2025-05-10 05:43:07.824770 :95174B94:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:43:07.824771 :95174B95:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:43:07.824771 :95174B96:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:43:07.824771 :95174B97:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:43:07.824772 :95174B98:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:43:07.825266 :95174B99: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-10 05:43:07.825313 :95174BA2: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-10 05:45:26.693742 :9517799F: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-10 05:53:09.241419 :95181030: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 7460, W000)