Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250707220007\orcl_w000_608_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:36640M/63366M, Ph+PgF:42679M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 608, image: ORACLE.EXE (W000) *** 2025-07-07 22:00:07.244 *** SESSION ID:(201.18191) 2025-07-07 22:00:07.244 *** 2025-07-07 22:00:07.244 Process diagnostic dump for ORACLE.EXE (W000), OS id=608, pid: 25, proc_ser: 220, sid: 201, sess_ser: 18191 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=93 seq_num=94 snap_id=1 wait times: snap=0.040309 sec, exc=0.040309 sec, total=0.040309 sec wait times: max=5.000000 sec, heur=7 min 15 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.000084 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=92 seq_num=93 snap_id=1 wait times: snap=5.003248 sec, exc=5.003248 sec, total=5.003248 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=91 seq_num=92 snap_id=1 wait times: snap=5.000392 sec, exc=5.000392 sec, total=5.000392 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=90 seq_num=91 snap_id=1 wait times: snap=5.008212 sec, exc=5.008212 sec, total=5.008212 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=89 seq_num=90 snap_id=1 wait times: snap=5.010332 sec, exc=5.010332 sec, total=5.010332 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=88 seq_num=89 snap_id=1 wait times: snap=5.010105 sec, exc=5.010105 sec, total=5.010105 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=87 seq_num=88 snap_id=1 wait times: snap=5.014745 sec, exc=5.014745 sec, total=5.014745 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=86 seq_num=87 snap_id=1 wait times: snap=5.004645 sec, exc=5.004645 sec, total=5.004645 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=85 seq_num=86 snap_id=1 wait times: snap=5.014727 sec, exc=5.014727 sec, total=5.014727 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=84 seq_num=85 snap_id=1 wait times: snap=5.007255 sec, exc=5.007255 sec, total=5.007255 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=83 seq_num=84 snap_id=1 wait times: snap=5.004941 sec, exc=5.004941 sec, total=5.004941 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time Sampled Session History of session 201 serial 18191 --------------------------------------------------- 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, 21:58:07 - 22:00:07] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-07 22:00:07.244 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 608, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-07 19:22:17.353332 :AEE2CB77:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18356 osp_idx=23 osp_ver=185959 osp_pg=0 (spawn #362144) 2025-07-07 19:22:17.353333 :AEE2CB78:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 19:22:17.353334 :AEE2CB79:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=70 time=596913251 2025-07-07 19:22:17.353334 :AEE2CB7A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 19:22:17.353334 :AEE2CB7B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 19:22:17.353335 :AEE2CB7C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 19:22:17.353335 :AEE2CB7D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 19:22:17.353335 :AEE2CB7E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 19:22:17.353827 :AEE2CB7F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 19:22:17.353871 :AEE2CB87:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 19:32:18.218505 :AEE396C6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 19:32:18.551475 :AEE396FE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 19:32:18.546 2025-07-07 19:32:18.551477 :AEE396FF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16896 pso_num=25 pso_serial#=208 2025-07-07 19:32:18.551616 :AEE39700:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16896 osp_idx=23 osp_ver=185960 osp_pg=0 (spawn #362167) 2025-07-07 19:32:18.551616 :AEE39701:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 19:32:18.551617 :AEE39702:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=71 time=597514439 2025-07-07 19:32:18.551617 :AEE39703:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 19:32:18.551618 :AEE39704:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 19:32:18.551618 :AEE39705:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 19:32:18.551618 :AEE39706:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 19:32:18.551618 :AEE39707:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 19:32:18.552171 :AEE39708:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 19:32:18.552218 :AEE39710:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 19:42:19.415928 :AEE462EB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 19:42:19.780142 :AEE46333:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 19:42:19.775 2025-07-07 19:42:19.780144 :AEE46334:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11728 pso_num=25 pso_serial#=209 2025-07-07 19:42:19.780290 :AEE46335:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11728 osp_idx=23 osp_ver=185961 osp_pg=0 (spawn #362192) 2025-07-07 19:42:19.780290 :AEE46336:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 19:42:19.780291 :AEE46337:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=72 time=598115673 2025-07-07 19:42:19.780291 :AEE46338:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 19:42:19.780292 :AEE46339:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 19:42:19.780292 :AEE4633A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 19:42:19.780292 :AEE4633B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 19:42:19.780293 :AEE4633C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 19:42:19.780880 :AEE4633D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 19:42:19.780928 :AEE46345:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 19:52:20.688863 :AEE52E66:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 19:52:20.990703 :AEE52E9F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 19:52:20.985 2025-07-07 19:52:20.990704 :AEE52EA0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14980 pso_num=25 pso_serial#=210 2025-07-07 19:52:20.990852 :AEE52EA1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14980 osp_idx=23 osp_ver=185962 osp_pg=0 (spawn #362214) 2025-07-07 19:52:20.990853 :AEE52EA2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 19:52:20.990853 :AEE52EA3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=73 time=598716892 2025-07-07 19:52:20.990854 :AEE52EA4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 19:52:20.990854 :AEE52EA5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 19:52:20.990854 :AEE52EA6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 19:52:20.990855 :AEE52EA7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 19:52:20.990855 :AEE52EA8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 19:52:20.991406 :AEE52EA9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 19:52:20.991451 :AEE52EB1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 19:55:57.804805 :AEE57840:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-07 20:02:22.241358 :AEE5FC99:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-07 20:12:23.095914 :AEE6D119:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 20:12:23.522439 :AEE6D15D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 20:12:23.517 2025-07-07 20:12:23.522441 :AEE6D15E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14500 pso_num=25 pso_serial#=211 2025-07-07 20:12:23.522580 :AEE6D15F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14500 osp_idx=23 osp_ver=185963 osp_pg=0 (spawn #362262) 2025-07-07 20:12:23.522581 :AEE6D160:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 20:12:23.522581 :AEE6D161:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=74 time=599919423 2025-07-07 20:12:23.522581 :AEE6D162:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 20:12:23.522581 :AEE6D163:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 20:12:23.522582 :AEE6D164:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 20:12:23.522582 :AEE6D165:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 20:12:23.522583 :AEE6D166:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 20:12:23.523101 :AEE6D167:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 20:12:23.523143 :AEE6D16E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 20:22:24.381208 :AEE79C0C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 20:22:24.792358 :AEE79C47:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 20:22:24.787 2025-07-07 20:22:24.792360 :AEE79C48:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=5284 pso_num=25 pso_serial#=212 2025-07-07 20:22:24.792510 :AEE79C49:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=5284 osp_idx=23 osp_ver=185964 osp_pg=0 (spawn #362284) 2025-07-07 20:22:24.792512 :AEE79C4A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 20:22:24.792513 :AEE79C4B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=75 time=600520689 2025-07-07 20:22:24.792513 :AEE79C4C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 20:22:24.792514 :AEE79C4D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 20:22:24.792514 :AEE79C4E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 20:22:24.792514 :AEE79C4F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 20:22:24.792515 :AEE79C50:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 20:22:24.793035 :AEE79C51:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 20:22:24.793081 :AEE79C59:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 20:32:25.611978 :AEE86792:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 20:32:26.086189 :AEE867EA:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 20:32:26.081 2025-07-07 20:32:26.086192 :AEE867EB:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17120 pso_num=25 pso_serial#=213 2025-07-07 20:32:26.086353 :AEE867EC:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17120 osp_idx=23 osp_ver=185965 osp_pg=0 (spawn #362307) 2025-07-07 20:32:26.086354 :AEE867ED:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 20:32:26.086354 :AEE867EE:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=76 time=601121986 2025-07-07 20:32:26.086355 :AEE867EF:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 20:32:26.086355 :AEE867F0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 20:32:26.086355 :AEE867F1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 20:32:26.086356 :AEE867F2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 20:32:26.086356 :AEE867F3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 20:32:26.087046 :AEE867F4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 20:32:26.087116 :AEE867FE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 20:42:27.328532 :AEE9340B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-07 20:52:28.195288 :AEE9FEAD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 20:52:28.606425 :AEE9FEF5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 20:52:28.601 2025-07-07 20:52:28.606428 :AEE9FEF6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4056 pso_num=25 pso_serial#=214 2025-07-07 20:52:28.606571 :AEE9FEF7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4056 osp_idx=23 osp_ver=185966 osp_pg=0 (spawn #362351) 2025-07-07 20:52:28.606571 :AEE9FEF8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 20:52:28.606572 :AEE9FEF9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=77 time=602324501 2025-07-07 20:52:28.606572 :AEE9FEFA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 20:52:28.606573 :AEE9FEFB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 20:52:28.606573 :AEE9FEFC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 20:52:28.606573 :AEE9FEFD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 20:52:28.606574 :AEE9FEFE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 20:52:28.607095 :AEE9FEFF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 20:52:28.607139 :AEE9FF07:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 21:02:29.437804 :AEEACBD1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 21:02:29.989817 :AEEACC0A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 21:02:29.985 2025-07-07 21:02:29.989819 :AEEACC0B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9264 pso_num=25 pso_serial#=215 2025-07-07 21:02:29.989974 :AEEACC0C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9264 osp_idx=23 osp_ver=185967 osp_pg=0 (spawn #362377) 2025-07-07 21:02:29.989975 :AEEACC0D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 21:02:29.989975 :AEEACC0E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=78 time=602925876 2025-07-07 21:02:29.989976 :AEEACC0F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 21:02:29.989976 :AEEACC10:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 21:02:29.989977 :AEEACC11:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 21:02:29.989977 :AEEACC12:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 21:02:29.989977 :AEEACC13:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 21:02:29.990551 :AEEACC14:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 21:02:29.990599 :AEEACC1A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 21:12:30.807731 :AEEB9FA6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 21:12:31.250046 :AEEB9FE0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 21:12:31.245 2025-07-07 21:12:31.250049 :AEEB9FE1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15528 pso_num=25 pso_serial#=216 2025-07-07 21:12:31.250222 :AEEB9FE2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15528 osp_idx=23 osp_ver=185968 osp_pg=0 (spawn #362400) 2025-07-07 21:12:31.250225 :AEEB9FE3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 21:12:31.250225 :AEEB9FE4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=79 time=603527142 2025-07-07 21:12:31.250226 :AEEB9FE5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 21:12:31.250226 :AEEB9FE6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 21:12:31.250226 :AEEB9FE7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 21:12:31.250227 :AEEB9FE8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 21:12:31.250227 :AEEB9FE9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 21:12:31.250756 :AEEB9FEA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 21:12:31.250806 :AEEB9FF1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 21:22:32.124484 :AEEC6A78:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 21:22:32.629258 :AEEC6ACE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 21:22:32.630 2025-07-07 21:22:32.629260 :AEEC6ACF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16484 pso_num=25 pso_serial#=217 2025-07-07 21:22:32.629405 :AEEC6AD0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16484 osp_idx=23 osp_ver=185969 osp_pg=0 (spawn #362422) 2025-07-07 21:22:32.629405 :AEEC6AD1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 21:22:32.629406 :AEEC6AD2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=80 time=604128517 2025-07-07 21:22:32.629406 :AEEC6AD3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 21:22:32.629407 :AEEC6AD4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 21:22:32.629407 :AEEC6AD5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 21:22:32.629407 :AEEC6AD6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 21:22:32.629408 :AEEC6AD7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 21:22:32.629956 :AEEC6AD8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 21:22:32.630000 :AEEC6ADF:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 21:32:33.505827 :AEED35E0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 21:32:33.948284 :AEED3619:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 21:32:33.943 2025-07-07 21:32:33.948286 :AEED361A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12720 pso_num=25 pso_serial#=218 2025-07-07 21:32:33.948438 :AEED361B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12720 osp_idx=23 osp_ver=185970 osp_pg=0 (spawn #362445) 2025-07-07 21:32:33.948438 :AEED361C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 21:32:33.948439 :AEED361D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=81 time=604729845 2025-07-07 21:32:33.948439 :AEED361E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 21:32:33.948439 :AEED361F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 21:32:33.948440 :AEED3620:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 21:32:33.948440 :AEED3621:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 21:32:33.948440 :AEED3622:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 21:32:33.949037 :AEED3623:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 21:32:33.949084 :AEED3629:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 21:42:34.758261 :AEEE00EE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 21:42:35.200519 :AEEE0135:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 21:42:35.195 2025-07-07 21:42:35.200520 :AEEE0136:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=2964 pso_num=25 pso_serial#=219 2025-07-07 21:42:35.200663 :AEEE0137:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=2964 osp_idx=23 osp_ver=185971 osp_pg=0 (spawn #362468) 2025-07-07 21:42:35.200663 :AEEE0138:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 21:42:35.200664 :AEEE0139:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=82 time=605331095 2025-07-07 21:42:35.200664 :AEEE013A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 21:42:35.200665 :AEEE013B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 21:42:35.200665 :AEEE013C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 21:42:35.200666 :AEEE013D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 21:42:35.200666 :AEEE013E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 21:42:35.201197 :AEEE013F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 21:42:35.201242 :AEEE0149:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 21:52:36.001353 :AEEECAEE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-07 21:52:36.521735 :AEEECB25:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-07 21:52:36.517 2025-07-07 21:52:36.521737 :AEEECB26:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=608 pso_num=25 pso_serial#=220 2025-07-07 21:52:36.521875 :AEEECB27:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=608 osp_idx=23 osp_ver=185972 osp_pg=0 (spawn #362490) 2025-07-07 21:52:36.521876 :AEEECB28:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-07 21:52:36.521877 :AEEECB29:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=83 time=605932423 2025-07-07 21:52:36.521877 :AEEECB2A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-07 21:52:36.521877 :AEEECB2B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-07 21:52:36.521878 :AEEECB2C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-07 21:52:36.521878 :AEEECB2D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-07 21:52:36.521878 :AEEECB2E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-07 21:52:36.522400 :AEEECB2F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-07 21:52:36.522459 :AEEECB39:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-07 21:52:51.530139 :AEEECFFA:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-07-07 21:52:51.530143 :AEEECFFB:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-07-07 21:52:51.530144 :AEEECFFC:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=4, exc=4, tot=4 2025-07-07 21:52:51.530149 :AEEED001:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 608, W000)