Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250730082413\orcl_w000_14064_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:35904M/63366M, Ph+PgF:41587M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 14064, image: ORACLE.EXE (W000) *** 2025-07-30 08:24:13.550 *** SESSION ID:(201.31475) 2025-07-30 08:24:13.550 *** 2025-07-30 08:24:13.550 Process diagnostic dump for ORACLE.EXE (W000), OS id=14064, pid: 25, proc_ser: 92, sid: 201, sess_ser: 31475 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=1.664972 sec, exc=1.664972 sec, total=1.664972 sec wait times: max=5.000000 sec, heur=2 min 31 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.000023 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.000398 sec, exc=5.000398 sec, total=5.000398 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.005594 sec, exc=5.005594 sec, total=5.005594 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=5.014588 sec, exc=5.014588 sec, total=5.014588 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=5.014719 sec, exc=5.014719 sec, total=5.014719 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.004620 sec, exc=5.004620 sec, total=5.004620 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=25 seq_num=26 snap_id=1 wait times: snap=5.014745 sec, exc=5.014745 sec, total=5.014745 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=5.015250 sec, exc=5.015250 sec, total=5.015250 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.003216 sec, exc=5.003216 sec, total=5.003216 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.009657 sec, exc=5.009657 sec, total=5.009657 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.002890 sec, exc=5.002890 sec, total=5.002890 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time Sampled Session History of session 201 serial 31475 --------------------------------------------------- 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:22:13 - 08:24:13] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-30 08:24:13.550 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 14064, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-30 06:01:24.612343 :B8DC822C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 06:01:25.054526 :B8DC825D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 06:01:25.050 2025-07-30 06:01:25.054528 :B8DC825E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20208 pso_num=25 pso_serial#=79 2025-07-30 06:01:25.054665 :B8DC825F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20208 osp_idx=23 osp_ver=221786 osp_pg=0 (spawn #436940) 2025-07-30 06:01:25.054666 :B8DC8260:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 06:01:25.054667 :B8DC8261:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=108 time=2536060954 2025-07-30 06:01:25.054667 :B8DC8262:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 06:01:25.054667 :B8DC8263:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 06:01:25.054668 :B8DC8264:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 06:01:25.054668 :B8DC8265:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 06:01:25.054668 :B8DC8266:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 06:01:25.055169 :B8DC8267: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-07-30 06:01:25.055226 :B8DC826E: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-07-30 06:11:25.842285 :B8DD57E1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 06:11:26.253441 :B8DD5824:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 06:11:26.248 2025-07-30 06:11:26.253443 :B8DD5825:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18812 pso_num=25 pso_serial#=80 2025-07-30 06:11:26.253587 :B8DD5826:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18812 osp_idx=23 osp_ver=221787 osp_pg=0 (spawn #436964) 2025-07-30 06:11:26.253588 :B8DD5827:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 06:11:26.253588 :B8DD5828:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=109 time=2536662142 2025-07-30 06:11:26.253589 :B8DD5829:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 06:11:26.253589 :B8DD582A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 06:11:26.253589 :B8DD582B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 06:11:26.253590 :B8DD582C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 06:11:26.253590 :B8DD582D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 06:11:26.254089 :B8DD582E: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-07-30 06:11:26.254153 :B8DD5835: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-07-30 06:21:27.071324 :B8DE23F1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 06:21:27.482333 :B8DE2422:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 06:21:27.478 2025-07-30 06:21:27.482335 :B8DE2423:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8216 pso_num=25 pso_serial#=81 2025-07-30 06:21:27.482472 :B8DE2424:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8216 osp_idx=23 osp_ver=221788 osp_pg=0 (spawn #436987) 2025-07-30 06:21:27.482473 :B8DE2425:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 06:21:27.482473 :B8DE2426:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=110 time=2537263376 2025-07-30 06:21:27.482474 :B8DE2427:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 06:21:27.482474 :B8DE2428:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 06:21:27.482475 :B8DE2429:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 06:21:27.482475 :B8DE242A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 06:21:27.482475 :B8DE242B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 06:21:27.482979 :B8DE242C: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-07-30 06:21:27.483039 :B8DE2436: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-07-30 06:31:28.340432 :B8DEF0DF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 06:31:28.751557 :B8DEF10E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 06:31:28.746 2025-07-30 06:31:28.751560 :B8DEF10F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19412 pso_num=25 pso_serial#=82 2025-07-30 06:31:28.751700 :B8DEF110:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19412 osp_idx=23 osp_ver=221789 osp_pg=0 (spawn #437009) 2025-07-30 06:31:28.751701 :B8DEF111:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 06:31:28.751701 :B8DEF112:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=111 time=2537864642 2025-07-30 06:31:28.751701 :B8DEF113:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 06:31:28.751702 :B8DEF114:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 06:31:28.751702 :B8DEF115:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 06:31:28.751702 :B8DEF116:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 06:31:28.751703 :B8DEF117:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 06:31:28.752194 :B8DEF118: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-07-30 06:31:28.752243 :B8DEF11F: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-07-30 06:41:29.481811 :B8DFBCFB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 06:41:30.033314 :B8DFBD35:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 06:41:30.028 2025-07-30 06:41:30.033316 :B8DFBD36:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20040 pso_num=25 pso_serial#=83 2025-07-30 06:41:30.033454 :B8DFBD37:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20040 osp_idx=23 osp_ver=221790 osp_pg=0 (spawn #437032) 2025-07-30 06:41:30.033454 :B8DFBD38:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 06:41:30.033454 :B8DFBD39:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=112 time=2538465923 2025-07-30 06:41:30.033455 :B8DFBD3A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 06:41:30.033455 :B8DFBD3B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 06:41:30.033455 :B8DFBD3C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 06:41:30.033456 :B8DFBD3D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 06:41:30.033456 :B8DFBD3E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 06:41:30.033951 :B8DFBD3F: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-07-30 06:41:30.034010 :B8DFBD45: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-07-30 06:51:30.828095 :B8E08A4F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 06:51:31.239203 :B8E08A80:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 06:51:31.234 2025-07-30 06:51:31.239205 :B8E08A81:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9904 pso_num=25 pso_serial#=84 2025-07-30 06:51:31.239342 :B8E08A82:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9904 osp_idx=23 osp_ver=221791 osp_pg=0 (spawn #437055) 2025-07-30 06:51:31.239342 :B8E08A83:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 06:51:31.239343 :B8E08A84:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=113 time=2539067126 2025-07-30 06:51:31.239343 :B8E08A85:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 06:51:31.239344 :B8E08A86:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 06:51:31.239344 :B8E08A87:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 06:51:31.239344 :B8E08A88:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 06:51:31.239345 :B8E08A89:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 06:51:31.239839 :B8E08A8A: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-07-30 06:51:31.239886 :B8E08A90: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-07-30 07:01:32.012824 :B8E157A6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 07:01:32.361556 :B8E157D5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 07:01:32.360 2025-07-30 07:01:32.361558 :B8E157D6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7572 pso_num=25 pso_serial#=85 2025-07-30 07:01:32.361707 :B8E157D7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7572 osp_idx=23 osp_ver=221792 osp_pg=0 (spawn #437079) 2025-07-30 07:01:32.361708 :B8E157D8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 07:01:32.361708 :B8E157D9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=114 time=2539668251 2025-07-30 07:01:32.361708 :B8E157DA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 07:01:32.361709 :B8E157DB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 07:01:32.361709 :B8E157DC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 07:01:32.361709 :B8E157DD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 07:01:32.361710 :B8E157DE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 07:01:32.362246 :B8E157DF: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-07-30 07:01:32.362298 :B8E157E8: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-07-30 07:11:33.124493 :B8E22D89:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 07:11:33.551053 :B8E22DC2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 07:11:33.546 2025-07-30 07:11:33.551055 :B8E22DC3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18728 pso_num=25 pso_serial#=86 2025-07-30 07:11:33.551196 :B8E22DC4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18728 osp_idx=23 osp_ver=221793 osp_pg=0 (spawn #437103) 2025-07-30 07:11:33.551196 :B8E22DC5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 07:11:33.551197 :B8E22DC6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=115 time=2540269439 2025-07-30 07:11:33.551197 :B8E22DC7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 07:11:33.551198 :B8E22DC8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 07:11:33.551198 :B8E22DC9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 07:11:33.551199 :B8E22DCA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 07:11:33.551199 :B8E22DCB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 07:11:33.551689 :B8E22DCC: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-07-30 07:11:33.551734 :B8E22DD4: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-07-30 07:21:34.344277 :B8E2FADB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 07:21:34.677268 :B8E2FB09:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 07:21:34.672 2025-07-30 07:21:34.677270 :B8E2FB0A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13880 pso_num=25 pso_serial#=87 2025-07-30 07:21:34.677415 :B8E2FB0B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13880 osp_idx=23 osp_ver=221794 osp_pg=0 (spawn #437126) 2025-07-30 07:21:34.677416 :B8E2FB0C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 07:21:34.677417 :B8E2FB0D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=116 time=2540870564 2025-07-30 07:21:34.677417 :B8E2FB0E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 07:21:34.677417 :B8E2FB0F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 07:21:34.677418 :B8E2FB10:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 07:21:34.677418 :B8E2FB11:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 07:21:34.677418 :B8E2FB12:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 07:21:34.677926 :B8E2FB13: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-07-30 07:21:34.677970 :B8E2FB1B: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-07-30 07:31:35.532104 :B8E3C6E4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 07:31:35.880544 :B8E3C71C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 07:31:35.875 2025-07-30 07:31:35.880546 :B8E3C71D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13152 pso_num=25 pso_serial#=88 2025-07-30 07:31:35.880680 :B8E3C71E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13152 osp_idx=23 osp_ver=221795 osp_pg=0 (spawn #437148) 2025-07-30 07:31:35.880681 :B8E3C71F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 07:31:35.880681 :B8E3C720:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=117 time=2541471767 2025-07-30 07:31:35.880682 :B8E3C721:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 07:31:35.880682 :B8E3C722:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 07:31:35.880683 :B8E3C723:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 07:31:35.880683 :B8E3C724:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 07:31:35.880683 :B8E3C725:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 07:31:35.881161 :B8E3C726: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-07-30 07:31:35.881213 :B8E3C730: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-07-30 07:41:36.696205 :B8E49434:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 07:41:37.013492 :B8E49463:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 07:41:37.008 2025-07-30 07:41:37.013494 :B8E49464:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9288 pso_num=25 pso_serial#=89 2025-07-30 07:41:37.013631 :B8E49465:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9288 osp_idx=23 osp_ver=221796 osp_pg=0 (spawn #437171) 2025-07-30 07:41:37.013632 :B8E49466:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 07:41:37.013632 :B8E49467:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=118 time=2542072908 2025-07-30 07:41:37.013633 :B8E49468:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 07:41:37.013633 :B8E49469:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 07:41:37.013633 :B8E4946A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 07:41:37.013634 :B8E4946B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 07:41:37.013634 :B8E4946C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 07:41:37.014131 :B8E4946D: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-07-30 07:41:37.014177 :B8E49475: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-07-30 07:48:23.625761 :B8E51DCD: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-07-30 07:51:38.211781 :B8E5604F: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-07-30 07:51:38.211822 :B8E56050:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-07-30 07:51:38.211873 :B8E56054:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-07-30 07:51:38.211874 :B8E56056:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=51, exc=51, tot=51 2025-07-30 08:01:39.164499 :B8E62EB5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 08:01:39.403345 :B8E62EE2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 08:01:39.398 2025-07-30 08:01:39.403347 :B8E62EE3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20288 pso_num=25 pso_serial#=90 2025-07-30 08:01:39.403540 :B8E62EE4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20288 osp_idx=23 osp_ver=221797 osp_pg=0 (spawn #437218) 2025-07-30 08:01:39.403541 :B8E62EE5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 08:01:39.403541 :B8E62EE6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=119 time=2543275298 2025-07-30 08:01:39.403542 :B8E62EE7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 08:01:39.403542 :B8E62EE8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 08:01:39.403542 :B8E62EE9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 08:01:39.403543 :B8E62EEA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 08:01:39.403543 :B8E62EEB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 08:01:39.404045 :B8E62EEC: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-07-30 08:01:39.404089 :B8E62EF5: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-07-30 08:11:40.150470 :B8E7013E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 08:11:40.420920 :B8E70179:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 08:11:40.416 2025-07-30 08:11:40.420922 :B8E7017A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17380 pso_num=25 pso_serial#=91 2025-07-30 08:11:40.421064 :B8E7017B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17380 osp_idx=23 osp_ver=221798 osp_pg=0 (spawn #437242) 2025-07-30 08:11:40.421065 :B8E7017C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 08:11:40.421065 :B8E7017D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=120 time=2543876314 2025-07-30 08:11:40.421066 :B8E7017E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 08:11:40.421066 :B8E7017F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 08:11:40.421067 :B8E70180:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 08:11:40.421067 :B8E70181:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 08:11:40.421067 :B8E70182:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 08:11:40.421575 :B8E70183: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-07-30 08:11:40.421629 :B8E7018A: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-07-30 08:21:41.133074 :B8E7CFE2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 08:21:41.625973 :B8E7D01E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 08:21:41.621 2025-07-30 08:21:41.625975 :B8E7D01F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14064 pso_num=25 pso_serial#=92 2025-07-30 08:21:41.626111 :B8E7D020:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14064 osp_idx=23 osp_ver=221799 osp_pg=0 (spawn #437265) 2025-07-30 08:21:41.626112 :B8E7D021:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-30 08:21:41.626112 :B8E7D022:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=121 time=2544477517 2025-07-30 08:21:41.626113 :B8E7D023:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 08:21:41.626113 :B8E7D024:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 08:21:41.626114 :B8E7D025:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 08:21:41.626114 :B8E7D026:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 08:21:41.626114 :B8E7D027:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 08:21:41.626601 :B8E7D028: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-07-30 08:21:41.626646 :B8E7D02F: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: 14064, W000)