Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250427060008\orcl_w000_9992_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:37568M/63366M, Ph+PgF:45213M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 9992, image: ORACLE.EXE (W000) *** 2025-04-27 06:00:08.478 *** SESSION ID:(177.33429) 2025-04-27 06:00:08.478 *** 2025-04-27 06:00:08.478 Process diagnostic dump for ORACLE.EXE (W000), OS id=9992, pid: 22, proc_ser: 187, sid: 177, sess_ser: 33429 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=214 seq_num=215 snap_id=1 wait times: snap=3.543185 sec, exc=3.543185 sec, total=3.543185 sec wait times: max=5.000000 sec, heur=13 min 31 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.000034 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=213 seq_num=214 snap_id=1 wait times: snap=5.007173 sec, exc=5.007173 sec, total=5.007173 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=212 seq_num=213 snap_id=1 wait times: snap=5.007258 sec, exc=5.007258 sec, total=5.007258 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=211 seq_num=212 snap_id=1 wait times: snap=5.001396 sec, exc=5.001396 sec, total=5.001396 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=210 seq_num=211 snap_id=1 wait times: snap=5.006067 sec, exc=5.006067 sec, total=5.006067 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000038 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=209 seq_num=210 snap_id=1 wait times: snap=5.013853 sec, exc=5.013853 sec, total=5.013853 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=208 seq_num=209 snap_id=1 wait times: snap=5.014700 sec, exc=5.014700 sec, total=5.014700 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=207 seq_num=208 snap_id=1 wait times: snap=5.014711 sec, exc=5.014711 sec, total=5.014711 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=206 seq_num=207 snap_id=1 wait times: snap=5.005123 sec, exc=5.005123 sec, total=5.005123 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 8: 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.003375 sec, exc=5.003375 sec, total=5.003375 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 9: 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.005843 sec, exc=5.005843 sec, total=5.005843 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time Sampled Session History of session 177 serial 33429 --------------------------------------------------- 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:08 - 06:00:08] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-27 06:00:08.478 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 9992, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-27 03:12:09.111570 :8F489475:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 03:12:09.111570 :8F489476:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=112 time=2994330906 2025-04-27 03:12:09.111571 :8F489477:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 03:12:09.111571 :8F489478:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 03:12:09.111571 :8F489479:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 03:12:09.111571 :8F48947A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 03:12:09.111572 :8F48947B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 03:12:09.112068 :8F48947C: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-04-27 03:12:09.112118 :8F489486: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-04-27 03:22:10.054418 :8F495E8A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 03:22:10.371605 :8F495EBF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 03:22:10.366 2025-04-27 03:22:10.371607 :8F495EC0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8828 pso_num=22 pso_serial#=175 2025-04-27 03:22:10.371744 :8F495EC1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8828 osp_idx=0 osp_ver=127420 osp_pg=0 (spawn #122367) 2025-04-27 03:22:10.371744 :8F495EC2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 03:22:10.371744 :8F495EC3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=113 time=2994932171 2025-04-27 03:22:10.371745 :8F495EC4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 03:22:10.371745 :8F495EC5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 03:22:10.371745 :8F495EC6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 03:22:10.371746 :8F495EC7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 03:22:10.371746 :8F495EC8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 03:22:10.372239 :8F495EC9: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-04-27 03:22:10.372286 :8F495ED1: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-04-27 03:32:11.289446 :8F4A29A9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 03:32:11.606694 :8F4A29E0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 03:32:11.602 2025-04-27 03:32:11.606696 :8F4A29E1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10760 pso_num=22 pso_serial#=176 2025-04-27 03:32:11.606837 :8F4A29E2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10760 osp_idx=0 osp_ver=127421 osp_pg=0 (spawn #122390) 2025-04-27 03:32:11.606838 :8F4A29E3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 03:32:11.606838 :8F4A29E4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=114 time=2995533406 2025-04-27 03:32:11.606838 :8F4A29E5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 03:32:11.606839 :8F4A29E6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 03:32:11.606839 :8F4A29E7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 03:32:11.606839 :8F4A29E8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 03:32:11.606840 :8F4A29E9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 03:32:11.607346 :8F4A29EA: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-04-27 03:32:11.607392 :8F4A29F4: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-04-27 03:42:12.582857 :8F4AF442:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 03:42:12.743716 :8F4AF47A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 03:42:12.739 2025-04-27 03:42:12.743718 :8F4AF47B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9796 pso_num=22 pso_serial#=177 2025-04-27 03:42:12.743848 :8F4AF47C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9796 osp_idx=0 osp_ver=127422 osp_pg=0 (spawn #122414) 2025-04-27 03:42:12.743849 :8F4AF47D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 03:42:12.743849 :8F4AF47E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=115 time=2996134546 2025-04-27 03:42:12.743850 :8F4AF47F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 03:42:12.743850 :8F4AF480:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 03:42:12.743851 :8F4AF481:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 03:42:12.743851 :8F4AF482:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 03:42:12.743851 :8F4AF483:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 03:42:12.744357 :8F4AF484: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-04-27 03:42:12.744402 :8F4AF48C: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-04-27 03:46:36.896086 :8F4B4E51: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-04-27 03:52:13.960348 :8F4BC049: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-04-27 04:02:14.826114 :8F4C8C66:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 04:02:15.189951 :8F4C8CAE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 04:02:15.185 2025-04-27 04:02:15.189952 :8F4C8CAF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=1112 pso_num=22 pso_serial#=178 2025-04-27 04:02:15.190091 :8F4C8CB0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=1112 osp_idx=0 osp_ver=127423 osp_pg=0 (spawn #122460) 2025-04-27 04:02:15.190092 :8F4C8CB1:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 04:02:15.190092 :8F4C8CB2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=116 time=2997336984 2025-04-27 04:02:15.190092 :8F4C8CB3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 04:02:15.190093 :8F4C8CB4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 04:02:15.190093 :8F4C8CB5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 04:02:15.190093 :8F4C8CB6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 04:02:15.190094 :8F4C8CB7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 04:02:15.190602 :8F4C8CB8: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-04-27 04:02:15.190646 :8F4C8CC1: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-04-27 04:12:16.148565 :8F4D603D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 04:12:16.387507 :8F4D6060:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 04:12:16.383 2025-04-27 04:12:16.387510 :8F4D6061:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8216 pso_num=22 pso_serial#=179 2025-04-27 04:12:16.387641 :8F4D6062:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8216 osp_idx=0 osp_ver=127424 osp_pg=0 (spawn #122484) 2025-04-27 04:12:16.387642 :8F4D6063:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 04:12:16.387642 :8F4D6064:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=117 time=2997938187 2025-04-27 04:12:16.387643 :8F4D6065:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 04:12:16.387643 :8F4D6066:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 04:12:16.387643 :8F4D6067:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 04:12:16.387643 :8F4D6068:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 04:12:16.387644 :8F4D6069:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 04:12:16.388137 :8F4D606A: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-04-27 04:12:16.388194 :8F4D6074: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-04-27 04:22:17.408949 :8F4E2B47:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 04:22:17.663661 :8F4E2B69:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 04:22:17.659 2025-04-27 04:22:17.663663 :8F4E2B6A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8868 pso_num=22 pso_serial#=180 2025-04-27 04:22:17.663796 :8F4E2B6B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8868 osp_idx=0 osp_ver=127425 osp_pg=0 (spawn #122510) 2025-04-27 04:22:17.663797 :8F4E2B6C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 04:22:17.663797 :8F4E2B6D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=118 time=2998539453 2025-04-27 04:22:17.663798 :8F4E2B6E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 04:22:17.663798 :8F4E2B6F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 04:22:17.663799 :8F4E2B70:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 04:22:17.663799 :8F4E2B71:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 04:22:17.663799 :8F4E2B72:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 04:22:17.664363 :8F4E2B73: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-04-27 04:22:17.664407 :8F4E2B7A: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-04-27 04:32:18.510021 :8F4EF5BA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 04:32:18.873663 :8F4EF606:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 04:32:18.869 2025-04-27 04:32:18.873665 :8F4EF607:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9480 pso_num=22 pso_serial#=181 2025-04-27 04:32:18.873808 :8F4EF608:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9480 osp_idx=0 osp_ver=127426 osp_pg=0 (spawn #122534) 2025-04-27 04:32:18.873808 :8F4EF609:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 04:32:18.873809 :8F4EF60A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=119 time=2999140671 2025-04-27 04:32:18.873809 :8F4EF60B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 04:32:18.873810 :8F4EF60C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 04:32:18.873810 :8F4EF60D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 04:32:18.873811 :8F4EF60E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 04:32:18.873811 :8F4EF60F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 04:32:18.874300 :8F4EF610: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-04-27 04:32:18.874344 :8F4EF618: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-04-27 04:42:19.756318 :8F4FBFCE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 04:42:20.103977 :8F4FC013:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 04:42:20.099 2025-04-27 04:42:20.103979 :8F4FC014:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9116 pso_num=22 pso_serial#=182 2025-04-27 04:42:20.104109 :8F4FC015:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9116 osp_idx=0 osp_ver=127427 osp_pg=0 (spawn #122557) 2025-04-27 04:42:20.104110 :8F4FC016:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 04:42:20.104110 :8F4FC017:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=120 time=2999741906 2025-04-27 04:42:20.104111 :8F4FC018:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 04:42:20.104111 :8F4FC019:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 04:42:20.104112 :8F4FC01A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 04:42:20.104112 :8F4FC01B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 04:42:20.104112 :8F4FC01C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 04:42:20.104602 :8F4FC01D: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-04-27 04:42:20.104649 :8F4FC024: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-04-27 04:52:21.360649 :8F508A5E: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-04-27 04:52:21.360689 :8F508A5F:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=122 seq_num=123 snap_id=1 2025-04-27 04:52:21.360719 :8F508A61:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=122 seq_num=123 snap_id=1 2025-04-27 04:52:21.360722 :8F508A63:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=28, exc=28, tot=28 2025-04-27 05:02:22.120307 :8F5155C1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 05:02:22.655432 :8F515608:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 05:02:22.651 2025-04-27 05:02:22.655434 :8F515609:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2292 pso_num=22 pso_serial#=183 2025-04-27 05:02:22.655566 :8F51560A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2292 osp_idx=0 osp_ver=127428 osp_pg=0 (spawn #122603) 2025-04-27 05:02:22.655566 :8F51560B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 05:02:22.655567 :8F51560C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=121 time=3000944453 2025-04-27 05:02:22.655567 :8F51560D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 05:02:22.655567 :8F51560E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 05:02:22.655568 :8F51560F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 05:02:22.655568 :8F515610:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 05:02:22.655568 :8F515611:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 05:02:22.656104 :8F515612: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-04-27 05:02:22.656149 :8F515619: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-04-27 05:12:23.481556 :8F5228A4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 05:12:23.907950 :8F5228EC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 05:12:23.903 2025-04-27 05:12:23.907952 :8F5228ED:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10664 pso_num=22 pso_serial#=184 2025-04-27 05:12:23.908095 :8F5228EE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10664 osp_idx=0 osp_ver=127429 osp_pg=0 (spawn #122627) 2025-04-27 05:12:23.908096 :8F5228EF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 05:12:23.908096 :8F5228F0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=122 time=3001545703 2025-04-27 05:12:23.908097 :8F5228F1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 05:12:23.908097 :8F5228F2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 05:12:23.908097 :8F5228F3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 05:12:23.908098 :8F5228F4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 05:12:23.908098 :8F5228F5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 05:12:23.908603 :8F5228F6: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-04-27 05:12:23.908648 :8F5228FF: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-04-27 05:22:24.745109 :8F52F370:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 05:22:25.109032 :8F52F3C3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 05:22:25.104 2025-04-27 05:22:25.109034 :8F52F3C4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8620 pso_num=22 pso_serial#=185 2025-04-27 05:22:25.109167 :8F52F3C5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8620 osp_idx=0 osp_ver=127430 osp_pg=0 (spawn #122651) 2025-04-27 05:22:25.109168 :8F52F3C6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 05:22:25.109169 :8F52F3C7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=123 time=3002146906 2025-04-27 05:22:25.109169 :8F52F3C8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 05:22:25.109169 :8F52F3C9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 05:22:25.109170 :8F52F3CA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 05:22:25.109170 :8F52F3CB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 05:22:25.109170 :8F52F3CC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 05:22:25.109657 :8F52F3CD: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-04-27 05:22:25.109708 :8F52F3D7: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-04-27 05:32:25.994906 :8F53BE40:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 05:32:26.499234 :8F53BE84:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 05:32:26.494 2025-04-27 05:32:26.499236 :8F53BE85:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10828 pso_num=22 pso_serial#=186 2025-04-27 05:32:26.499380 :8F53BE86:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10828 osp_idx=0 osp_ver=127431 osp_pg=0 (spawn #122674) 2025-04-27 05:32:26.499381 :8F53BE87:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 05:32:26.499381 :8F53BE88:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=124 time=3002748296 2025-04-27 05:32:26.499382 :8F53BE89:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 05:32:26.499382 :8F53BE8A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 05:32:26.499383 :8F53BE8B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 05:32:26.499383 :8F53BE8C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 05:32:26.499383 :8F53BE8D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 05:32:26.499890 :8F53BE8E: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-04-27 05:32:26.499943 :8F53BE96: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-04-27 05:42:27.368858 :8F5488DC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-27 05:42:27.930490 :8F548931:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 05:42:27.926 2025-04-27 05:42:27.930492 :8F548932:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9992 pso_num=22 pso_serial#=187 2025-04-27 05:42:27.930632 :8F548933:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9992 osp_idx=0 osp_ver=127432 osp_pg=0 (spawn #122697) 2025-04-27 05:42:27.930632 :8F548934:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 05:42:27.930633 :8F548935:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=125 time=3003349734 2025-04-27 05:42:27.930633 :8F548936:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 05:42:27.930634 :8F548937:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 05:42:27.930634 :8F548938:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 05:42:27.930634 :8F548939:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 05:42:27.930635 :8F54893A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 05:42:27.931125 :8F54893B: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-04-27 05:42:27.931175 :8F548942: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-04-27 05:46:37.474555 :8F54DCD4: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-04-27 05:52:29.272338 :8F55546E: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: 9992, W000)