Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250728220010\orcl_w000_16700_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:35939M/63366M, Ph+PgF:41689M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 16700, image: ORACLE.EXE (W000) *** 2025-07-28 22:00:10.252 *** SESSION ID:(177.50095) 2025-07-28 22:00:10.252 *** 2025-07-28 22:00:10.252 Process diagnostic dump for ORACLE.EXE (W000), OS id=16700, pid: 22, proc_ser: 62, sid: 177, sess_ser: 50095 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=2.599835 sec, exc=2.599835 sec, total=2.599835 sec wait times: max=5.000000 sec, heur=2 min 32 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.000026 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.001199 sec, exc=5.001199 sec, total=5.001199 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000017 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.006975 sec, exc=5.006975 sec, total=5.006975 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=5.010152 sec, exc=5.010152 sec, total=5.010152 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=5.009192 sec, exc=5.009192 sec, total=5.009192 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=26 seq_num=27 snap_id=1 wait times: snap=5.004613 sec, exc=5.004613 sec, total=5.004613 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.015235 sec, exc=5.015235 sec, total=5.015235 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000039 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=5.003167 sec, exc=5.003167 sec, total=5.003167 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000059 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.002648 sec, exc=5.002648 sec, total=5.002648 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.002911 sec, exc=5.002911 sec, total=5.002911 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000040 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.014703 sec, exc=5.014703 sec, total=5.014703 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000060 sec of elapsed time Sampled Session History of session 177 serial 50095 --------------------------------------------------- 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:10 - 22:00:10] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-28 22:00:10.252 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 16700, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-28 19:37:21.092872 :B83B2F23:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19444 pso_num=22 pso_serial#=49 2025-07-28 19:37:21.093023 :B83B2F24:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19444 osp_idx=0 osp_ver=462181 osp_pg=0 (spawn #432159) 2025-07-28 19:37:21.093025 :B83B2F25:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 19:37:21.093025 :B83B2F26:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=101 time=2412216986 2025-07-28 19:37:21.093025 :B83B2F27:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 19:37:21.093026 :B83B2F28:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 19:37:21.093026 :B83B2F29:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 19:37:21.093026 :B83B2F2A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 19:37:21.093027 :B83B2F2B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 19:37:21.093513 :B83B2F2C: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-07-28 19:37:21.093560 :B83B2F33: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-07-28 19:47:21.831112 :B83BF500:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 19:47:22.164061 :B83BF57F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 19:47:22.159 2025-07-28 19:47:22.164064 :B83BF580:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17956 pso_num=22 pso_serial#=50 2025-07-28 19:47:22.164218 :B83BF581:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17956 osp_idx=0 osp_ver=462182 osp_pg=0 (spawn #432182) 2025-07-28 19:47:22.164219 :B83BF582:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 19:47:22.164219 :B83BF583:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=102 time=2412818064 2025-07-28 19:47:22.164220 :B83BF584:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 19:47:22.164220 :B83BF585:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 19:47:22.164221 :B83BF586:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 19:47:22.164221 :B83BF587:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 19:47:22.164221 :B83BF588:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 19:47:22.164724 :B83BF589: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-07-28 19:47:22.164770 :B83BF592: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-07-28 19:57:22.998190 :B83CBB24:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 19:57:23.331065 :B83CBB8B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 19:57:23.326 2025-07-28 19:57:23.331066 :B83CBB8C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17436 pso_num=22 pso_serial#=51 2025-07-28 19:57:23.331202 :B83CBB8D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17436 osp_idx=0 osp_ver=462183 osp_pg=0 (spawn #432205) 2025-07-28 19:57:23.331202 :B83CBB8E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 19:57:23.331203 :B83CBB8F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=103 time=2413419220 2025-07-28 19:57:23.331203 :B83CBB90:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 19:57:23.331203 :B83CBB91:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 19:57:23.331204 :B83CBB92:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 19:57:23.331204 :B83CBB93:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 19:57:23.331204 :B83CBB94:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 19:57:23.331683 :B83CBB95: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-07-28 19:57:23.331731 :B83CBB9E: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-07-28 19:57:38.360606 :B83CC101: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-07-28 20:07:24.215529 :B83D8C53:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 20:07:24.470110 :B83D8CB6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 20:07:24.465 2025-07-28 20:07:24.470112 :B83D8CB7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=3448 pso_num=22 pso_serial#=52 2025-07-28 20:07:24.470254 :B83D8CB8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=3448 osp_idx=0 osp_ver=462184 osp_pg=0 (spawn #432231) 2025-07-28 20:07:24.470254 :B83D8CB9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 20:07:24.470255 :B83D8CBA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=104 time=2414020361 2025-07-28 20:07:24.470256 :B83D8CBB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 20:07:24.470256 :B83D8CBC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 20:07:24.470256 :B83D8CBD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 20:07:24.470257 :B83D8CBE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 20:07:24.470257 :B83D8CBF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 20:07:24.470734 :B83D8CC0: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-07-28 20:07:24.470785 :B83D8CCA: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-07-28 20:17:25.346341 :B83E5204:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 20:17:25.587769 :B83E5267:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 20:17:25.582 2025-07-28 20:17:25.587772 :B83E5268:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4148 pso_num=22 pso_serial#=53 2025-07-28 20:17:25.587917 :B83E5269:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4148 osp_idx=0 osp_ver=462185 osp_pg=0 (spawn #432254) 2025-07-28 20:17:25.587917 :B83E526A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 20:17:25.587918 :B83E526B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=105 time=2414621486 2025-07-28 20:17:25.587918 :B83E526C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 20:17:25.587918 :B83E526D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 20:17:25.587918 :B83E526E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 20:17:25.587919 :B83E526F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 20:17:25.587919 :B83E5270:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 20:17:25.588418 :B83E5271: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-07-28 20:17:25.588471 :B83E527B: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-07-28 20:27:26.456869 :B83F1A7D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 20:27:26.695999 :B83F1ABC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 20:27:26.691 2025-07-28 20:27:26.696001 :B83F1ABD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7436 pso_num=22 pso_serial#=54 2025-07-28 20:27:26.696141 :B83F1ABE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7436 osp_idx=0 osp_ver=462186 osp_pg=0 (spawn #432276) 2025-07-28 20:27:26.696142 :B83F1ABF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 20:27:26.696142 :B83F1AC0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=106 time=2415222595 2025-07-28 20:27:26.696142 :B83F1AC1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 20:27:26.696143 :B83F1AC2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 20:27:26.696143 :B83F1AC3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 20:27:26.696144 :B83F1AC4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 20:27:26.696144 :B83F1AC5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 20:27:26.696651 :B83F1AC6: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-07-28 20:27:26.696700 :B83F1ACC: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-07-28 20:37:27.448085 :B83FE2A1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 20:37:27.858981 :B83FE2DF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 20:37:27.854 2025-07-28 20:37:27.858983 :B83FE2E0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18772 pso_num=22 pso_serial#=55 2025-07-28 20:37:27.859111 :B83FE2E1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18772 osp_idx=0 osp_ver=462187 osp_pg=0 (spawn #432299) 2025-07-28 20:37:27.859112 :B83FE2E2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 20:37:27.859112 :B83FE2E3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=107 time=2415823751 2025-07-28 20:37:27.859112 :B83FE2E4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 20:37:27.859113 :B83FE2E5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 20:37:27.859113 :B83FE2E6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 20:37:27.859114 :B83FE2E7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 20:37:27.859114 :B83FE2E8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 20:37:27.859600 :B83FE2E9: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-07-28 20:37:27.859644 :B83FE2F1: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-07-28 20:47:28.604340 :B840AB35:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 20:47:29.020657 :B840AB73:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 20:47:29.016 2025-07-28 20:47:29.020659 :B840AB74:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12284 pso_num=22 pso_serial#=56 2025-07-28 20:47:29.020792 :B840AB75:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12284 osp_idx=0 osp_ver=462188 osp_pg=0 (spawn #432322) 2025-07-28 20:47:29.020793 :B840AB76:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 20:47:29.020793 :B840AB77:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=108 time=2416424908 2025-07-28 20:47:29.020794 :B840AB78:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 20:47:29.020794 :B840AB79:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 20:47:29.020795 :B840AB7A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 20:47:29.020795 :B840AB7B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 20:47:29.020795 :B840AB7C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 20:47:29.021289 :B840AB7D: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-07-28 20:47:29.021337 :B840AB84: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-07-28 20:57:29.899904 :B8417269:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 20:57:30.201558 :B84172B5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 20:57:30.197 2025-07-28 20:57:30.201560 :B84172B6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18440 pso_num=22 pso_serial#=57 2025-07-28 20:57:30.201694 :B84172B7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18440 osp_idx=0 osp_ver=462189 osp_pg=0 (spawn #432344) 2025-07-28 20:57:30.201695 :B84172B8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 20:57:30.201695 :B84172B9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=109 time=2417026095 2025-07-28 20:57:30.201695 :B84172BA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 20:57:30.201696 :B84172BB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 20:57:30.201696 :B84172BC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 20:57:30.201696 :B84172BD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 20:57:30.201697 :B84172BE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 20:57:30.202180 :B84172BF: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-07-28 20:57:30.202226 :B84172C6: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-07-28 21:07:30.926349 :B84242C2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 21:07:31.306098 :B8424302:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 21:07:31.301 2025-07-28 21:07:31.306101 :B8424303:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18548 pso_num=22 pso_serial#=58 2025-07-28 21:07:31.306285 :B8424304:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18548 osp_idx=0 osp_ver=462190 osp_pg=0 (spawn #432370) 2025-07-28 21:07:31.306286 :B8424305:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 21:07:31.306286 :B8424306:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=110 time=2417627204 2025-07-28 21:07:31.306287 :B8424307:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:07:31.306287 :B8424308:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:07:31.306288 :B8424309:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:07:31.306288 :B842430A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:07:31.306288 :B842430B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:07:31.306787 :B842430C: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-07-28 21:07:31.306831 :B8424313: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-07-28 21:14:02.027622 :B842C386: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-07-28 21:17:32.514988 :B84308EC: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-07-28 21:27:33.341428 :B843D168:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 21:27:33.833871 :B843D1CF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 21:27:33.828 2025-07-28 21:27:33.833873 :B843D1D0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19032 pso_num=22 pso_serial#=59 2025-07-28 21:27:33.834013 :B843D1D1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19032 osp_idx=0 osp_ver=462191 osp_pg=0 (spawn #432414) 2025-07-28 21:27:33.834014 :B843D1D2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 21:27:33.834014 :B843D1D3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=111 time=2418829720 2025-07-28 21:27:33.834015 :B843D1D4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:27:33.834015 :B843D1D5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:27:33.834015 :B843D1D6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:27:33.834016 :B843D1D7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:27:33.834016 :B843D1D8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:27:33.834515 :B843D1D9: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-07-28 21:27:33.834563 :B843D1E3: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-07-28 21:37:34.476321 :B84497D7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 21:37:35.012391 :B844983E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 21:37:35.007 2025-07-28 21:37:35.012393 :B844983F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19284 pso_num=22 pso_serial#=60 2025-07-28 21:37:35.012527 :B8449840:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19284 osp_idx=0 osp_ver=462192 osp_pg=0 (spawn #432437) 2025-07-28 21:37:35.012528 :B8449841:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 21:37:35.012528 :B8449842:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=112 time=2419430908 2025-07-28 21:37:35.012529 :B8449843:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:37:35.012529 :B8449844:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:37:35.012529 :B8449845:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:37:35.012530 :B8449846:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:37:35.012530 :B8449847:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:37:35.013011 :B8449848: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-07-28 21:37:35.013058 :B844984F: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-07-28 21:47:35.718128 :B8455DCA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 21:47:36.316727 :B8455E32:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 21:47:36.312 2025-07-28 21:47:36.316729 :B8455E33:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13760 pso_num=22 pso_serial#=61 2025-07-28 21:47:36.316870 :B8455E34:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13760 osp_idx=0 osp_ver=462193 osp_pg=0 (spawn #432460) 2025-07-28 21:47:36.316871 :B8455E35:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 21:47:36.316871 :B8455E36:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=113 time=2420032204 2025-07-28 21:47:36.316872 :B8455E37:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:47:36.316872 :B8455E38:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:47:36.316872 :B8455E39:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:47:36.316873 :B8455E3A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:47:36.316873 :B8455E3B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:47:36.317374 :B8455E3C: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-07-28 21:47:36.317419 :B8455E44: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-07-28 21:48:21.379539 :B8456D59:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-07-28 21:48:21.379586 :B8456D6D:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-07-28 21:48:21.379588 :B8456D6E:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=47, exc=47, tot=47 2025-07-28 21:57:37.137601 :B84623BE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-28 21:57:37.455339 :B846242A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-28 21:57:37.455 2025-07-28 21:57:37.455341 :B846242B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16700 pso_num=22 pso_serial#=62 2025-07-28 21:57:37.455479 :B846242C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16700 osp_idx=0 osp_ver=462194 osp_pg=0 (spawn #432482) 2025-07-28 21:57:37.455479 :B846242D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-28 21:57:37.455480 :B846242E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=114 time=2420633345 2025-07-28 21:57:37.455480 :B846242F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:57:37.455481 :B8462430:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:57:37.455481 :B8462431:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:57:37.455481 :B8462432:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:57:37.455481 :B8462433:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:57:37.455983 :B8462434: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-07-28 21:57:37.456028 :B846243B: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 16700, W000)