Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250530220008\orcl_w000_13408_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:37221M/63366M, Ph+PgF:44093M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 13408, image: ORACLE.EXE (W000) *** 2025-05-30 22:00:08.802 *** SESSION ID:(201.17941) 2025-05-30 22:00:08.802 *** 2025-05-30 22:00:08.802 Process diagnostic dump for ORACLE.EXE (W000), OS id=13408, pid: 25, proc_ser: 17, sid: 201, sess_ser: 17941 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.690022 sec, exc=0.690022 sec, total=0.690022 sec wait times: max=5.000000 sec, heur=25.739353 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.000028 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=5.013415 sec, exc=5.013415 sec, total=5.013415 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=5.010970 sec, exc=5.010970 sec, total=5.010970 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=5.004621 sec, exc=5.004621 sec, total=5.004621 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=2 seq_num=3 snap_id=1 wait times: snap=5.014728 sec, exc=5.014728 sec, total=5.014728 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=5.005484 sec, exc=5.005484 sec, total=5.005484 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.004096 sec of elapsed time 5: waited for 'class slave wait' slave id=0x121ee8b0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.000042 sec, exc=0.000042 sec, total=0.000042 sec wait times: max=infinite wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 201 serial 17941 --------------------------------------------------- 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 --------------------------------------------------- [26 samples, 21:59:43 - 22:00:08] idle wait at each sample [session created at: 21:59:43] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-30 22:00:08.802 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 13408, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-30 19:29:24.565802 :9E202127:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 19:29:24.565803 :9E202128:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 19:29:24.565804 :9E202129:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 19:29:24.565804 :9E20212A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 19:29:24.566302 :9E20212B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 19:29:24.566348 :9E202133:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 19:39:25.479713 :9E20E65B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 19:39:25.921947 :9E20E6AC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 19:39:25.917 2025-05-30 19:39:25.921950 :9E20E6AD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13364 pso_num=25 pso_serial#=4 2025-05-30 19:39:25.922091 :9E20E6AE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13364 osp_idx=23 osp_ver=126341 osp_pg=0 (spawn #235482) 2025-05-30 19:39:25.922092 :9E20E6AF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 19:39:25.922092 :9E20E6B0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=221 time=1609726688 2025-05-30 19:39:25.922093 :9E20E6B1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 19:39:25.922093 :9E20E6B2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 19:39:25.922093 :9E20E6B3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 19:39:25.922093 :9E20E6B4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 19:39:25.922094 :9E20E6B5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 19:39:25.922596 :9E20E6B6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 19:39:25.922639 :9E20E6BF:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 19:49:26.929073 :9E21AC11:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 19:49:27.262117 :9E21AC59:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 19:49:27.257 2025-05-30 19:49:27.262119 :9E21AC5A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7880 pso_num=25 pso_serial#=5 2025-05-30 19:49:27.262257 :9E21AC5B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7880 osp_idx=23 osp_ver=126342 osp_pg=0 (spawn #235505) 2025-05-30 19:49:27.262258 :9E21AC5C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 19:49:27.262258 :9E21AC5D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=222 time=1610328032 2025-05-30 19:49:27.262261 :9E21AC5E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 19:49:27.262261 :9E21AC5F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 19:49:27.262261 :9E21AC60:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 19:49:27.262262 :9E21AC61:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 19:49:27.262262 :9E21AC62:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 19:49:27.262776 :9E21AC63:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 19:49:27.262830 :9E21AC6A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 19:59:27.714713 :9E227442:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-05-30 20:09:28.645199 :9E234712:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 20:09:29.071837 :9E234750:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 20:09:29.066 2025-05-30 20:09:29.071839 :9E234751:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14224 pso_num=25 pso_serial#=6 2025-05-30 20:09:29.071972 :9E234752:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14224 osp_idx=23 osp_ver=126343 osp_pg=0 (spawn #235552) 2025-05-30 20:09:29.071972 :9E234753:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 20:09:29.071973 :9E234754:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=223 time=1611527719 2025-05-30 20:09:29.071973 :9E234755:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 20:09:29.071973 :9E234756:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 20:09:29.071974 :9E234757:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 20:09:29.071974 :9E234758:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 20:09:29.071974 :9E234759:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 20:09:29.072499 :9E23475A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 20:09:29.072543 :9E234761:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 20:19:29.926437 :9E240D99:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 20:19:30.290500 :9E240DDC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 20:19:30.285 2025-05-30 20:19:30.290502 :9E240DDD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13120 pso_num=25 pso_serial#=7 2025-05-30 20:19:30.290636 :9E240DDE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13120 osp_idx=23 osp_ver=126344 osp_pg=0 (spawn #235575) 2025-05-30 20:19:30.290636 :9E240DDF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 20:19:30.290637 :9E240DE0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=224 time=1612128938 2025-05-30 20:19:30.290637 :9E240DE1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 20:19:30.290638 :9E240DE2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 20:19:30.290638 :9E240DE3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 20:19:30.290638 :9E240DE4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 20:19:30.290639 :9E240DE5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 20:19:30.291122 :9E240DE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 20:19:30.291171 :9E240DED:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 20:29:31.209056 :9E24D359:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 20:29:31.523994 :9E24D35C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 20:29:31.515 2025-05-30 20:29:31.523996 :9E24D35D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13968 pso_num=25 pso_serial#=8 2025-05-30 20:29:31.524128 :9E24D35E:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13968 (legacy spawn) 2025-05-30 20:29:31.530646 :9E24D35F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-30 20:29:31.530824 :9E24D364:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 20:29:31.531658 :9E24D369:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 20:29:31.583084 :9E24D39E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 20:29:31.578 2025-05-30 20:29:31.583086 :9E24D39F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9804 pso_num=25 pso_serial#=9 2025-05-30 20:29:31.583226 :9E24D3A0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9804 osp_idx=23 osp_ver=126346 osp_pg=0 (spawn #235597) 2025-05-30 20:29:31.583227 :9E24D3A1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 20:29:31.583228 :9E24D3A2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=225 time=1612730235 2025-05-30 20:29:31.583228 :9E24D3A3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 20:29:31.583229 :9E24D3A4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 20:29:31.583229 :9E24D3A5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 20:29:31.583229 :9E24D3A6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 20:29:31.583230 :9E24D3A7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 20:29:31.583750 :9E24D3A8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 20:29:31.583793 :9E24D3B0:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 20:39:32.479131 :9E259827:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 20:39:32.874390 :9E25986D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 20:39:32.869 2025-05-30 20:39:32.874392 :9E25986E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14096 pso_num=25 pso_serial#=10 2025-05-30 20:39:32.874538 :9E25986F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14096 osp_idx=23 osp_ver=126347 osp_pg=0 (spawn #235620) 2025-05-30 20:39:32.874539 :9E259870:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 20:39:32.874539 :9E259871:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=226 time=1613331516 2025-05-30 20:39:32.874540 :9E259872:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 20:39:32.874540 :9E259873:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 20:39:32.874540 :9E259874:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 20:39:32.874541 :9E259875:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 20:39:32.874541 :9E259876:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 20:39:32.875036 :9E259877:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 20:39:32.875081 :9E25987F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 20:45:43.969968 :9E261234:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 20:49:34.061420 :9E265CCF:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-05-30 20:59:34.904517 :9E2721D1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 20:59:35.341022 :9E27221F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 20:59:35.336 2025-05-30 20:59:35.341024 :9E272220:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13524 pso_num=25 pso_serial#=11 2025-05-30 20:59:35.341219 :9E272221:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13524 osp_idx=23 osp_ver=126348 osp_pg=0 (spawn #235664) 2025-05-30 20:59:35.341220 :9E272222:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 20:59:35.341220 :9E272223:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=227 time=1614533985 2025-05-30 20:59:35.341221 :9E272224:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 20:59:35.341221 :9E272225:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 20:59:35.341221 :9E272226:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 20:59:35.341222 :9E272227:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 20:59:35.341222 :9E272228:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 20:59:35.341721 :9E272229:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 20:59:35.341768 :9E272231:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 21:09:36.332082 :9E27EEF9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 21:09:36.664769 :9E27EF2E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 21:09:36.660 2025-05-30 21:09:36.664771 :9E27EF2F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11936 pso_num=25 pso_serial#=12 2025-05-30 21:09:36.664967 :9E27EF30:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11936 osp_idx=23 osp_ver=126349 osp_pg=0 (spawn #235690) 2025-05-30 21:09:36.664967 :9E27EF31:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 21:09:36.664968 :9E27EF32:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=228 time=1615135313 2025-05-30 21:09:36.664969 :9E27EF33:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 21:09:36.664969 :9E27EF34:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 21:09:36.664970 :9E27EF35:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 21:09:36.664970 :9E27EF36:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 21:09:36.664972 :9E27EF37:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 21:09:36.665471 :9E27EF38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 21:09:36.665529 :9E27EF3E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 21:19:37.657765 :9E28B705:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 21:19:37.881205 :9E28B747:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 21:19:37.877 2025-05-30 21:19:37.881207 :9E28B748:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14996 pso_num=25 pso_serial#=13 2025-05-30 21:19:37.881342 :9E28B749:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14996 osp_idx=23 osp_ver=126350 osp_pg=0 (spawn #235713) 2025-05-30 21:19:37.881343 :9E28B74A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 21:19:37.881343 :9E28B74B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=229 time=1615736532 2025-05-30 21:19:37.881344 :9E28B74C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 21:19:37.881344 :9E28B74D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 21:19:37.881345 :9E28B74E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 21:19:37.881345 :9E28B74F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 21:19:37.881345 :9E28B750:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 21:19:37.881842 :9E28B751:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 21:19:37.881886 :9E28B759:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 21:29:38.851386 :9E297BFA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 21:29:39.152864 :9E297C2E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 21:29:39.147 2025-05-30 21:29:39.152866 :9E297C2F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14568 pso_num=25 pso_serial#=14 2025-05-30 21:29:39.153001 :9E297C30:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14568 osp_idx=23 osp_ver=126351 osp_pg=0 (spawn #235735) 2025-05-30 21:29:39.153002 :9E297C31:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 21:29:39.153002 :9E297C32:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=230 time=1616337797 2025-05-30 21:29:39.153003 :9E297C33:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 21:29:39.153003 :9E297C34:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 21:29:39.153004 :9E297C35:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 21:29:39.153004 :9E297C36:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 21:29:39.153004 :9E297C37:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 21:29:39.153486 :9E297C38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 21:29:39.153538 :9E297C3F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 21:30:09.197989 :9E2985E0:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-30 21:30:09.198068 :9E2985E5:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-30 21:30:09.198070 :9E2985E6:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=77, exc=77, tot=77 2025-05-30 21:39:40.116328 :9E2A41B1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 21:39:40.419026 :9E2A4207:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 21:39:40.414 2025-05-30 21:39:40.419027 :9E2A4208:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15300 pso_num=25 pso_serial#=15 2025-05-30 21:39:40.419165 :9E2A4209:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15300 osp_idx=23 osp_ver=126352 osp_pg=0 (spawn #235758) 2025-05-30 21:39:40.419165 :9E2A420A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 21:39:40.419166 :9E2A420B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=231 time=1616939063 2025-05-30 21:39:40.419166 :9E2A420C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 21:39:40.419166 :9E2A420D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 21:39:40.419167 :9E2A420E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 21:39:40.419167 :9E2A420F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 21:39:40.419168 :9E2A4210:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 21:39:40.419649 :9E2A4211:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 21:39:40.419691 :9E2A4219:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 21:49:41.245837 :9E2B06AE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 21:49:41.766151 :9E2B06EF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 21:49:41.761 2025-05-30 21:49:41.766153 :9E2B06F0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10832 pso_num=25 pso_serial#=16 2025-05-30 21:49:41.766287 :9E2B06F1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10832 osp_idx=23 osp_ver=126353 osp_pg=0 (spawn #235781) 2025-05-30 21:49:41.766288 :9E2B06F2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 21:49:41.766288 :9E2B06F3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=232 time=1617540407 2025-05-30 21:49:41.766288 :9E2B06F4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 21:49:41.766289 :9E2B06F5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 21:49:41.766289 :9E2B06F6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 21:49:41.766290 :9E2B06F7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 21:49:41.766290 :9E2B06F8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 21:49:41.766778 :9E2B06F9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 21:49:41.766821 :9E2B0701:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-30 21:59:42.647635 :9E2BCC7E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-30 21:59:43.060598 :9E2BCCD2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-30 21:59:43.055 2025-05-30 21:59:43.060600 :9E2BCCD3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13408 pso_num=25 pso_serial#=17 2025-05-30 21:59:43.060735 :9E2BCCD4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13408 osp_idx=23 osp_ver=126354 osp_pg=0 (spawn #235803) 2025-05-30 21:59:43.060735 :9E2BCCD5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-30 21:59:43.060736 :9E2BCCD6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=233 time=1618141704 2025-05-30 21:59:43.060736 :9E2BCCD7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 21:59:43.060737 :9E2BCCD8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 21:59:43.060737 :9E2BCCD9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 21:59:43.060737 :9E2BCCDA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 21:59:43.060738 :9E2BCCDB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 21:59:43.061226 :9E2BCCDC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-30 21:59:43.061274 :9E2BCCE3:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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 25 (osid: 13408, W000)