Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250729082346\orcl_w000_4728_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:35923M/63366M, Ph+PgF:41625M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 4728, image: ORACLE.EXE (W000) *** 2025-07-29 08:23:46.600 *** SESSION ID:(177.52407) 2025-07-29 08:23:46.600 *** 2025-07-29 08:23:46.600 Process diagnostic dump for ORACLE.EXE (W000), OS id=4728, pid: 22, proc_ser: 27, sid: 177, sess_ser: 52407 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=60 seq_num=61 snap_id=1 wait times: snap=0.654124 sec, exc=0.654124 sec, total=0.654124 sec wait times: max=5.000000 sec, heur=4 min 56 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000034 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=59 seq_num=60 snap_id=1 wait times: snap=5.002123 sec, exc=5.002123 sec, total=5.002123 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=58 seq_num=59 snap_id=1 wait times: snap=5.004195 sec, exc=5.004195 sec, total=5.004195 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=57 seq_num=58 snap_id=1 wait times: snap=5.000732 sec, exc=5.000732 sec, total=5.000732 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=56 seq_num=57 snap_id=1 wait times: snap=5.004630 sec, exc=5.004630 sec, total=5.004630 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=55 seq_num=56 snap_id=1 wait times: snap=5.004626 sec, exc=5.004626 sec, total=5.004626 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=54 seq_num=55 snap_id=1 wait times: snap=5.001694 sec, exc=5.001694 sec, total=5.001694 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=53 seq_num=54 snap_id=1 wait times: snap=5.001235 sec, exc=5.001235 sec, total=5.001235 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=52 seq_num=53 snap_id=1 wait times: snap=5.013517 sec, exc=5.013517 sec, total=5.013517 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=51 seq_num=52 snap_id=1 wait times: snap=5.001499 sec, exc=5.001499 sec, total=5.001499 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=50 seq_num=51 snap_id=1 wait times: snap=5.004702 sec, exc=5.004702 sec, total=5.004702 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time Sampled Session History of session 177 serial 52407 --------------------------------------------------- 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, 08:21:46 - 08:23:46] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-29 08:23:46.600 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 4728, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-29 06:08:34.916466 :B86C6FE1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:08:35.290205 :B86C6FE4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:08:35.276 2025-07-29 06:08:35.290208 :B86C6FE5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12636 pso_num=22 pso_serial#=13 2025-07-29 06:08:35.290342 :B86C6FE6:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12636 (legacy spawn) 2025-07-29 06:08:35.296798 :B86C6FE7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-29 06:08:35.296971 :B86C6FEC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-29 06:08:35.297776 :B86C6FF1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:08:35.315625 :B86C6FF4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:08:35.307 2025-07-29 06:08:35.315627 :B86C6FF5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4800 pso_num=22 pso_serial#=14 2025-07-29 06:08:35.315772 :B86C6FF6:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=4800 (legacy spawn) 2025-07-29 06:08:35.322267 :B86C6FF7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-29 06:08:35.322452 :B86C7008:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-29 06:08:35.323295 :B86C700D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:08:35.358766 :B86C706B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:08:35.354 2025-07-29 06:08:35.358767 :B86C706C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18480 pso_num=22 pso_serial#=15 2025-07-29 06:08:35.358904 :B86C706D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18480 osp_idx=0 osp_ver=463167 osp_pg=0 (spawn #433624) 2025-07-29 06:08:35.358904 :B86C706E: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-29 06:08:35.358905 :B86C706F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=57 time=2450091251 2025-07-29 06:08:35.358905 :B86C7070:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 06:08:35.358906 :B86C7071:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 06:08:35.358906 :B86C7072:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 06:08:35.358906 :B86C7073:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 06:08:35.358906 :B86C7074:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 06:08:35.359407 :B86C7075: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-29 06:08:35.359451 :B86C707D: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-29 06:18:36.203445 :B86D3569:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:18:36.567526 :B86D35B4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:18:36.563 2025-07-29 06:18:36.567529 :B86D35B5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6792 pso_num=22 pso_serial#=16 2025-07-29 06:18:36.567670 :B86D35B6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6792 osp_idx=0 osp_ver=463168 osp_pg=0 (spawn #433647) 2025-07-29 06:18:36.567670 :B86D35B7: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-29 06:18:36.567671 :B86D35B8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=58 time=2450692454 2025-07-29 06:18:36.567671 :B86D35B9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 06:18:36.567672 :B86D35BA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 06:18:36.567672 :B86D35BB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 06:18:36.567672 :B86D35BC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 06:18:36.567673 :B86D35BD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 06:18:36.568216 :B86D35BE: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-29 06:18:36.568261 :B86D35C8: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-29 06:28:37.344399 :B86DFB78:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:28:37.781057 :B86DFBD0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:28:37.776 2025-07-29 06:28:37.781059 :B86DFBD1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18784 pso_num=22 pso_serial#=17 2025-07-29 06:28:37.781194 :B86DFBD2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18784 osp_idx=0 osp_ver=463169 osp_pg=0 (spawn #433669) 2025-07-29 06:28:37.781195 :B86DFBD3: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-29 06:28:37.781196 :B86DFBD4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=59 time=2451293673 2025-07-29 06:28:37.781196 :B86DFBD5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 06:28:37.781196 :B86DFBD6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 06:28:37.781197 :B86DFBD7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 06:28:37.781197 :B86DFBD8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 06:28:37.781197 :B86DFBD9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 06:28:37.781679 :B86DFBDA: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-29 06:28:37.781724 :B86DFBE3: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-29 06:38:38.555942 :B86EC164:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:38:38.951324 :B86EC1A9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:38:38.946 2025-07-29 06:38:38.951326 :B86EC1AA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4264 pso_num=22 pso_serial#=18 2025-07-29 06:38:38.951461 :B86EC1AB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4264 osp_idx=0 osp_ver=463170 osp_pg=0 (spawn #433692) 2025-07-29 06:38:38.951461 :B86EC1AC: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-29 06:38:38.951462 :B86EC1AD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=60 time=2451894845 2025-07-29 06:38:38.951462 :B86EC1AE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 06:38:38.951463 :B86EC1AF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 06:38:38.951463 :B86EC1B0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 06:38:38.951463 :B86EC1B1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 06:38:38.951464 :B86EC1B2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 06:38:38.951953 :B86EC1B3: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-29 06:38:38.951997 :B86EC1BA: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-29 06:48:39.759487 :B86F87E6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:48:40.156149 :B86F883B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:48:40.151 2025-07-29 06:48:40.156152 :B86F883C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10356 pso_num=22 pso_serial#=19 2025-07-29 06:48:40.156285 :B86F883D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10356 osp_idx=0 osp_ver=463171 osp_pg=0 (spawn #433715) 2025-07-29 06:48:40.156285 :B86F883E: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-29 06:48:40.156286 :B86F883F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=61 time=2452496048 2025-07-29 06:48:40.156286 :B86F8840:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 06:48:40.156286 :B86F8841:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 06:48:40.156287 :B86F8842:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 06:48:40.156287 :B86F8843:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 06:48:40.156288 :B86F8844:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 06:48:40.156776 :B86F8845: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-29 06:48:40.156822 :B86F884D: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-29 06:58:40.949215 :B8704CD0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 06:58:41.345140 :B8704D1A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 06:58:41.340 2025-07-29 06:58:41.345143 :B8704D1B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17868 pso_num=22 pso_serial#=20 2025-07-29 06:58:41.345291 :B8704D1C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17868 osp_idx=0 osp_ver=463172 osp_pg=0 (spawn #433737) 2025-07-29 06:58:41.345292 :B8704D1D: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-29 06:58:41.345292 :B8704D1E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=62 time=2453097236 2025-07-29 06:58:41.345293 :B8704D1F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 06:58:41.345293 :B8704D20:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 06:58:41.345293 :B8704D21:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 06:58:41.345294 :B8704D22:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 06:58:41.345294 :B8704D23:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 06:58:41.345859 :B8704D24: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-29 06:58:41.345909 :B8704D2B: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-29 07:08:42.110927 :B8711E32:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 07:08:42.568777 :B8711E7F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 07:08:42.564 2025-07-29 07:08:42.568779 :B8711E80:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19296 pso_num=22 pso_serial#=21 2025-07-29 07:08:42.568923 :B8711E81:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19296 osp_idx=0 osp_ver=463173 osp_pg=0 (spawn #433763) 2025-07-29 07:08:42.568924 :B8711E82: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-29 07:08:42.568924 :B8711E83:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=63 time=2453698470 2025-07-29 07:08:42.568924 :B8711E84:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 07:08:42.568925 :B8711E85:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 07:08:42.568925 :B8711E86:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 07:08:42.568926 :B8711E87:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 07:08:42.568926 :B8711E88:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 07:08:42.569436 :B8711E89: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-29 07:08:42.569479 :B8711E91: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-29 07:18:43.313619 :B871E2CD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 07:18:43.765911 :B871E320:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 07:18:43.761 2025-07-29 07:18:43.765912 :B871E321:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10356 pso_num=22 pso_serial#=22 2025-07-29 07:18:43.766052 :B871E322:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10356 osp_idx=0 osp_ver=463174 osp_pg=0 (spawn #433786) 2025-07-29 07:18:43.766053 :B871E323: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-29 07:18:43.766053 :B871E324:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=64 time=2454299658 2025-07-29 07:18:43.766054 :B871E325:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 07:18:43.766054 :B871E326:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 07:18:43.766055 :B871E327:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 07:18:43.766056 :B871E328:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 07:18:43.766057 :B871E329:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 07:18:43.766552 :B871E32A: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-29 07:18:43.766599 :B871E332: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-29 07:28:44.579452 :B872A8B7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 07:28:44.912391 :B872A901:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 07:28:44.907 2025-07-29 07:28:44.912394 :B872A902:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10156 pso_num=22 pso_serial#=23 2025-07-29 07:28:44.912539 :B872A903:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10156 osp_idx=0 osp_ver=463175 osp_pg=0 (spawn #433808) 2025-07-29 07:28:44.912540 :B872A904: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-29 07:28:44.912540 :B872A905:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=65 time=2454900814 2025-07-29 07:28:44.912541 :B872A906:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 07:28:44.912541 :B872A907:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 07:28:44.912541 :B872A908:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 07:28:44.912542 :B872A909:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 07:28:44.912542 :B872A90A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 07:28:44.913047 :B872A90B: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-29 07:28:44.913098 :B872A912: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-29 07:29:45.026236 :B872BD12:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=13 seq_num=14 snap_id=1 2025-07-29 07:29:45.026263 :B872BD1F:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=13 seq_num=14 snap_id=1 2025-07-29 07:29:45.026264 :B872BD20:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=25, exc=25, tot=25 2025-07-29 07:31:03.385770 :B872D6AB: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-29 07:38:46.039235 :B8736F39: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-29 07:48:46.838856 :B87433E9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 07:48:47.171643 :B874343F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 07:48:47.167 2025-07-29 07:48:47.171646 :B8743440:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8568 pso_num=22 pso_serial#=24 2025-07-29 07:48:47.171786 :B8743441:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8568 osp_idx=0 osp_ver=463176 osp_pg=0 (spawn #433853) 2025-07-29 07:48:47.171786 :B8743442: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-29 07:48:47.171787 :B8743443:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=66 time=2456103064 2025-07-29 07:48:47.171787 :B8743444:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 07:48:47.171788 :B8743445:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 07:48:47.171788 :B8743446:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 07:48:47.171788 :B8743447:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 07:48:47.171788 :B8743448:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 07:48:47.172294 :B8743449: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-29 07:48:47.172340 :B8743452: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-29 07:58:47.960561 :B874F9E6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 07:58:48.262128 :B874FA2F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 07:58:48.258 2025-07-29 07:58:48.262130 :B874FA30:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=3292 pso_num=22 pso_serial#=25 2025-07-29 07:58:48.262263 :B874FA31:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=3292 osp_idx=0 osp_ver=463177 osp_pg=0 (spawn #433876) 2025-07-29 07:58:48.262263 :B874FA32: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-29 07:58:48.262263 :B874FA33:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=67 time=2456704158 2025-07-29 07:58:48.262264 :B874FA34:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 07:58:48.262264 :B874FA35:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 07:58:48.262265 :B874FA36:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 07:58:48.262265 :B874FA37:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 07:58:48.262265 :B874FA38:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 07:58:48.262759 :B874FA39: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-29 07:58:48.262802 :B874FA3F: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-29 08:08:49.083711 :B875C6AD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 08:08:49.447809 :B875C6F8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 08:08:49.443 2025-07-29 08:08:49.447812 :B875C6F9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19192 pso_num=22 pso_serial#=26 2025-07-29 08:08:49.447946 :B875C6FA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19192 osp_idx=0 osp_ver=463178 osp_pg=0 (spawn #433902) 2025-07-29 08:08:49.447947 :B875C6FB: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-29 08:08:49.447948 :B875C6FC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=68 time=2457305345 2025-07-29 08:08:49.447948 :B875C6FD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 08:08:49.447948 :B875C6FE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 08:08:49.447949 :B875C6FF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 08:08:49.447949 :B875C700:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 08:08:49.447949 :B875C701:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 08:08:49.448434 :B875C702: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-29 08:08:49.448479 :B875C709: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-29 08:18:50.310728 :B8768F00:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-29 08:18:50.565356 :B8768F49:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-29 08:18:50.561 2025-07-29 08:18:50.565357 :B8768F4A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4728 pso_num=22 pso_serial#=27 2025-07-29 08:18:50.565498 :B8768F4B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4728 osp_idx=0 osp_ver=463179 osp_pg=0 (spawn #433925) 2025-07-29 08:18:50.565499 :B8768F4C: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-29 08:18:50.565499 :B8768F4D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=69 time=2457906454 2025-07-29 08:18:50.565500 :B8768F4E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 08:18:50.565500 :B8768F4F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 08:18:50.565500 :B8768F50:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 08:18:50.565501 :B8768F51:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 08:18:50.565501 :B8768F52:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 08:18:50.566002 :B8768F53: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-29 08:18:50.566051 :B8768F59: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: 4728, W000)