Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250914060008\orcl_w000_19356_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:34753M/63366M, Ph+PgF:39359M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 19356, image: ORACLE.EXE (W000) *** 2025-09-14 06:00:08.731 *** SESSION ID:(177.56889) 2025-09-14 06:00:08.731 *** 2025-09-14 06:00:08.731 Process diagnostic dump for ORACLE.EXE (W000), OS id=19356, pid: 22, proc_ser: 92, sid: 177, sess_ser: 56889 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=4.142910 sec, exc=4.142910 sec, total=4.142910 sec wait times: max=5.000000 sec, heur=1 min 49 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.000021 sec since current wait 0: 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.003077 sec, exc=5.003077 sec, total=5.003077 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.004627 sec, exc=5.004627 sec, total=5.004627 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=19 seq_num=20 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.000027 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.004196 sec, exc=5.004196 sec, total=5.004196 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.002139 sec, exc=5.002139 sec, total=5.002139 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=16 seq_num=17 snap_id=1 wait times: snap=5.001426 sec, exc=5.001426 sec, total=5.001426 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=5.000318 sec, exc=5.000318 sec, total=5.000318 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=5.007507 sec, exc=5.007507 sec, total=5.007507 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=5.004717 sec, exc=5.004717 sec, total=5.004717 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=12 seq_num=13 snap_id=1 wait times: snap=5.014746 sec, exc=5.014746 sec, total=5.014746 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time Sampled Session History of session 177 serial 56889 --------------------------------------------------- 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 --------------------------------------------------- [110 samples, 05:58:19 - 06:00:08] idle wait at each sample [session created at: 05:58:19] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-14 06:00:08.731 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 19356, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-14 03:38:02.276001 :CD21CAD0:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 03:38:02.276003 :CD21CAD1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=138 time=2206733580 2025-09-14 03:38:02.276003 :CD21CAD2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 03:38:02.276004 :CD21CAD3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 03:38:02.276004 :CD21CAD4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 03:38:02.276004 :CD21CAD5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 03:38:02.276005 :CD21CAD6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 03:38:02.276507 :CD21CAD7: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-09-14 03:38:02.276550 :CD21CADF: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-09-14 03:48:03.247221 :CD228F13:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 03:48:03.564517 :CD228F64:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 03:48:03.560 2025-09-14 03:48:03.564519 :CD228F65:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19768 pso_num=22 pso_serial#=80 2025-09-14 03:48:03.564659 :CD228F66:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19768 osp_idx=0 osp_ver=604247 osp_pg=0 (spawn #589975) 2025-09-14 03:48:03.564659 :CD228F67:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 03:48:03.564660 :CD228F68:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=139 time=2207334862 2025-09-14 03:48:03.564660 :CD228F69:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 03:48:03.564660 :CD228F6A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 03:48:03.564661 :CD228F6B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 03:48:03.564661 :CD228F6C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 03:48:03.564661 :CD228F6D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 03:48:03.565225 :CD228F6E: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-09-14 03:48:03.565269 :CD228F76: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-09-14 03:58:04.462610 :CD235369:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 03:58:04.858013 :CD2353B9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 03:58:04.853 2025-09-14 03:58:04.858015 :CD2353BA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23100 pso_num=22 pso_serial#=81 2025-09-14 03:58:04.858148 :CD2353BB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23100 osp_idx=0 osp_ver=604248 osp_pg=0 (spawn #589998) 2025-09-14 03:58:04.858149 :CD2353BC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 03:58:04.858149 :CD2353BD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=140 time=2207936158 2025-09-14 03:58:04.858150 :CD2353BE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 03:58:04.858150 :CD2353BF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 03:58:04.858151 :CD2353C0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 03:58:04.858151 :CD2353C1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 03:58:04.858151 :CD2353C2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 03:58:04.858724 :CD2353C3: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-09-14 03:58:04.858768 :CD2353CB: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-09-14 04:00:31.874528 :CD238401: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-09-14 04:08:06.038367 :CD24235E: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-09-14 04:18:06.964223 :CD24E688:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 04:18:07.203425 :CD24E6DC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 04:18:07.198 2025-09-14 04:18:07.203427 :CD24E6DD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22072 pso_num=22 pso_serial#=82 2025-09-14 04:18:07.203566 :CD24E6DE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22072 osp_idx=0 osp_ver=604249 osp_pg=0 (spawn #590045) 2025-09-14 04:18:07.203567 :CD24E6DF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 04:18:07.203568 :CD24E6E0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=141 time=2209138502 2025-09-14 04:18:07.203568 :CD24E6E1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 04:18:07.203568 :CD24E6E2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 04:18:07.203569 :CD24E6E3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 04:18:07.203569 :CD24E6E4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 04:18:07.203569 :CD24E6E5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 04:18:07.204057 :CD24E6E6: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-09-14 04:18:07.204104 :CD24E6EE: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-09-14 04:28:08.046833 :CD25AAD6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 04:28:08.442335 :CD25AB2F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 04:28:08.437 2025-09-14 04:28:08.442336 :CD25AB30:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=25500 pso_num=22 pso_serial#=83 2025-09-14 04:28:08.442477 :CD25AB31:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=25500 osp_idx=0 osp_ver=604250 osp_pg=0 (spawn #590068) 2025-09-14 04:28:08.442478 :CD25AB32:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 04:28:08.442478 :CD25AB33:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=142 time=2209739752 2025-09-14 04:28:08.442479 :CD25AB34:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 04:28:08.442479 :CD25AB35:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 04:28:08.442479 :CD25AB36:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 04:28:08.442480 :CD25AB37:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 04:28:08.442480 :CD25AB38:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 04:28:08.442974 :CD25AB39: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-09-14 04:28:08.443028 :CD25AB40: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-09-14 04:28:38.499591 :CD25B523: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-09-14 04:28:38.499617 :CD25B528: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-09-14 04:28:38.499618 :CD25B529:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=24, exc=24, tot=24 2025-09-14 04:38:09.278206 :CD266FCD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 04:38:09.621407 :CD26701A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 04:38:09.617 2025-09-14 04:38:09.621409 :CD26701B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24716 pso_num=22 pso_serial#=84 2025-09-14 04:38:09.621557 :CD26701C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24716 osp_idx=0 osp_ver=604251 osp_pg=0 (spawn #590090) 2025-09-14 04:38:09.621558 :CD26701D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 04:38:09.621558 :CD26701E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=143 time=2210340924 2025-09-14 04:38:09.621558 :CD26701F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 04:38:09.621559 :CD267020:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 04:38:09.621559 :CD267021:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 04:38:09.621559 :CD267022:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 04:38:09.621560 :CD267023:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 04:38:09.622051 :CD267024: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-09-14 04:38:09.622099 :CD26702B: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-09-14 04:48:10.519283 :CD273509:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 04:48:10.789658 :CD27354A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 04:48:10.784 2025-09-14 04:48:10.789660 :CD27354B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23856 pso_num=22 pso_serial#=85 2025-09-14 04:48:10.789799 :CD27354C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23856 osp_idx=0 osp_ver=604252 osp_pg=0 (spawn #590113) 2025-09-14 04:48:10.789800 :CD27354D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 04:48:10.789800 :CD27354E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=144 time=2210942096 2025-09-14 04:48:10.789801 :CD27354F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 04:48:10.789801 :CD273550:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 04:48:10.789801 :CD273551:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 04:48:10.789802 :CD273552:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 04:48:10.789802 :CD273553:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 04:48:10.790287 :CD273554: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-09-14 04:48:10.790331 :CD27355C: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-09-14 04:58:11.728836 :CD27F94E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 04:58:11.921386 :CD27F9A3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 04:58:11.917 2025-09-14 04:58:11.921388 :CD27F9A4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24028 pso_num=22 pso_serial#=86 2025-09-14 04:58:11.921542 :CD27F9A5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24028 osp_idx=0 osp_ver=604253 osp_pg=0 (spawn #590136) 2025-09-14 04:58:11.921542 :CD27F9A6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 04:58:11.921543 :CD27F9A7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=145 time=2211543221 2025-09-14 04:58:11.921543 :CD27F9A8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 04:58:11.921543 :CD27F9A9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 04:58:11.921543 :CD27F9AA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 04:58:11.921544 :CD27F9AB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 04:58:11.921544 :CD27F9AC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 04:58:11.922061 :CD27F9AD: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-09-14 04:58:11.922111 :CD27F9B4: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-09-14 05:08:12.782295 :CD28C8A8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 05:08:13.193416 :CD28C8F8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 05:08:13.189 2025-09-14 05:08:13.193418 :CD28C8F9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21584 pso_num=22 pso_serial#=87 2025-09-14 05:08:13.193561 :CD28C8FA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21584 osp_idx=0 osp_ver=604254 osp_pg=0 (spawn #590161) 2025-09-14 05:08:13.193562 :CD28C8FB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 05:08:13.193563 :CD28C8FC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=146 time=2212144502 2025-09-14 05:08:13.193563 :CD28C8FD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 05:08:13.193564 :CD28C8FE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 05:08:13.193564 :CD28C8FF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 05:08:13.193564 :CD28C900:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 05:08:13.193565 :CD28C901:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 05:08:13.194089 :CD28C902: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-09-14 05:08:13.194133 :CD28C90A: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-09-14 05:18:14.053236 :CD298C3F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 05:18:14.464411 :CD298C99:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 05:18:14.459 2025-09-14 05:18:14.464413 :CD298C9A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19848 pso_num=22 pso_serial#=88 2025-09-14 05:18:14.464544 :CD298C9B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19848 osp_idx=0 osp_ver=604255 osp_pg=0 (spawn #590184) 2025-09-14 05:18:14.464545 :CD298C9C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 05:18:14.464545 :CD298C9D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=147 time=2212745768 2025-09-14 05:18:14.464546 :CD298C9E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 05:18:14.464546 :CD298C9F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 05:18:14.464546 :CD298CA0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 05:18:14.464547 :CD298CA1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 05:18:14.464547 :CD298CA2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 05:18:14.465040 :CD298CA3: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-09-14 05:18:14.465092 :CD298CAD: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-09-14 05:28:15.349869 :CD2A50DE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 05:28:15.698937 :CD2A5130:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 05:28:15.693 2025-09-14 05:28:15.698939 :CD2A5131:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23424 pso_num=22 pso_serial#=89 2025-09-14 05:28:15.699107 :CD2A5132:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23424 osp_idx=0 osp_ver=604256 osp_pg=0 (spawn #590207) 2025-09-14 05:28:15.699108 :CD2A5133:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 05:28:15.699108 :CD2A5134:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=148 time=2213347002 2025-09-14 05:28:15.699109 :CD2A5135:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 05:28:15.699109 :CD2A5136:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 05:28:15.699109 :CD2A5137:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 05:28:15.699110 :CD2A5138:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 05:28:15.699110 :CD2A5139:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 05:28:15.699669 :CD2A513A: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-09-14 05:28:15.699715 :CD2A5141: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-09-14 05:28:45.742208 :CD2A5AFD: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-09-14 05:28:45.742213 :CD2A5B00: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-09-14 05:28:45.742214 :CD2A5B01:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=5, exc=5, tot=5 2025-09-14 05:28:45.742223 :CD2A5B06: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-09-14 05:38:16.486267 :CD2B159B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 05:38:16.912911 :CD2B160A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 05:38:16.908 2025-09-14 05:38:16.912914 :CD2B160B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22396 pso_num=22 pso_serial#=90 2025-09-14 05:38:16.913056 :CD2B160C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22396 osp_idx=0 osp_ver=604257 osp_pg=0 (spawn #590229) 2025-09-14 05:38:16.913056 :CD2B160D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 05:38:16.913057 :CD2B160E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=149 time=2213948221 2025-09-14 05:38:16.913057 :CD2B160F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 05:38:16.913057 :CD2B1610:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 05:38:16.913058 :CD2B1611:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 05:38:16.913058 :CD2B1612:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 05:38:16.913059 :CD2B1613:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 05:38:16.913558 :CD2B1614: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-09-14 05:38:16.913607 :CD2B161C: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-09-14 05:48:17.783602 :CD2BDACE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 05:48:18.179016 :CD2BDB47:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 05:48:18.173 2025-09-14 05:48:18.179018 :CD2BDB48:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21564 pso_num=22 pso_serial#=91 2025-09-14 05:48:18.179150 :CD2BDB49:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21564 osp_idx=0 osp_ver=604258 osp_pg=0 (spawn #590252) 2025-09-14 05:48:18.179151 :CD2BDB4A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 05:48:18.179151 :CD2BDB4B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=150 time=2214549487 2025-09-14 05:48:18.179152 :CD2BDB4C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 05:48:18.179152 :CD2BDB4D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 05:48:18.179153 :CD2BDB4E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 05:48:18.179153 :CD2BDB4F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 05:48:18.179153 :CD2BDB50:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 05:48:18.179645 :CD2BDB51: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-09-14 05:48:18.179690 :CD2BDB5B: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-09-14 05:58:19.070845 :CD2C9EF2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-14 05:58:19.446497 :CD2C9F4A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-14 05:58:19.442 2025-09-14 05:58:19.446498 :CD2C9F4B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19356 pso_num=22 pso_serial#=92 2025-09-14 05:58:19.446633 :CD2C9F4C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19356 osp_idx=0 osp_ver=604259 osp_pg=0 (spawn #590275) 2025-09-14 05:58:19.446634 :CD2C9F4D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-14 05:58:19.446634 :CD2C9F4E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=151 time=2215150752 2025-09-14 05:58:19.446634 :CD2C9F4F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-14 05:58:19.446635 :CD2C9F50:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-14 05:58:19.446635 :CD2C9F51:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-14 05:58:19.446635 :CD2C9F52:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-14 05:58:19.446636 :CD2C9F53:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-14 05:58:19.447125 :CD2C9F54: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-09-14 05:58:19.447169 :CD2C9F5D: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: 19356, W000)