Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510060009\orcl_j000_7872_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:37473M/63366M, Ph+PgF:44814M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 7872, image: ORACLE.EXE (J000) *** 2025-05-10 06:00:09.402 *** SESSION ID:(201.56169) 2025-05-10 06:00:09.402 *** 2025-05-10 06:00:09.402 Process diagnostic dump for ORACLE.EXE (J000), OS id=7872, pid: 25, proc_ser: 15, sid: 201, sess_ser: 56169 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 7872 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.196447 sec, exc=0.196447 sec, total=0.196447 sec wait times: max=0.500000 sec, heur=7.224480 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.000010 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.512652 sec, exc=0.512652 sec, total=0.512652 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.499963 sec, exc=0.499963 sec, total=0.499963 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000017 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.510126 sec, exc=0.510126 sec, total=0.510126 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.510112 sec, exc=0.510112 sec, total=0.510112 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500000 sec, exc=0.500000 sec, total=0.500000 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time Sampled Session History of session 201 serial 56169 --------------------------------------------------- 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 --------------------------------------------------- [8 samples, 06:00:02 - 06:00:09] idle wait at each sample [session created at: 06:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 06:00:09.402 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 7872, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 05:51:13.473753 :9517EB19:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11216 osp_idx=23 osp_ver=84154 osp_pg=0 (spawn #166775) 2025-05-10 05:51:13.473754 :9517EB1A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:51:13.473754 :9517EB1B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=78 time=4127050640 2025-05-10 05:51:13.473755 :9517EB1C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:51:13.473755 :9517EB1D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:51:13.473756 :9517EB1E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:51:13.473756 :9517EB1F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:51:13.473756 :9517EB20:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:51:13.474234 :9517EB21:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:51:43.605746 :9517F4B8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:52:13.599987 :9517FE48:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:52:13.588 2025-05-10 05:52:13.599989 :9517FE49:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9804 pso_num=25 pso_serial#=6 2025-05-10 05:52:13.600121 :9517FE4A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9804 osp_idx=23 osp_ver=84155 osp_pg=0 (spawn #166777) 2025-05-10 05:52:13.600122 :9517FE4B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:52:13.600123 :9517FE4C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=79 time=4127110765 2025-05-10 05:52:13.600123 :9517FE4D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:52:13.600123 :9517FE4E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:52:13.600124 :9517FE4F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:52:13.600124 :9517FE50:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:52:13.600125 :9517FE51:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:52:13.600652 :9517FE52:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:52:43.669545 :951807F7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:53:13.680046 :95181199:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:53:13.668 2025-05-10 05:53:13.680048 :9518119A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9560 pso_num=25 pso_serial#=7 2025-05-10 05:53:13.680178 :9518119B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9560 osp_idx=23 osp_ver=84156 osp_pg=0 (spawn #166779) 2025-05-10 05:53:13.680179 :9518119C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:53:13.680179 :9518119D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=80 time=4127170843 2025-05-10 05:53:13.680180 :9518119E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:53:13.680180 :9518119F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:53:13.680180 :951811A0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:53:13.680181 :951811A1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:53:13.680181 :951811A2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:53:13.680658 :951811A3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:53:43.770645 :95181B30:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:54:13.773985 :951824E0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:54:13.762 2025-05-10 05:54:13.773988 :951824E1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11456 pso_num=25 pso_serial#=8 2025-05-10 05:54:13.774132 :951824E2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11456 osp_idx=23 osp_ver=84157 osp_pg=0 (spawn #166781) 2025-05-10 05:54:13.774133 :951824E3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:54:13.774134 :951824E4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=81 time=4127230937 2025-05-10 05:54:13.774135 :951824E5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:54:13.774135 :951824E6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:54:13.774135 :951824E7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:54:13.774136 :951824E8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:54:13.774136 :951824E9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:54:13.774602 :951824EA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:54:43.857667 :95182FAF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:55:13.853351 :9518398E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:55:13.842 2025-05-10 05:55:13.853352 :9518398F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12232 pso_num=25 pso_serial#=9 2025-05-10 05:55:13.853486 :95183990:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12232 osp_idx=23 osp_ver=84158 osp_pg=0 (spawn #166784) 2025-05-10 05:55:13.853487 :95183991:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:55:13.853488 :95183992:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=82 time=4127291015 2025-05-10 05:55:13.853488 :95183993:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:55:13.853488 :95183994:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:55:13.853489 :95183995:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:55:13.853489 :95183996:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:55:13.853489 :95183997:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:55:13.853966 :95183998:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:55:43.952039 :9518437A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:56:13.944920 :95184D1F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:56:13.934 2025-05-10 05:56:13.944922 :95184D20:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12044 pso_num=25 pso_serial#=10 2025-05-10 05:56:13.945049 :95184D21:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12044 osp_idx=23 osp_ver=84159 osp_pg=0 (spawn #166786) 2025-05-10 05:56:13.945050 :95184D22:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:56:13.945050 :95184D23:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=83 time=4127351109 2025-05-10 05:56:13.945051 :95184D24:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:56:13.945051 :95184D25:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:56:13.945052 :95184D26:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:56:13.945052 :95184D27:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:56:13.945052 :95184D28:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:56:13.945540 :95184D29:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:56:44.043910 :951856E2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:57:14.058650 :95186068:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:57:14.048 2025-05-10 05:57:14.058652 :95186069:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11920 pso_num=25 pso_serial#=11 2025-05-10 05:57:14.058797 :9518606A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11920 osp_idx=23 osp_ver=84160 osp_pg=0 (spawn #166788) 2025-05-10 05:57:14.058798 :9518606B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:57:14.058798 :9518606C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=84 time=4127411218 2025-05-10 05:57:14.058799 :9518606D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:57:14.058799 :9518606E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:57:14.058799 :9518606F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:57:14.058800 :95186070:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:57:14.058800 :95186071:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:57:14.059291 :95186072:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:57:44.169279 :95186AB6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:58:14.149109 :9518740A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:58:14.138 2025-05-10 05:58:14.149111 :9518740B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12960 pso_num=25 pso_serial#=12 2025-05-10 05:58:14.149238 :9518740C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12960 osp_idx=23 osp_ver=84161 osp_pg=0 (spawn #166790) 2025-05-10 05:58:14.149239 :9518740D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:58:14.149239 :9518740E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=85 time=4127471312 2025-05-10 05:58:14.149239 :9518740F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:58:14.149242 :95187410:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:58:14.149242 :95187411:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:58:14.149242 :95187412:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:58:14.149242 :95187413:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:58:14.149733 :95187414:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:58:44.259415 :95187DCD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 05:59:09.249551 :951885F3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 05:59:09.238 2025-05-10 05:59:09.249554 :951885F4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10320 pso_num=25 pso_serial#=13 2025-05-10 05:59:09.249680 :951885F5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10320 osp_idx=23 osp_ver=84162 osp_pg=0 (spawn #166792) 2025-05-10 05:59:09.249681 :951885F6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:59:09.249681 :951885F7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=86 time=4127526406 2025-05-10 05:59:09.249682 :951885F8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:59:09.249682 :951885F9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:59:09.249683 :951885FA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:59:09.249683 :951885FB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:59:09.249683 :951885FC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:59:09.250238 :951885FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:59:14.255148 :951887C5:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 05:59:44.363224 :951891EE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 06:00:00.035702 :951896FB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 06:00:00.027 2025-05-10 06:00:00.035704 :951896FC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10860 pso_num=25 pso_serial#=14 2025-05-10 06:00:00.035838 :951896FD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10860 osp_idx=23 osp_ver=84163 osp_pg=0 (spawn #166795) 2025-05-10 06:00:00.035838 :951896FE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 06:00:00.035839 :951896FF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=87 time=4127577203 2025-05-10 06:00:00.035839 :95189700:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 06:00:00.035839 :95189701:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 06:00:00.035840 :95189702:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 06:00:00.035840 :95189703:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 06:00:00.035841 :95189704:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 06:00:00.036359 :95189705:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.036405 :9518970B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:00.036498 :9518971F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.040437 :9518972E: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-10 06:00:00.041716 :95189736: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-10 06:00:00.041744 :95189739:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.041801 :95189744:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:00.043642 :9518974F: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-10 06:00:00.043665 :95189752:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.043698 :9518975D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:00.044146 :95189768: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-10 06:00:00.046709 :95189770: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-10 06:00:00.051992 :95189778: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-10 06:00:00.057529 :95189780: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-10 06:00:00.059380 :95189788: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-10 06:00:00.062387 :95189790: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-10 06:00:00.063650 :95189798: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-10 06:00:00.064553 :951897A0: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-10 06:00:00.067153 :951897A8: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-10 06:00:00.071099 :951897B0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.071464 :951897BF: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-10 06:00:00.071513 :951897C2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-10 06:00:00.071527 :951897C3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-10 06:00:00.074366 :951897C9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.074659 :951897D8: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-10 06:00:00.074706 :951897DB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-10 06:00:00.074721 :951897DC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-10 06:00:00.077390 :951897E2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.077655 :951897F1: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-10 06:00:00.077700 :951897F4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-10 06:00:00.077715 :951897F5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-10 06:00:00.077946 :951897FB: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-10 06:00:00.077964 :951897FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:00.077993 :9518980A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:00.079540 :95189814:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-10 06:00:02.042046 :951898E3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-10 06:00:02.037 2025-05-10 06:00:02.042048 :951898E4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7872 pso_num=25 pso_serial#=15 2025-05-10 06:00:02.042181 :951898E5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7872 osp_idx=23 osp_ver=84164 osp_pg=0 (spawn #166796) 2025-05-10 06:00:02.042182 :951898E6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 06:00:02.042183 :951898E7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=88 time=4127579203 2025-05-10 06:00:02.042183 :951898E8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 06:00:02.042183 :951898E9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 06:00:02.042184 :951898EA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 06:00:02.042184 :951898EB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 06:00:02.042184 :951898EC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 06:00:02.042667 :951898ED:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.047858 :9518990C: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-10 06:00:02.047901 :95189910:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-10 06:00:02.063382 :95189987:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=29 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.063506 :9518998A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=29 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.064539 :951899A0: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-10 06:00:02.069629 :95189AF1: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-10 06:00:02.070352 :95189B04: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-10 06:00:02.076295 :95189B26:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.076446 :95189B35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.077209 :95189B3D: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-10 06:00:02.077411 :95189B46:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-10 06:00:02.077922 :95189B47:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=28 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.078409 :95189B4A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=28 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.078498 :95189B4C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=28 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.078570 :95189B4F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=28 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:02.078599 :95189B52:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=28 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:02.079149 :95189B53: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-10 06:00:02.079202 :95189B56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.079337 :95189B6B: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-10 06:00:02.177676 :95189C53:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:02.179790 :95189C56: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-10 06:00:02.179828 :95189C59:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-10 06:00:02.182275 :95189C5F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-10 06:00:02.185567 :95189C60: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-10 06:00:02.185650 :95189C63:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.185734 :95189C70: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 7872, J000)