Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250807082951\orcl_w000_21368_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:35672M/63366M, Ph+PgF:41173M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 21368, image: ORACLE.EXE (W000) *** 2025-08-07 08:29:51.307 *** SESSION ID:(177.48993) 2025-08-07 08:29:51.307 *** 2025-08-07 08:29:51.307 Process diagnostic dump for ORACLE.EXE (W000), OS id=21368, pid: 22, proc_ser: 127, sid: 177, sess_ser: 48993 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=62 seq_num=63 snap_id=1 wait times: snap=4.230202 sec, exc=4.230202 sec, total=4.230202 sec wait times: max=5.000000 sec, heur=5 min 9 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=61 seq_num=62 snap_id=1 wait times: snap=5.004638 sec, exc=5.004638 sec, total=5.004638 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=60 seq_num=61 snap_id=1 wait times: snap=5.001710 sec, exc=5.001710 sec, total=5.001710 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 2: 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.001411 sec, exc=5.001411 sec, total=5.001411 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=58 seq_num=59 snap_id=1 wait times: snap=5.003245 sec, exc=5.003245 sec, total=5.003245 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=57 seq_num=58 snap_id=1 wait times: snap=5.005493 sec, exc=5.005493 sec, total=5.005493 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 5: 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.004633 sec, exc=5.004633 sec, total=5.004633 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 6: 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.004632 sec, exc=5.004632 sec, total=5.004632 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=54 seq_num=55 snap_id=1 wait times: snap=5.004632 sec, exc=5.004632 sec, total=5.004632 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 8: 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.014750 sec, exc=5.014750 sec, total=5.014750 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=52 seq_num=53 snap_id=1 wait times: snap=5.001697 sec, exc=5.001697 sec, total=5.001697 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 48993 --------------------------------------------------- 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:27:51 - 08:29:51] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-07 08:29:51.307 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 21368, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-07 06:04:24.704939 :BC6EE02F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 06:04:24.704939 :BC6EE030:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 06:04:24.704940 :BC6EE031:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 06:04:24.705459 :BC6EE032: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-08-07 06:04:24.705511 :BC6EE03A: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-08-07 06:14:25.554217 :BC6FAD53:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 06:14:26.012057 :BC6FAD87:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 06:14:26.007 2025-08-07 06:14:26.012059 :BC6FAD88:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17936 pso_num=22 pso_serial#=115 2025-08-07 06:14:26.012197 :BC6FAD89:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17936 osp_idx=0 osp_ver=489532 osp_pg=0 (spawn #463627) 2025-08-07 06:14:26.012198 :BC6FAD8A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 06:14:26.012198 :BC6FAD8B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=28 time=3227935314 2025-08-07 06:14:26.012199 :BC6FAD8C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 06:14:26.012199 :BC6FAD8D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 06:14:26.012200 :BC6FAD8E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 06:14:26.012200 :BC6FAD8F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 06:14:26.012200 :BC6FAD90:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 06:14:26.012705 :BC6FAD91: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-08-07 06:14:26.012752 :BC6FAD98: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-08-07 06:24:26.784623 :BC70710A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 06:24:27.211571 :BC70714B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 06:24:27.207 2025-08-07 06:24:27.211574 :BC70714C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19564 pso_num=22 pso_serial#=116 2025-08-07 06:24:27.211713 :BC70714D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19564 osp_idx=0 osp_ver=489533 osp_pg=0 (spawn #463649) 2025-08-07 06:24:27.211714 :BC70714E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 06:24:27.211714 :BC70714F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=29 time=3228536517 2025-08-07 06:24:27.211715 :BC707150:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 06:24:27.211715 :BC707151:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 06:24:27.211715 :BC707152:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 06:24:27.211716 :BC707153:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 06:24:27.211716 :BC707154:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 06:24:27.212227 :BC707155: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-08-07 06:24:27.212272 :BC70715C: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-08-07 06:34:28.107629 :BC713533:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 06:34:28.471625 :BC71356C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 06:34:28.466 2025-08-07 06:34:28.471627 :BC71356D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18772 pso_num=22 pso_serial#=117 2025-08-07 06:34:28.471768 :BC71356E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18772 osp_idx=0 osp_ver=489534 osp_pg=0 (spawn #463672) 2025-08-07 06:34:28.471768 :BC71356F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 06:34:28.471769 :BC713570:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=30 time=3229137783 2025-08-07 06:34:28.471769 :BC713571:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 06:34:28.471770 :BC713572:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 06:34:28.471770 :BC713573:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 06:34:28.471770 :BC713574:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 06:34:28.471771 :BC713575:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 06:34:28.472260 :BC713576: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-08-07 06:34:28.472314 :BC71357D: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-08-07 06:44:29.297950 :BC71F9CA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 06:44:29.750485 :BC71FA11:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 06:44:29.745 2025-08-07 06:44:29.750488 :BC71FA12:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18712 pso_num=22 pso_serial#=118 2025-08-07 06:44:29.750630 :BC71FA13:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18712 osp_idx=0 osp_ver=489535 osp_pg=0 (spawn #463695) 2025-08-07 06:44:29.750631 :BC71FA14:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 06:44:29.750632 :BC71FA15:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=31 time=3229739064 2025-08-07 06:44:29.750632 :BC71FA16:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 06:44:29.750632 :BC71FA17:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 06:44:29.750633 :BC71FA18:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 06:44:29.750633 :BC71FA19:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 06:44:29.750633 :BC71FA1A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 06:44:29.751140 :BC71FA1B: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-08-07 06:44:29.751190 :BC71FA21: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-08-07 06:54:30.551329 :BC72BE02:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 06:54:31.025003 :BC72BE49:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 06:54:31.019 2025-08-07 06:54:31.025006 :BC72BE4A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9844 pso_num=22 pso_serial#=119 2025-08-07 06:54:31.025152 :BC72BE4B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9844 osp_idx=0 osp_ver=489536 osp_pg=0 (spawn #463717) 2025-08-07 06:54:31.025152 :BC72BE4C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 06:54:31.025153 :BC72BE4D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=32 time=3230340329 2025-08-07 06:54:31.025153 :BC72BE4E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 06:54:31.025154 :BC72BE4F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 06:54:31.025154 :BC72BE50:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 06:54:31.025154 :BC72BE51:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 06:54:31.025155 :BC72BE52:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 06:54:31.025674 :BC72BE53: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-08-07 06:54:31.025723 :BC72BE5A: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-08-07 07:00:42.034812 :BC7336FC: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-08-07 07:04:32.346871 :BC7383F7: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-08-07 07:14:33.300249 :BC7453C2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 07:14:33.554781 :BC7453FA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 07:14:33.550 2025-08-07 07:14:33.554783 :BC7453FB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20860 pso_num=22 pso_serial#=120 2025-08-07 07:14:33.554920 :BC7453FC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20860 osp_idx=0 osp_ver=489537 osp_pg=0 (spawn #463765) 2025-08-07 07:14:33.554920 :BC7453FD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 07:14:33.554921 :BC7453FE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=33 time=3231542861 2025-08-07 07:14:33.554921 :BC7453FF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 07:14:33.554921 :BC745400:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 07:14:33.554922 :BC745401:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 07:14:33.554922 :BC745402:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 07:14:33.554922 :BC745403:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 07:14:33.555407 :BC745404: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-08-07 07:14:33.555454 :BC74540B: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-08-07 07:24:34.322570 :BC751AEF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 07:24:34.639838 :BC751B26:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 07:24:34.634 2025-08-07 07:24:34.639840 :BC751B27:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19724 pso_num=22 pso_serial#=121 2025-08-07 07:24:34.639976 :BC751B28:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19724 osp_idx=0 osp_ver=489538 osp_pg=0 (spawn #463787) 2025-08-07 07:24:34.639977 :BC751B29:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 07:24:34.639978 :BC751B2A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=34 time=3232143939 2025-08-07 07:24:34.639978 :BC751B2B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 07:24:34.639978 :BC751B2C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 07:24:34.639979 :BC751B2D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 07:24:34.639979 :BC751B2E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 07:24:34.639979 :BC751B2F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 07:24:34.640486 :BC751B30: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-08-07 07:24:34.640541 :BC751B37: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-08-07 07:34:35.493268 :BC75E13D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 07:34:35.826364 :BC75E170:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 07:34:35.821 2025-08-07 07:34:35.826366 :BC75E171:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20664 pso_num=22 pso_serial#=122 2025-08-07 07:34:35.826518 :BC75E172:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20664 osp_idx=0 osp_ver=489539 osp_pg=0 (spawn #463810) 2025-08-07 07:34:35.826519 :BC75E173:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 07:34:35.826520 :BC75E174:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=35 time=3232745126 2025-08-07 07:34:35.826520 :BC75E175:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 07:34:35.826521 :BC75E176:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 07:34:35.826521 :BC75E177:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 07:34:35.826521 :BC75E178:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 07:34:35.826522 :BC75E179:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 07:34:35.827036 :BC75E17A: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-08-07 07:34:35.827080 :BC75E181: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-08-07 07:44:36.570551 :BC76A833:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 07:44:36.997330 :BC76A873:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 07:44:36.992 2025-08-07 07:44:36.997332 :BC76A874:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18492 pso_num=22 pso_serial#=123 2025-08-07 07:44:36.997476 :BC76A875:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18492 osp_idx=0 osp_ver=489540 osp_pg=0 (spawn #463833) 2025-08-07 07:44:36.997477 :BC76A876:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 07:44:36.997477 :BC76A877:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=36 time=3233346298 2025-08-07 07:44:36.997478 :BC76A878:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 07:44:36.997478 :BC76A879:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 07:44:36.997478 :BC76A87A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 07:44:36.997479 :BC76A87B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 07:44:36.997479 :BC76A87C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 07:44:36.997988 :BC76A87D: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-08-07 07:44:36.998042 :BC76A885: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-08-07 07:54:37.829220 :BC776FD5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 07:54:38.203214 :BC777010:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 07:54:38.198 2025-08-07 07:54:38.203216 :BC777011:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19516 pso_num=22 pso_serial#=124 2025-08-07 07:54:38.203358 :BC777012:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19516 osp_idx=0 osp_ver=489541 osp_pg=0 (spawn #463855) 2025-08-07 07:54:38.203359 :BC777013:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 07:54:38.203359 :BC777014:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=37 time=3233947501 2025-08-07 07:54:38.203360 :BC777015:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 07:54:38.203360 :BC777016:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 07:54:38.203360 :BC777017:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 07:54:38.203361 :BC777018:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 07:54:38.203361 :BC777019:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 07:54:38.203868 :BC77701A: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-08-07 07:54:38.203913 :BC777022: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-08-07 08:04:39.088944 :BC783D18:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 08:04:39.343881 :BC783D4E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 08:04:39.338 2025-08-07 08:04:39.343883 :BC783D4F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18492 pso_num=22 pso_serial#=125 2025-08-07 08:04:39.344030 :BC783D50:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18492 osp_idx=0 osp_ver=489542 osp_pg=0 (spawn #463881) 2025-08-07 08:04:39.344030 :BC783D51:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 08:04:39.344031 :BC783D52:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=38 time=3234548642 2025-08-07 08:04:39.344032 :BC783D53:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 08:04:39.344032 :BC783D54:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 08:04:39.344033 :BC783D55:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 08:04:39.344033 :BC783D56:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 08:04:39.344034 :BC783D57:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 08:04:39.344548 :BC783D58: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-08-07 08:04:39.344604 :BC783D5E: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-08-07 08:14:40.213594 :BC790BE5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 08:14:40.468428 :BC790C1D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 08:14:40.463 2025-08-07 08:14:40.468431 :BC790C1E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21116 pso_num=22 pso_serial#=126 2025-08-07 08:14:40.468571 :BC790C1F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21116 osp_idx=0 osp_ver=489543 osp_pg=0 (spawn #463905) 2025-08-07 08:14:40.468572 :BC790C20:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 08:14:40.468572 :BC790C21:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=39 time=3235149767 2025-08-07 08:14:40.468573 :BC790C22:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 08:14:40.468573 :BC790C23:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 08:14:40.468573 :BC790C24:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 08:14:40.468574 :BC790C25:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 08:14:40.468574 :BC790C26:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 08:14:40.469080 :BC790C27: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-08-07 08:14:40.469124 :BC790C2E: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-08-07 08:15:10.517317 :BC79162C: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-08-07 08:15:10.517350 :BC791631: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-08-07 08:15:10.517352 :BC791632:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=33, exc=33, tot=33 2025-08-07 08:15:40.566273 :BC791FDB:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=14 seq_num=15 snap_id=1 2025-08-07 08:15:40.566280 :BC791FE0:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=14 seq_num=15 snap_id=1 2025-08-07 08:15:40.566280 :BC791FE1:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=7, exc=7, tot=7 2025-08-07 08:15:40.566291 :BC791FE2: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-08-07 08:24:41.344341 :BC79D450:db_trace:ksl2.c@2324:kslwtbctx(): [10005:22:0] KSL WAIT BEG [latch free] 136431760/0x821c890 70/0x46 0/0x0 wait_id=0 seq_num=0 snap_id=0 2025-08-07 08:24:41.344355 :BC79D451:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:0] KSL WAIT END [latch free] 136431760/0x821c890 70/0x46 0/0x0 wait_id=0 seq_num=0 snap_id=0 2025-08-07 08:24:41.344356 :BC79D452:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:0] KSL WAIT END wait times (usecs) - snap=15, exc=15, tot=15 2025-08-07 08:24:41.344480 :BC79D457:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-07 08:24:41.661659 :BC79D48D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-07 08:24:41.657 2025-08-07 08:24:41.661661 :BC79D48E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21368 pso_num=22 pso_serial#=127 2025-08-07 08:24:41.661799 :BC79D48F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21368 osp_idx=0 osp_ver=489544 osp_pg=0 (spawn #463927) 2025-08-07 08:24:41.661800 :BC79D490:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-07 08:24:41.661800 :BC79D491:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=40 time=3235750970 2025-08-07 08:24:41.661800 :BC79D492:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-07 08:24:41.661801 :BC79D493:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-07 08:24:41.661801 :BC79D494:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-07 08:24:41.661801 :BC79D495:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-07 08:24:41.661802 :BC79D496:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-07 08:24:41.662282 :BC79D497: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-08-07 08:24:41.662328 :BC79D49E: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: 21368, W000)