Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250603220006\orcl_w000_13744_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:36971M/63366M, Ph+PgF:43703M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13744, image: ORACLE.EXE (W000) *** 2025-06-03 22:00:06.593 *** SESSION ID:(177.27015) 2025-06-03 22:00:06.593 *** 2025-06-03 22:00:06.593 Process diagnostic dump for ORACLE.EXE (W000), OS id=13744, pid: 22, proc_ser: 53, sid: 177, sess_ser: 27015 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=95 seq_num=96 snap_id=1 wait times: snap=0.428035 sec, exc=0.428035 sec, total=0.428035 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.000027 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=94 seq_num=95 snap_id=1 wait times: snap=5.008373 sec, exc=5.008373 sec, total=5.008373 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=93 seq_num=94 snap_id=1 wait times: snap=5.000187 sec, exc=5.000187 sec, total=5.000187 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=92 seq_num=93 snap_id=1 wait times: snap=5.001988 sec, exc=5.001988 sec, total=5.001988 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 3: 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.008388 sec, exc=5.008388 sec, total=5.008388 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 4: 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.004628 sec, exc=5.004628 sec, total=5.004628 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: 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.004621 sec, exc=5.004621 sec, total=5.004621 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 6: 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.009224 sec, exc=5.009224 sec, total=5.009224 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: 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.005153 sec, exc=5.005153 sec, total=5.005153 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: 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.003311 sec, exc=5.003311 sec, total=5.003311 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: 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.001468 sec, exc=5.001468 sec, total=5.001468 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 177 serial 27015 --------------------------------------------------- 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:06 - 22:00:06] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-03 22:00:06.593 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13744, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-03 19:32:04.141453 :9FE0EA88:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 19:32:04.615070 :9FE0EACC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 19:32:04.610 2025-06-03 19:32:04.615072 :9FE0EACD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13728 pso_num=22 pso_serial#=40 2025-06-03 19:32:04.615207 :9FE0EACE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13728 osp_idx=0 osp_ver=258427 osp_pg=0 (spawn #248811) 2025-06-03 19:32:04.615208 :9FE0EACF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 19:32:04.615208 :9FE0EAD0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=72 time=1954883266 2025-06-03 19:32:04.615208 :9FE0EAD1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 19:32:04.615209 :9FE0EAD2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 19:32:04.615209 :9FE0EAD3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 19:32:04.615209 :9FE0EAD4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 19:32:04.615210 :9FE0EAD5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 19:32:04.615722 :9FE0EAD6: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-06-03 19:32:04.615765 :9FE0EADF: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-06-03 19:42:05.430328 :9FE1B30C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 19:42:05.794351 :9FE1B342:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 19:42:05.789 2025-06-03 19:42:05.794353 :9FE1B343:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14644 pso_num=22 pso_serial#=41 2025-06-03 19:42:05.794485 :9FE1B344:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14644 osp_idx=0 osp_ver=258428 osp_pg=0 (spawn #248833) 2025-06-03 19:42:05.794486 :9FE1B345:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 19:42:05.794486 :9FE1B346:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=73 time=1955484438 2025-06-03 19:42:05.794486 :9FE1B347:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 19:42:05.794487 :9FE1B348:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 19:42:05.794487 :9FE1B349:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 19:42:05.794487 :9FE1B34A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 19:42:05.794488 :9FE1B34B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 19:42:05.794988 :9FE1B34C: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-06-03 19:42:05.795041 :9FE1B356: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-06-03 19:52:06.683710 :9FE27A89:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 19:52:06.954033 :9FE27AC3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 19:52:06.949 2025-06-03 19:52:06.954035 :9FE27AC4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14444 pso_num=22 pso_serial#=42 2025-06-03 19:52:06.954175 :9FE27AC5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14444 osp_idx=0 osp_ver=258429 osp_pg=0 (spawn #248856) 2025-06-03 19:52:06.954176 :9FE27AC6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 19:52:06.954176 :9FE27AC7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=74 time=1956085594 2025-06-03 19:52:06.954177 :9FE27AC8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 19:52:06.954177 :9FE27AC9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 19:52:06.954178 :9FE27ACA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 19:52:06.954178 :9FE27ACB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 19:52:06.954178 :9FE27ACC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 19:52:06.954742 :9FE27ACD: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-06-03 19:52:06.954784 :9FE27AD5: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-06-03 20:02:07.804453 :9FE343EE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 20:02:08.147359 :9FE34440:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 20:02:08.142 2025-06-03 20:02:08.147361 :9FE34441:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6832 pso_num=22 pso_serial#=43 2025-06-03 20:02:08.147516 :9FE34442:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6832 osp_idx=0 osp_ver=258430 osp_pg=0 (spawn #248881) 2025-06-03 20:02:08.147517 :9FE34443:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 20:02:08.147517 :9FE34444:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=75 time=1956686797 2025-06-03 20:02:08.147517 :9FE34445:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 20:02:08.147518 :9FE34446:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 20:02:08.147518 :9FE34447:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 20:02:08.147518 :9FE34448:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 20:02:08.147519 :9FE34449:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 20:02:08.148046 :9FE3444A: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-06-03 20:02:08.148097 :9FE34452: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-06-03 20:12:08.942678 :9FE41154:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 20:12:09.259926 :9FE4118E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 20:12:09.255 2025-06-03 20:12:09.259928 :9FE4118F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15808 pso_num=22 pso_serial#=44 2025-06-03 20:12:09.260067 :9FE41190:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15808 osp_idx=0 osp_ver=258431 osp_pg=0 (spawn #248904) 2025-06-03 20:12:09.260068 :9FE41191:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 20:12:09.260069 :9FE41192:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=76 time=1957287907 2025-06-03 20:12:09.260069 :9FE41193:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 20:12:09.260069 :9FE41194:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 20:12:09.260070 :9FE41195:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 20:12:09.260070 :9FE41196:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 20:12:09.260070 :9FE41197:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 20:12:09.260569 :9FE41198: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-06-03 20:12:09.260615 :9FE4119F: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-06-03 20:18:01.896012 :9FE485D6: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-06-03 20:22:10.398790 :9FE4DB5E: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-06-03 20:32:11.312033 :9FE5A225:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 20:32:11.535294 :9FE5A25E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 20:32:11.530 2025-06-03 20:32:11.535296 :9FE5A25F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14204 pso_num=22 pso_serial#=45 2025-06-03 20:32:11.535436 :9FE5A260:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14204 osp_idx=0 osp_ver=258432 osp_pg=0 (spawn #248949) 2025-06-03 20:32:11.535437 :9FE5A261:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 20:32:11.535437 :9FE5A262:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=77 time=1958490188 2025-06-03 20:32:11.535438 :9FE5A263:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 20:32:11.535438 :9FE5A264:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 20:32:11.535438 :9FE5A265:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 20:32:11.535439 :9FE5A266:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 20:32:11.535439 :9FE5A267:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 20:32:11.535941 :9FE5A268: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-06-03 20:32:11.535986 :9FE5A26F: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-06-03 20:42:12.336953 :9FE66960:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 20:42:12.622994 :9FE669A8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 20:42:12.618 2025-06-03 20:42:12.622996 :9FE669A9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10388 pso_num=22 pso_serial#=46 2025-06-03 20:42:12.623137 :9FE669AA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10388 osp_idx=0 osp_ver=258433 osp_pg=0 (spawn #248971) 2025-06-03 20:42:12.623137 :9FE669AB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 20:42:12.623138 :9FE669AC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=78 time=1959091266 2025-06-03 20:42:12.623138 :9FE669AD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 20:42:12.623139 :9FE669AE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 20:42:12.623139 :9FE669AF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 20:42:12.623139 :9FE669B0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 20:42:12.623139 :9FE669B1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 20:42:12.623643 :9FE669B2: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-06-03 20:42:12.623686 :9FE669BA: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-06-03 20:52:13.522212 :9FE730B0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 20:52:13.698755 :9FE730E9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 20:52:13.694 2025-06-03 20:52:13.698757 :9FE730EA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14824 pso_num=22 pso_serial#=47 2025-06-03 20:52:13.698890 :9FE730EB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14824 osp_idx=0 osp_ver=258434 osp_pg=0 (spawn #248994) 2025-06-03 20:52:13.698890 :9FE730EC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 20:52:13.698890 :9FE730ED:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=79 time=1959692344 2025-06-03 20:52:13.698891 :9FE730EE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 20:52:13.698891 :9FE730EF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 20:52:13.698891 :9FE730F0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 20:52:13.698892 :9FE730F1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 20:52:13.698892 :9FE730F2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 20:52:13.699374 :9FE730F3: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-06-03 20:52:13.699422 :9FE730FA: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-06-03 21:02:14.508235 :9FE7F950:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 21:02:14.809839 :9FE7F9BE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 21:02:14.805 2025-06-03 21:02:14.809842 :9FE7F9BF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11372 pso_num=22 pso_serial#=48 2025-06-03 21:02:14.809976 :9FE7F9C0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11372 osp_idx=0 osp_ver=258435 osp_pg=0 (spawn #249019) 2025-06-03 21:02:14.809977 :9FE7F9C1:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 21:02:14.809977 :9FE7F9C2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=80 time=1960293454 2025-06-03 21:02:14.809978 :9FE7F9C3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 21:02:14.809978 :9FE7F9C4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 21:02:14.809979 :9FE7F9C5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 21:02:14.809979 :9FE7F9C6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 21:02:14.809979 :9FE7F9C7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 21:02:14.810469 :9FE7F9C8: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-06-03 21:02:14.810515 :9FE7F9D2: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-06-03 21:12:15.609183 :9FE8C716:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 21:12:15.942259 :9FE8C74A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 21:12:15.937 2025-06-03 21:12:15.942261 :9FE8C74B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15492 pso_num=22 pso_serial#=49 2025-06-03 21:12:15.942407 :9FE8C74C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15492 osp_idx=0 osp_ver=258436 osp_pg=0 (spawn #249042) 2025-06-03 21:12:15.942408 :9FE8C74D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 21:12:15.942408 :9FE8C74E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=81 time=1960894594 2025-06-03 21:12:15.942408 :9FE8C74F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 21:12:15.942409 :9FE8C750:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 21:12:15.942409 :9FE8C751:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 21:12:15.942410 :9FE8C752:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 21:12:15.942410 :9FE8C753:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 21:12:15.942930 :9FE8C754: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-06-03 21:12:15.942976 :9FE8C75C: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-06-03 21:22:16.863537 :9FE990C7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 21:22:17.102532 :9FE99108:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 21:22:17.098 2025-06-03 21:22:17.102535 :9FE99109:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14056 pso_num=22 pso_serial#=50 2025-06-03 21:22:17.102676 :9FE9910A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14056 osp_idx=0 osp_ver=258437 osp_pg=0 (spawn #249065) 2025-06-03 21:22:17.102677 :9FE9910B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 21:22:17.102678 :9FE9910C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=82 time=1961495750 2025-06-03 21:22:17.102678 :9FE9910D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 21:22:17.102678 :9FE9910E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 21:22:17.102679 :9FE9910F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 21:22:17.102679 :9FE99110:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 21:22:17.102679 :9FE99111:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 21:22:17.103171 :9FE99112: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-06-03 21:22:17.103219 :9FE9911A: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-06-03 21:32:17.905083 :9FEA5839:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 21:32:18.284794 :9FEA5875:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 21:32:18.280 2025-06-03 21:32:18.284796 :9FEA5876:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16312 pso_num=22 pso_serial#=51 2025-06-03 21:32:18.284943 :9FEA5877:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16312 osp_idx=0 osp_ver=258438 osp_pg=0 (spawn #249088) 2025-06-03 21:32:18.284944 :9FEA5878:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 21:32:18.284944 :9FEA5879:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=83 time=1962096938 2025-06-03 21:32:18.284945 :9FEA587A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 21:32:18.284945 :9FEA587B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 21:32:18.284946 :9FEA587C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 21:32:18.284946 :9FEA587D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 21:32:18.284946 :9FEA587E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 21:32:18.285454 :9FEA587F: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-06-03 21:32:18.285506 :9FEA5887: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-06-03 21:42:19.119123 :9FEB1F0F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 21:42:19.420831 :9FEB1F52:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 21:42:19.416 2025-06-03 21:42:19.420833 :9FEB1F53:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14576 pso_num=22 pso_serial#=52 2025-06-03 21:42:19.420964 :9FEB1F54:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14576 osp_idx=0 osp_ver=258439 osp_pg=0 (spawn #249110) 2025-06-03 21:42:19.420965 :9FEB1F55:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 21:42:19.420965 :9FEB1F56:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=84 time=1962698063 2025-06-03 21:42:19.420966 :9FEB1F57:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 21:42:19.420966 :9FEB1F58:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 21:42:19.420967 :9FEB1F59:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 21:42:19.420967 :9FEB1F5A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 21:42:19.420967 :9FEB1F5B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 21:42:19.421452 :9FEB1F5C: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-06-03 21:42:19.421496 :9FEB1F65: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-06-03 21:52:20.304896 :9FEBE59C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-03 21:52:20.575162 :9FEBE5D5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-03 21:52:20.570 2025-06-03 21:52:20.575164 :9FEBE5D6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13744 pso_num=22 pso_serial#=53 2025-06-03 21:52:20.575301 :9FEBE5D7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13744 osp_idx=0 osp_ver=258440 osp_pg=0 (spawn #249133) 2025-06-03 21:52:20.575302 :9FEBE5D8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 21:52:20.575302 :9FEBE5D9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=85 time=1963299219 2025-06-03 21:52:20.575303 :9FEBE5DA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 21:52:20.575303 :9FEBE5DB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 21:52:20.575303 :9FEBE5DC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 21:52:20.575304 :9FEBE5DD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 21:52:20.575304 :9FEBE5DE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 21:52:20.575788 :9FEBE5DF: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-06-03 21:52:20.575836 :9FEBE5E6: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-06-03 21:52:50.604134 :9FEBEFFF:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-06-03 21:52:50.604154 :9FEBF004:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-06-03 21:52:50.604155 :9FEBF005:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=19, exc=19, tot=19 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 13744, W000)