Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510100018\orcl_w000_6488_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:37534M/63366M, Ph+PgF:44950M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 6488, image: ORACLE.EXE (W000) *** 2025-05-10 10:00:18.094 *** SESSION ID:(209.32963) 2025-05-10 10:00:18.094 *** 2025-05-10 10:00:18.094 Process diagnostic dump for ORACLE.EXE (W000), OS id=6488, pid: 26, proc_ser: 51, sid: 209, sess_ser: 32963 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=82 seq_num=83 snap_id=1 wait times: snap=3.212600 sec, exc=3.212600 sec, total=3.212600 sec wait times: max=5.000000 sec, heur=2 min 48 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.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=81 seq_num=82 snap_id=1 wait times: snap=5.010813 sec, exc=5.010813 sec, total=5.010813 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=80 seq_num=81 snap_id=1 wait times: snap=5.011427 sec, exc=5.011427 sec, total=5.011427 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=79 seq_num=80 snap_id=1 wait times: snap=5.014708 sec, exc=5.014708 sec, total=5.014708 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=78 seq_num=79 snap_id=1 wait times: snap=5.014729 sec, exc=5.014729 sec, total=5.014729 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.010142 sec, exc=5.010142 sec, total=5.010142 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=76 seq_num=77 snap_id=1 wait times: snap=5.014732 sec, exc=5.014732 sec, total=5.014732 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=75 seq_num=76 snap_id=1 wait times: snap=5.014720 sec, exc=5.014720 sec, total=5.014720 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=74 seq_num=75 snap_id=1 wait times: snap=5.004211 sec, exc=5.004211 sec, total=5.004211 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=73 seq_num=74 snap_id=1 wait times: snap=5.007596 sec, exc=5.007596 sec, total=5.007596 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=72 seq_num=73 snap_id=1 wait times: snap=5.014740 sec, exc=5.014740 sec, total=5.014740 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 209 serial 32963 --------------------------------------------------- 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, 09:58:18 - 10:00:18] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 10:00:18.094 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 6488, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 08:02:25.730711 :952226CE:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 08:02:25.730712 :952226CF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 08:02:25.730712 :952226D0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 08:02:25.731179 :952226D1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 08:02:55.804254 :9522308B:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:03:25.910249 :95223AB3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:03:25.906 2025-05-10 08:03:25.910251 :95223AB4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12756 pso_num=26 pso_serial#=37 2025-05-10 08:03:25.910387 :95223AB5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12756 osp_idx=24 osp_ver=244836 osp_pg=0 (spawn #167095) 2025-05-10 08:03:25.910387 :95223AB6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 08:03:25.910388 :95223AB7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=228 time=4134983078 2025-05-10 08:03:25.910388 :95223AB8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 08:03:25.910388 :95223AB9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 08:03:25.910389 :95223ABA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 08:03:25.910389 :95223ABB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 08:03:25.910391 :95223ABC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 08:03:25.910955 :95223ABD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 08:03:25.911001 :95223AC6:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:13:26.804991 :952304FB:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:13:26.917164 :95230509:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:13:26.914 2025-05-10 08:13:26.917166 :9523050A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11428 pso_num=26 pso_serial#=38 2025-05-10 08:13:26.917297 :9523050B:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=11428 (legacy spawn) 2025-05-10 08:13:26.923659 :9523050C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 08:13:26.923826 :95230515:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:13:26.924614 :95230516:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:13:26.933286 :95230519:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:13:26.930 2025-05-10 08:13:26.933289 :9523051A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12244 pso_num=26 pso_serial#=39 2025-05-10 08:13:26.933466 :9523051B:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=12244 (legacy spawn) 2025-05-10 08:13:26.939847 :9523051C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 08:13:26.939999 :95230525:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:13:26.940843 :95230526:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:13:27.247053 :95230593:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:13:27.242 2025-05-10 08:13:27.247055 :95230594:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13020 pso_num=26 pso_serial#=40 2025-05-10 08:13:27.247185 :95230595:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13020 osp_idx=24 osp_ver=244839 osp_pg=0 (spawn #167119) 2025-05-10 08:13:27.247186 :95230596:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 08:13:27.247186 :95230597:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=229 time=4135584406 2025-05-10 08:13:27.247187 :95230598:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 08:13:27.247187 :95230599:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 08:13:27.247188 :9523059A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 08:13:27.247188 :9523059B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 08:13:27.247188 :9523059C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 08:13:27.247683 :9523059D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 08:13:27.247724 :952305A4:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:23:28.201164 :9523CC9C:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:23:28.209058 :9523CC9F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:23:28.201 2025-05-10 08:23:28.209060 :9523CCA0:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10320 pso_num=26 pso_serial#=41 2025-05-10 08:23:28.209194 :9523CCA1:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=10320 (legacy spawn) 2025-05-10 08:23:28.215593 :9523CCA2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 08:23:28.215765 :9523CCAA:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:23:28.216579 :9523CCC0:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:23:28.690214 :9523CD42:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:23:28.685 2025-05-10 08:23:28.690216 :9523CD43:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2804 pso_num=26 pso_serial#=42 2025-05-10 08:23:28.690353 :9523CD44:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2804 osp_idx=24 osp_ver=244841 osp_pg=0 (spawn #167142) 2025-05-10 08:23:28.690354 :9523CD45:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 08:23:28.690354 :9523CD46:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=230 time=4136185859 2025-05-10 08:23:28.690355 :9523CD47:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 08:23:28.690355 :9523CD48:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 08:23:28.690355 :9523CD49:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 08:23:28.690356 :9523CD4A:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 08:23:28.690356 :9523CD4B:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 08:23:28.690850 :9523CD4C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 08:23:28.690907 :9523CD52:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:33:29.612955 :9524FE99:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:33:30.195702 :9524FF2D:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:33:30.190 2025-05-10 08:33:30.195704 :9524FF2E:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11560 pso_num=26 pso_serial#=43 2025-05-10 08:33:30.195841 :9524FF2F:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11560 osp_idx=24 osp_ver=244842 osp_pg=0 (spawn #167171) 2025-05-10 08:33:30.195841 :9524FF30:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 08:33:30.195842 :9524FF31:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=231 time=4136787359 2025-05-10 08:33:30.195842 :9524FF32:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 08:33:30.195842 :9524FF33:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 08:33:30.195842 :9524FF34:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 08:33:30.195843 :9524FF35:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 08:33:30.195843 :9524FF36:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 08:33:30.196363 :9524FF37:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 08:33:30.196407 :9524FF3E:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:43:31.040526 :9525C908:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:43:31.638978 :9525C972:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:43:31.634 2025-05-10 08:43:31.638980 :9525C973:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11480 pso_num=26 pso_serial#=44 2025-05-10 08:43:31.639123 :9525C974:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11480 osp_idx=24 osp_ver=244843 osp_pg=0 (spawn #167194) 2025-05-10 08:43:31.639123 :9525C975:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 08:43:31.639124 :9525C976:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=232 time=4137388812 2025-05-10 08:43:31.639124 :9525C977:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 08:43:31.639125 :9525C978:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 08:43:31.639125 :9525C979:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 08:43:31.639125 :9525C97A:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 08:43:31.639126 :9525C97B:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 08:43:31.639645 :9525C97C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 08:43:31.639690 :9525C985:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 08:53:32.548638 :95268EDF:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 08:53:33.068937 :95268F3B:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 08:53:33.064 2025-05-10 08:53:33.068940 :95268F3C:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2676 pso_num=26 pso_serial#=45 2025-05-10 08:53:33.069083 :95268F3D:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2676 osp_idx=24 osp_ver=244844 osp_pg=0 (spawn #167217) 2025-05-10 08:53:33.069084 :95268F3E:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 08:53:33.069084 :95268F3F:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=233 time=4137990234 2025-05-10 08:53:33.069085 :95268F40:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 08:53:33.069085 :95268F41:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 08:53:33.069085 :95268F42:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 08:53:33.069086 :95268F43:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 08:53:33.069086 :95268F44:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 08:53:33.069591 :95268F45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 08:53:33.069635 :95268F4C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:03:33.899804 :9527595A:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 09:03:34.393540 :952759C7:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 09:03:34.388 2025-05-10 09:03:34.393542 :952759C8:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10700 pso_num=26 pso_serial#=46 2025-05-10 09:03:34.393679 :952759C9:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10700 osp_idx=24 osp_ver=244845 osp_pg=0 (spawn #167243) 2025-05-10 09:03:34.393680 :952759CA:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 09:03:34.393680 :952759CB:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=234 time=4138591562 2025-05-10 09:03:34.393681 :952759CC:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 09:03:34.393681 :952759CD:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 09:03:34.393682 :952759CE:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 09:03:34.393682 :952759CF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 09:03:34.393683 :952759D0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 09:03:34.394185 :952759D1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 09:03:34.394235 :952759D8:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:13:35.286134 :952825FF:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 09:13:35.806489 :95282683:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 09:13:35.801 2025-05-10 09:13:35.806492 :95282684:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9672 pso_num=26 pso_serial#=47 2025-05-10 09:13:35.806629 :95282685:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9672 osp_idx=24 osp_ver=244846 osp_pg=0 (spawn #167266) 2025-05-10 09:13:35.806630 :95282686:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 09:13:35.806630 :95282687:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=235 time=4139192968 2025-05-10 09:13:35.806631 :95282688:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 09:13:35.806631 :95282689:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 09:13:35.806631 :9528268A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 09:13:35.806632 :9528268B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 09:13:35.806632 :9528268C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 09:13:35.807123 :9528268D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 09:13:35.807170 :95282694:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:23:36.699958 :9528EE98:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 09:23:37.152318 :9528EF05:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 09:23:37.147 2025-05-10 09:23:37.152320 :9528EF06:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13292 pso_num=26 pso_serial#=48 2025-05-10 09:23:37.152460 :9528EF07:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13292 osp_idx=24 osp_ver=244847 osp_pg=0 (spawn #167289) 2025-05-10 09:23:37.152461 :9528EF08:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 09:23:37.152461 :9528EF09:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=236 time=4139794312 2025-05-10 09:23:37.152461 :9528EF0A:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 09:23:37.152462 :9528EF0B:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 09:23:37.152462 :9528EF0C:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 09:23:37.152463 :9528EF0D:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 09:23:37.152463 :9528EF0E:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 09:23:37.152976 :9528EF0F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 09:23:37.153026 :9528EF16:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:33:38.056118 :9529B3F9:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 09:33:38.592122 :9529B469:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 09:33:38.587 2025-05-10 09:33:38.592124 :9529B46A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=6652 pso_num=26 pso_serial#=49 2025-05-10 09:33:38.592263 :9529B46B:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=6652 osp_idx=24 osp_ver=244848 osp_pg=0 (spawn #167313) 2025-05-10 09:33:38.592263 :9529B46C:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 09:33:38.592264 :9529B46D:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=237 time=4140395765 2025-05-10 09:33:38.592264 :9529B46E:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 09:33:38.592264 :9529B46F:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 09:33:38.592265 :9529B470:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 09:33:38.592265 :9529B471:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 09:33:38.592265 :9529B472:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 09:33:38.592762 :9529B473:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 09:33:38.592812 :9529B479:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:43:39.488061 :952A785F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 09:43:39.836528 :952A78BF:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 09:43:39.831 2025-05-10 09:43:39.836530 :952A78C0:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2752 pso_num=26 pso_serial#=50 2025-05-10 09:43:39.836705 :952A78C1:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2752 osp_idx=24 osp_ver=244849 osp_pg=0 (spawn #167336) 2025-05-10 09:43:39.836706 :952A78C2:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 09:43:39.836706 :952A78C3:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=238 time=4140997000 2025-05-10 09:43:39.836707 :952A78C4:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 09:43:39.836707 :952A78C5:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 09:43:39.836708 :952A78C6:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 09:43:39.836708 :952A78C7:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 09:43:39.836709 :952A78C8:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 09:43:39.837240 :952A78C9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 09:43:39.837288 :952A78D2:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:43:54.842802 :952A7DBA:db_trace:ksl2.c@2477:kslwtbctx(): [10005:26:209] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-05-10 09:43:54.842806 :952A7DBB:db_trace:ksl2.c@2611:kslwtectx(): [10005:26:209] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-05-10 09:43:54.842806 :952A7DBC:db_trace:ksl2.c@2619:kslwtectx(): [10005:26:209] KSL WAIT END wait times (usecs) - snap=4, exc=4, tot=4 2025-05-10 09:43:54.842813 :952A7DC1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:53:40.718683 :952B3D99:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 09:53:41.113937 :952B3E26:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 09:53:41.109 2025-05-10 09:53:41.113939 :952B3E27:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=6488 pso_num=26 pso_serial#=51 2025-05-10 09:53:41.114069 :952B3E28:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=6488 osp_idx=24 osp_ver=244850 osp_pg=0 (spawn #167359) 2025-05-10 09:53:41.114069 :952B3E29:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 09:53:41.114070 :952B3E2A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=239 time=4141598281 2025-05-10 09:53:41.114070 :952B3E2B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 09:53:41.114070 :952B3E2C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 09:53:41.114071 :952B3E2D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 09:53:41.114071 :952B3E2E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 09:53:41.114071 :952B3E2F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 09:53:41.114579 :952B3E30:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 09:53:41.114631 :952B3E3A:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:55:04.389184 :952B5969:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 09:57:29.574500 :952B8870:db_trace:ksl2.c@2477:kslwtbctx(): [10005:26:209] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=48 seq_num=49 snap_id=1 2025-05-10 09:57:29.574524 :952B8884:db_trace:ksl2.c@2611:kslwtectx(): [10005:26:209] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=48 seq_num=49 snap_id=1 2025-05-10 09:57:29.574525 :952B8885:db_trace:ksl2.c@2619:kslwtectx(): [10005:26:209] KSL WAIT END wait times (usecs) - snap=24, exc=24, tot=24 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 6488, W000)