Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250718220007\orcl_w000_16512_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:36186M/63366M, Ph+PgF:42084M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 16512, image: ORACLE.EXE (W000) *** 2025-07-18 22:00:07.565 *** SESSION ID:(177.15375) 2025-07-18 22:00:07.565 *** 2025-07-18 22:00:07.565 Process diagnostic dump for ORACLE.EXE (W000), OS id=16512, pid: 22, proc_ser: 23, sid: 177, sess_ser: 15375 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=0.897019 sec, exc=0.897019 sec, total=0.897019 sec wait times: max=5.000000 sec, heur=2 min 26 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.000026 sec since current wait 0: 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.014746 sec, exc=5.014746 sec, total=5.014746 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: 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.010136 sec, exc=5.010136 sec, total=5.010136 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: 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.014758 sec, exc=5.014758 sec, total=5.014758 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 3: 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.008303 sec, exc=5.008303 sec, total=5.008303 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 4: 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.000427 sec, exc=5.000427 sec, total=5.000427 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 5: 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.013790 sec, exc=5.013790 sec, total=5.013790 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=23 seq_num=24 snap_id=1 wait times: snap=5.004910 sec, exc=5.004910 sec, total=5.004910 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=22 seq_num=23 snap_id=1 wait times: snap=5.014712 sec, exc=5.014712 sec, total=5.014712 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 8: 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.004623 sec, exc=5.004623 sec, total=5.004623 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.004560 sec, exc=5.004560 sec, total=5.004560 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time Sampled Session History of session 177 serial 15375 --------------------------------------------------- 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, 21:58:07 - 22:00:07] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-18 22:00:07.565 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 16512, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-18 19:27:21.525597 :B3C843B5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 19:27:21.525597 :B3C843B6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 19:27:21.526084 :B3C843B7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 19:27:21.526133 :B3C843BE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 19:37:22.435091 :B3C90E28:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 19:37:22.815181 :B3C90E77:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 19:37:22.811 2025-07-18 19:37:22.815182 :B3C90E78:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14912 pso_num=22 pso_serial#=10 2025-07-18 19:37:22.815318 :B3C90E79:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14912 osp_idx=0 osp_ver=419812 osp_pg=0 (spawn #398828) 2025-07-18 19:37:22.815318 :B3C90E7A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 19:37:22.815319 :B3C90E7B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=124 time=1548218704 2025-07-18 19:37:22.815319 :B3C90E7C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 19:37:22.815319 :B3C90E7D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 19:37:22.815320 :B3C90E7E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 19:37:22.815320 :B3C90E7F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 19:37:22.815320 :B3C90E80:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 19:37:22.815812 :B3C90E81:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 19:37:22.815855 :B3C90E88:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 19:47:23.764711 :B3C9D8D5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 19:47:24.144439 :B3C9D918:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 19:47:24.139 2025-07-18 19:47:24.144441 :B3C9D919:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18704 pso_num=22 pso_serial#=11 2025-07-18 19:47:24.144581 :B3C9D91A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18704 osp_idx=0 osp_ver=419813 osp_pg=0 (spawn #398852) 2025-07-18 19:47:24.144582 :B3C9D91B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 19:47:24.144583 :B3C9D91C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=125 time=1548820033 2025-07-18 19:47:24.144583 :B3C9D91D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 19:47:24.144583 :B3C9D91E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 19:47:24.144584 :B3C9D91F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 19:47:24.144584 :B3C9D920:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 19:47:24.144584 :B3C9D921:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 19:47:24.145077 :B3C9D922:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 19:47:24.145118 :B3C9D92B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 19:57:25.116530 :B3CAA286:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 19:57:25.433763 :B3CAA2C9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 19:57:25.429 2025-07-18 19:57:25.433766 :B3CAA2CA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18336 pso_num=22 pso_serial#=12 2025-07-18 19:57:25.433908 :B3CAA2CB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18336 osp_idx=0 osp_ver=419814 osp_pg=0 (spawn #398874) 2025-07-18 19:57:25.433909 :B3CAA2CC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 19:57:25.433909 :B3CAA2CD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=126 time=1549421329 2025-07-18 19:57:25.433910 :B3CAA2CE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 19:57:25.433910 :B3CAA2CF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 19:57:25.433911 :B3CAA2D0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 19:57:25.433911 :B3CAA2D1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 19:57:25.433911 :B3CAA2D2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 19:57:25.434415 :B3CAA2D3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 19:57:25.434465 :B3CAA2D9:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 20:07:26.303066 :B3CB7918:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 20:07:26.770905 :B3CB7979:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 20:07:26.766 2025-07-18 20:07:26.770908 :B3CB797A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19392 pso_num=22 pso_serial#=13 2025-07-18 20:07:26.771101 :B3CB797B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19392 osp_idx=0 osp_ver=419815 osp_pg=0 (spawn #398900) 2025-07-18 20:07:26.771102 :B3CB797C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 20:07:26.771102 :B3CB797D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=127 time=1550022673 2025-07-18 20:07:26.771103 :B3CB797E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 20:07:26.771103 :B3CB797F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 20:07:26.771103 :B3CB7980:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 20:07:26.771104 :B3CB7981:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 20:07:26.771104 :B3CB7982:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 20:07:26.771613 :B3CB7983:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 20:07:26.771660 :B3CB798B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 20:17:27.534443 :B3CC4436:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 20:17:28.106818 :B3CC4497:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 20:17:28.102 2025-07-18 20:17:28.106820 :B3CC4498:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18848 pso_num=22 pso_serial#=14 2025-07-18 20:17:28.106993 :B3CC4499:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18848 osp_idx=0 osp_ver=419816 osp_pg=0 (spawn #398923) 2025-07-18 20:17:28.106994 :B3CC449A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 20:17:28.106994 :B3CC449B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=128 time=1550624001 2025-07-18 20:17:28.106995 :B3CC449C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 20:17:28.106995 :B3CC449D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 20:17:28.106996 :B3CC449E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 20:17:28.106996 :B3CC449F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 20:17:28.106997 :B3CC44A0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 20:17:28.107505 :B3CC44A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 20:17:28.107553 :B3CC44A8:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 20:27:01.360511 :B3CD05EC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-18 20:27:29.427265 :B3CD104A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-18 20:37:30.336293 :B3CDDBBD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 20:37:30.872242 :B3CDDBE4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 20:37:30.867 2025-07-18 20:37:30.872244 :B3CDDBE5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2860 pso_num=22 pso_serial#=15 2025-07-18 20:37:30.872381 :B3CDDBE6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2860 osp_idx=0 osp_ver=419817 osp_pg=0 (spawn #398967) 2025-07-18 20:37:30.872382 :B3CDDBE7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 20:37:30.872382 :B3CDDBE8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=129 time=1551826767 2025-07-18 20:37:30.872382 :B3CDDBE9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 20:37:30.872383 :B3CDDBEA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 20:37:30.872383 :B3CDDBEB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 20:37:30.872383 :B3CDDBEC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 20:37:30.872384 :B3CDDBED:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 20:37:30.872872 :B3CDDBEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 20:37:30.872915 :B3CDDBF6:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 20:47:31.774712 :B3CEA5D8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 20:47:32.201328 :B3CEA5FF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 20:47:32.197 2025-07-18 20:47:32.201330 :B3CEA600:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15680 pso_num=22 pso_serial#=16 2025-07-18 20:47:32.201471 :B3CEA601:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15680 osp_idx=0 osp_ver=419818 osp_pg=0 (spawn #398990) 2025-07-18 20:47:32.201471 :B3CEA602:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 20:47:32.201472 :B3CEA603:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=130 time=1552428095 2025-07-18 20:47:32.201472 :B3CEA604:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 20:47:32.201473 :B3CEA605:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 20:47:32.201473 :B3CEA606:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 20:47:32.201473 :B3CEA607:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 20:47:32.201474 :B3CEA608:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 20:47:32.201966 :B3CEA609:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 20:47:32.202012 :B3CEA610:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 20:57:33.155209 :B3CF7054:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 20:57:33.628601 :B3CF706F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 20:57:33.623 2025-07-18 20:57:33.628603 :B3CF7070:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18248 pso_num=22 pso_serial#=17 2025-07-18 20:57:33.628737 :B3CF7071:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18248 osp_idx=0 osp_ver=419819 osp_pg=0 (spawn #399012) 2025-07-18 20:57:33.628737 :B3CF7072:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 20:57:33.628737 :B3CF7073:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=131 time=1553029517 2025-07-18 20:57:33.628738 :B3CF7074:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 20:57:33.628738 :B3CF7075:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 20:57:33.628739 :B3CF7076:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 20:57:33.628739 :B3CF7077:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 20:57:33.628739 :B3CF7078:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 20:57:33.629276 :B3CF7079:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 20:57:33.629321 :B3CF7081:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 21:07:34.500304 :B3D04314:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 21:07:34.895724 :B3D0433B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 21:07:34.890 2025-07-18 21:07:34.895726 :B3D0433C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15708 pso_num=22 pso_serial#=18 2025-07-18 21:07:34.895866 :B3D0433D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15708 osp_idx=0 osp_ver=419820 osp_pg=0 (spawn #399038) 2025-07-18 21:07:34.895866 :B3D0433E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 21:07:34.895866 :B3D0433F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=132 time=1553630783 2025-07-18 21:07:34.895867 :B3D04340:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 21:07:34.895867 :B3D04341:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 21:07:34.895868 :B3D04342:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 21:07:34.895868 :B3D04343:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 21:07:34.895868 :B3D04344:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 21:07:34.896367 :B3D04345:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 21:07:34.896410 :B3D0434D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 21:17:35.814426 :B3D11074:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 21:17:36.163018 :B3D1108F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 21:17:36.158 2025-07-18 21:17:36.163020 :B3D11090:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14712 pso_num=22 pso_serial#=19 2025-07-18 21:17:36.163175 :B3D11091:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14712 osp_idx=0 osp_ver=419821 osp_pg=0 (spawn #399061) 2025-07-18 21:17:36.163176 :B3D11092:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 21:17:36.163177 :B3D11093:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=133 time=1554232064 2025-07-18 21:17:36.163177 :B3D11094:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 21:17:36.163178 :B3D11095:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 21:17:36.163179 :B3D11096:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 21:17:36.163180 :B3D11097:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 21:17:36.163180 :B3D11098:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 21:17:36.163717 :B3D11099:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 21:17:36.163764 :B3D110A1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 21:27:37.066371 :B3D1DA2F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 21:27:37.508651 :B3D1DA68:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 21:27:37.503 2025-07-18 21:27:37.508653 :B3D1DA69:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17124 pso_num=22 pso_serial#=20 2025-07-18 21:27:37.508792 :B3D1DA6A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17124 osp_idx=0 osp_ver=419822 osp_pg=0 (spawn #399083) 2025-07-18 21:27:37.508793 :B3D1DA6B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 21:27:37.508794 :B3D1DA6C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=134 time=1554833408 2025-07-18 21:27:37.508794 :B3D1DA6D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 21:27:37.508795 :B3D1DA6E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 21:27:37.508795 :B3D1DA6F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 21:27:37.508795 :B3D1DA70:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 21:27:37.508796 :B3D1DA71:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 21:27:37.509296 :B3D1DA72:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 21:27:37.509345 :B3D1DA79:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 21:37:38.383720 :B3D2A6FF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 21:37:38.794861 :B3D2A738:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 21:37:38.790 2025-07-18 21:37:38.794863 :B3D2A739:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17104 pso_num=22 pso_serial#=21 2025-07-18 21:37:38.795004 :B3D2A73A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17104 osp_idx=0 osp_ver=419823 osp_pg=0 (spawn #399106) 2025-07-18 21:37:38.795005 :B3D2A73B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 21:37:38.795005 :B3D2A73C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=135 time=1555434689 2025-07-18 21:37:38.795006 :B3D2A73D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 21:37:38.795006 :B3D2A73E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 21:37:38.795006 :B3D2A73F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 21:37:38.795006 :B3D2A740:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 21:37:38.795007 :B3D2A741:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 21:37:38.795498 :B3D2A742:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 21:37:38.795546 :B3D2A749:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 21:47:39.723231 :B3D37090:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 21:47:40.118653 :B3D370CA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 21:47:40.114 2025-07-18 21:47:40.118656 :B3D370CB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19252 pso_num=22 pso_serial#=22 2025-07-18 21:47:40.118792 :B3D370CC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19252 osp_idx=0 osp_ver=419824 osp_pg=0 (spawn #399129) 2025-07-18 21:47:40.118793 :B3D370CD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 21:47:40.118793 :B3D370CE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=136 time=1556036017 2025-07-18 21:47:40.118794 :B3D370CF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 21:47:40.118794 :B3D370D0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 21:47:40.118794 :B3D370D1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 21:47:40.118795 :B3D370D2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 21:47:40.118795 :B3D370D3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 21:47:40.119283 :B3D370D4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 21:47:40.119336 :B3D370DB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-18 21:57:41.038826 :B3D43A75:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-18 21:57:41.434578 :B3D43AA3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-18 21:57:41.429 2025-07-18 21:57:41.434580 :B3D43AA4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16512 pso_num=22 pso_serial#=23 2025-07-18 21:57:41.434721 :B3D43AA5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16512 osp_idx=0 osp_ver=419825 osp_pg=0 (spawn #399151) 2025-07-18 21:57:41.434722 :B3D43AA6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-18 21:57:41.434722 :B3D43AA7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=137 time=1556637329 2025-07-18 21:57:41.434722 :B3D43AA8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-18 21:57:41.434723 :B3D43AA9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-18 21:57:41.434723 :B3D43AAA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-18 21:57:41.434724 :B3D43AAB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-18 21:57:41.434724 :B3D43AAC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-18 21:57:41.435237 :B3D43AAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-18 21:57:41.435284 :B3D43AB4:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 16512, W000)