Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250527220004\orcl_j001_12924_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:37287M/63366M, Ph+PgF:44260M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 12924, image: ORACLE.EXE (J001) *** 2025-05-27 22:00:04.840 *** SESSION ID:(193.37305) 2025-05-27 22:00:04.840 *** 2025-05-27 22:00:04.840 Process diagnostic dump for ORACLE.EXE (J001), OS id=12924, pid: 24, proc_ser: 82, sid: 193, sess_ser: 37305 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12924 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.314399 sec, exc=0.314399 sec, total=0.314399 sec wait times: max=0.500000 sec, heur=4.135704 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.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.501723 sec, exc=0.501723 sec, total=0.501723 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.328951 sec, exc=0.328951 sec, total=0.328951 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 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.000014 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 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.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500115 sec, exc=0.500115 sec, total=0.500115 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.500132 sec, exc=0.500132 sec, total=0.500132 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.490322 sec, exc=0.490322 sec, total=0.490322 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 193 serial 37305 --------------------------------------------------- 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 --------------------------------------------------- [5 samples, 22:00:00 - 22:00:04] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-27 22:00:04.840 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 12924, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-27 21:49:54.673295 :9CD8FAD8:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12732 pso_num=24 pso_serial#=71 2025-05-27 21:49:54.673432 :9CD8FAD9:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12732 osp_idx=22 osp_ver=327490 osp_pg=0 (spawn #225791) 2025-05-27 21:49:54.673432 :9CD8FADA:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:49:54.673433 :9CD8FADB:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=35 time=1358366922 2025-05-27 21:49:54.673433 :9CD8FADC:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:49:54.673434 :9CD8FADD:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:49:54.673434 :9CD8FADE:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:49:54.673434 :9CD8FADF:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:49:54.673435 :9CD8FAE0:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:49:54.673910 :9CD8FAE1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:50:19.705761 :9CD9031B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-27 21:50:49.777758 :9CD90C34:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:51:19.818731 :9CD915E8:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:51:19.807 2025-05-27 21:51:19.818733 :9CD915E9:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15228 pso_num=24 pso_serial#=72 2025-05-27 21:51:19.818870 :9CD915EA:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15228 osp_idx=22 osp_ver=327491 osp_pg=0 (spawn #225794) 2025-05-27 21:51:19.818871 :9CD915EB:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:51:19.818871 :9CD915EC:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=36 time=1358452063 2025-05-27 21:51:19.818872 :9CD915ED:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:51:19.818872 :9CD915EE:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:51:19.818873 :9CD915EF:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:51:19.818873 :9CD915F0:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:51:19.818873 :9CD915F1:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:51:19.819358 :9CD915F2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:51:49.896994 :9CD91FE0:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:51:53.726530 :9CD9214D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:51:53.714 2025-05-27 21:51:53.726532 :9CD9214E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=13468 pso_num=24 pso_serial#=73 2025-05-27 21:51:53.726670 :9CD9214F:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=13468 osp_idx=22 osp_ver=327492 osp_pg=0 (spawn #225796) 2025-05-27 21:51:53.726670 :9CD92150:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:51:53.726671 :9CD92151:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=37 time=1358485969 2025-05-27 21:51:53.726671 :9CD92152:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:51:53.726672 :9CD92153:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:51:53.726672 :9CD92154:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:51:53.726672 :9CD92155:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:51:53.726673 :9CD92156:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:51:53.727169 :9CD92157:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:51:53.727207 :9CD9215D:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-27 21:51:53.731320 :9CD92176:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-05-27 21:51:53.731366 :9CD92177:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-05-27 21:51:53.731620 :9CD92178:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-05-27 21:51:53.731636 :9CD92179:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-05-27 21:51:53.731849 :9CD9217A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-05-27 21:51:53.731862 :9CD9217B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-05-27 21:51:53.732071 :9CD9217C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-05-27 21:51:53.732084 :9CD9217D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-05-27 21:51:53.732288 :9CD9217E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-05-27 21:51:53.732302 :9CD9217F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-05-27 21:51:53.732568 :9CD92180:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-05-27 21:51:53.732581 :9CD92181:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-05-27 21:51:53.734910 :9CD92182:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:52:19.897831 :9CD929CE:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:52:19.886 2025-05-27 21:52:19.897833 :9CD929CF:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14400 pso_num=24 pso_serial#=74 2025-05-27 21:52:19.897967 :9CD929D0:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14400 osp_idx=22 osp_ver=327493 osp_pg=0 (spawn #225798) 2025-05-27 21:52:19.897967 :9CD929D1:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:52:19.897967 :9CD929D2:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=38 time=1358512141 2025-05-27 21:52:19.897968 :9CD929D3:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:52:19.897968 :9CD929D4:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:52:19.897969 :9CD929D5:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:52:19.897969 :9CD929D6:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:52:19.897969 :9CD929D7:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:52:19.898455 :9CD929D8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:52:49.978673 :9CD93329:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:53:20.010491 :9CD93C9D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:53:19.999 2025-05-27 21:53:20.010493 :9CD93C9E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15308 pso_num=24 pso_serial#=75 2025-05-27 21:53:20.010627 :9CD93C9F:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15308 osp_idx=22 osp_ver=327494 osp_pg=0 (spawn #225800) 2025-05-27 21:53:20.010628 :9CD93CA0:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:53:20.010628 :9CD93CA1:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=39 time=1358572250 2025-05-27 21:53:20.010628 :9CD93CA2:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:53:20.010629 :9CD93CA3:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:53:20.010629 :9CD93CA4:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:53:20.010629 :9CD93CA5:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:53:20.010630 :9CD93CA6:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:53:20.011104 :9CD93CA7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:53:50.072522 :9CD945D6:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:54:20.076109 :9CD94F6C:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:54:20.065 2025-05-27 21:54:20.076112 :9CD94F6D:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14876 pso_num=24 pso_serial#=76 2025-05-27 21:54:20.076248 :9CD94F6E:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14876 osp_idx=22 osp_ver=327495 osp_pg=0 (spawn #225802) 2025-05-27 21:54:20.076249 :9CD94F6F:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:54:20.076249 :9CD94F70:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=40 time=1358632329 2025-05-27 21:54:20.076250 :9CD94F71:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:54:20.076250 :9CD94F72:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:54:20.076251 :9CD94F73:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:54:20.076251 :9CD94F74:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:54:20.076251 :9CD94F75:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:54:20.076731 :9CD94F76:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:54:50.180929 :9CD958EE:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:55:20.195938 :9CD9630E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:55:20.185 2025-05-27 21:55:20.195940 :9CD9630F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9148 pso_num=24 pso_serial#=77 2025-05-27 21:55:20.196115 :9CD96310:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=9148 osp_idx=22 osp_ver=327496 osp_pg=0 (spawn #225804) 2025-05-27 21:55:20.196116 :9CD96311:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:55:20.196116 :9CD96312:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=41 time=1358692438 2025-05-27 21:55:20.196117 :9CD96313:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:55:20.196117 :9CD96314:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:55:20.196117 :9CD96315:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:55:20.196118 :9CD96316:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:55:20.196118 :9CD96317:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:55:20.196627 :9CD96318:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:55:50.270374 :9CD96CB6:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:56:20.280048 :9CD97632:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:56:20.269 2025-05-27 21:56:20.280049 :9CD97633:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15184 pso_num=24 pso_serial#=78 2025-05-27 21:56:20.280181 :9CD97634:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15184 osp_idx=22 osp_ver=327497 osp_pg=0 (spawn #225806) 2025-05-27 21:56:20.280182 :9CD97635:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:56:20.280182 :9CD97636:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=42 time=1358752532 2025-05-27 21:56:20.280183 :9CD97637:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:56:20.280183 :9CD97638:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:56:20.280183 :9CD97639:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:56:20.280184 :9CD9763A:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:56:20.280184 :9CD9763B:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:56:20.280657 :9CD9763C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:56:50.408669 :9CD98098:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:57:20.374176 :9CD98A3B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:57:20.363 2025-05-27 21:57:20.374178 :9CD98A3C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=13596 pso_num=24 pso_serial#=79 2025-05-27 21:57:20.374313 :9CD98A3D:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=13596 osp_idx=22 osp_ver=327498 osp_pg=0 (spawn #225808) 2025-05-27 21:57:20.374314 :9CD98A3E:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:57:20.374315 :9CD98A3F:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=43 time=1358812625 2025-05-27 21:57:20.374315 :9CD98A40:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:57:20.374315 :9CD98A41:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:57:20.374316 :9CD98A42:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:57:20.374316 :9CD98A43:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:57:20.374317 :9CD98A44:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:57:20.374804 :9CD98A45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:57:50.419986 :9CD993AD:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:58:20.450424 :9CD99D42:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:58:20.439 2025-05-27 21:58:20.450427 :9CD99D43:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14180 pso_num=24 pso_serial#=80 2025-05-27 21:58:20.450561 :9CD99D44:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14180 osp_idx=22 osp_ver=327499 osp_pg=0 (spawn #225810) 2025-05-27 21:58:20.450562 :9CD99D45:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:58:20.450562 :9CD99D46:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=44 time=1358872704 2025-05-27 21:58:20.450563 :9CD99D47:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:58:20.450563 :9CD99D48:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:58:20.450565 :9CD99D49:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:58:20.450565 :9CD99D4A:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:58:20.450566 :9CD99D4B:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:58:20.451041 :9CD99D4C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:58:50.507481 :9CD9A6C6:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:59:20.536471 :9CD9B034:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:59:20.525 2025-05-27 21:59:20.536473 :9CD9B035:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=7776 pso_num=24 pso_serial#=81 2025-05-27 21:59:20.536603 :9CD9B036:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=7776 osp_idx=22 osp_ver=327500 osp_pg=0 (spawn #225812) 2025-05-27 21:59:20.536603 :9CD9B037:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:59:20.536604 :9CD9B038:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=45 time=1358932782 2025-05-27 21:59:20.536604 :9CD9B039:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:59:20.536605 :9CD9B03A:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:59:20.536605 :9CD9B03B:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:59:20.536605 :9CD9B03C:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:59:20.536606 :9CD9B03D:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:59:20.537161 :9CD9B03E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 21:59:50.631319 :9CD9BA18:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-27 21:59:55.584310 :9CD9BBC8:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-27 21:59:55.573 2025-05-27 21:59:55.584312 :9CD9BBC9:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12924 pso_num=24 pso_serial#=82 2025-05-27 21:59:55.584452 :9CD9BBCA:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12924 osp_idx=22 osp_ver=327501 osp_pg=0 (spawn #225814) 2025-05-27 21:59:55.584452 :9CD9BBCB:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-27 21:59:55.584453 :9CD9BBCC:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=46 time=1358967829 2025-05-27 21:59:55.584453 :9CD9BBCD:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-27 21:59:55.584454 :9CD9BBCE:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-27 21:59:55.584454 :9CD9BBCF:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-27 21:59:55.584455 :9CD9BBD0:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-27 21:59:55.584455 :9CD9BBD1:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-27 21:59:55.584942 :9CD9BBD2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.572502 :9CD9BEDE:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-27 22:00:00.572502*:9CD9BF0D:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002495C718 estart=1748354400 eid=16781231 ctx=0x000000077FD6A000 cwh=0x0000000024950068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-27 22:00:00.572502*:9CD9BF0F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002495C718 curCtx=0x0000000024958938 pubTabIdxCnt=0 2025-05-27 22:00:00.572502*:9CD9BF10:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002495C718 2025-05-27 22:00:00.572502*:9CD9BF11:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002495C718 2025-05-27 22:00:00.572502*:9CD9BF1F:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002495C718 curCtx=0x0000000024958938 xsc->flg4=65792 flags=2 2025-05-27 22:00:00.572502*:9CD9BF20:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002495C718 2025-05-27 22:00:00.579277 :9CD9BF21:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.579337 :9CD9BF24:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-05-27 22:00:00.591104 :9CD9BFB1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.596667 :9CD9C0E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.597462 :9CD9C0E9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.603376 :9CD9C0FB:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-27 22:00:00.603578 :9CD9C0FC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.603735 :9CD9C10B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.603979 :9CD9C116:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.604357 :9CD9C126:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.604555 :9CD9C12E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-05-27 22:00:00.606055 :9CD9C132:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.606093 :9CD9C133:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.606202 :9CD9C146:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-27 22:00:00.697030 :9CD9C222:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-27 22:00:00.699426 :9CD9C225:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.699466 :9CD9C228:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-05-27 22:00:00.701966 :9CD9C22E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-05-27 22:00:00.705135 :9CD9C22F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.705212 :9CD9C232:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-27 22:00:00.705327 :9CD9C23F:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-27 22:00:04.026124 :9CD9C7B2:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 24 (osid: 12924, J001)