Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250628060006\orcl_j000_14664_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:36379M/63366M, Ph+PgF:42512M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 14664, image: ORACLE.EXE (J000) *** 2025-06-28 06:00:06.179 *** SESSION ID:(201.53787) 2025-06-28 06:00:06.179 *** 2025-06-28 06:00:06.179 Process diagnostic dump for ORACLE.EXE (J000), OS id=14664, pid: 25, proc_ser: 187, sid: 201, sess_ser: 53787 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 14664 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.335301 sec, exc=0.335301 sec, total=0.335301 sec wait times: max=0.500000 sec, heur=3.829278 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.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.503177 sec, exc=0.503177 sec, total=0.503177 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499984 sec, exc=0.499984 sec, total=0.499984 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.500006 sec, exc=0.500006 sec, total=0.500006 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.499991 sec, exc=0.499991 sec, total=0.499991 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.500014 sec, exc=0.500014 sec, total=0.500014 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499990 sec, exc=0.499990 sec, total=0.499990 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.490757 sec, exc=0.490757 sec, total=0.490757 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 201 serial 53787 --------------------------------------------------- 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 --------------------------------------------------- [4 samples, 06:00:02 - 06:00:06] 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-06-28 06:00:06.179 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 14664, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-28 05:53:24.447653 :AAA448D3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14052 osp_idx=23 osp_ver=172160 osp_pg=0 (spawn #330258) 2025-06-28 05:53:24.447654 :AAA448D4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:53:24.447654 :AAA448D5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=37 time=4065747625 2025-06-28 05:53:24.447654 :AAA448D6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:53:24.447655 :AAA448D7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:53:24.447655 :AAA448D8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:53:24.447655 :AAA448D9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:53:24.447656 :AAA448DA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:53:24.448141 :AAA448DB: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-06-28 05:53:54.522417 :AAA452D1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 05:54:24.547020 :AAA45C92:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 05:54:24.535 2025-06-28 05:54:24.547022 :AAA45C93:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17488 pso_num=25 pso_serial#=179 2025-06-28 05:54:24.547156 :AAA45C94:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17488 osp_idx=23 osp_ver=172161 osp_pg=0 (spawn #330260) 2025-06-28 05:54:24.547157 :AAA45C95:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:54:24.547158 :AAA45C96:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=38 time=4065807735 2025-06-28 05:54:24.547158 :AAA45C97:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:54:24.547159 :AAA45C98:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:54:24.547159 :AAA45C99:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:54:24.547159 :AAA45C9A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:54:24.547161 :AAA45C9B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:54:24.547655 :AAA45C9C: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-06-28 05:54:54.599551 :AAA4663D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 05:55:24.645686 :AAA4708C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 05:55:24.634 2025-06-28 05:55:24.645688 :AAA4708D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14152 pso_num=25 pso_serial#=180 2025-06-28 05:55:24.645830 :AAA4708E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14152 osp_idx=23 osp_ver=172162 osp_pg=0 (spawn #330262) 2025-06-28 05:55:24.645830 :AAA4708F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:55:24.645831 :AAA47090:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=39 time=4065867829 2025-06-28 05:55:24.645831 :AAA47091:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:55:24.645832 :AAA47092:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:55:24.645832 :AAA47093:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:55:24.645832 :AAA47094:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:55:24.645833 :AAA47095:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:55:24.646316 :AAA47096: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-06-28 05:55:54.745455 :AAA47ABF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 05:56:02.982554 :AAA47D78:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 05:56:02.970 2025-06-28 05:56:02.982556 :AAA47D79:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17976 pso_num=25 pso_serial#=181 2025-06-28 05:56:02.982699 :AAA47D7A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17976 osp_idx=23 osp_ver=172163 osp_pg=0 (spawn #330264) 2025-06-28 05:56:02.982700 :AAA47D7B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:56:02.982701 :AAA47D7C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=40 time=4065906172 2025-06-28 05:56:02.982702 :AAA47D7D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:56:02.982702 :AAA47D7E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:56:02.982703 :AAA47D7F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:56:02.982703 :AAA47D80:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:56:02.982703 :AAA47D81:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:56:02.983266 :AAA47D82: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-06-28 05:56:02.983308 :AAA47D89: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-06-28 05:56:02.987252 :AAA47DA5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-28 05:56:02.987302 :AAA47DA6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-28 05:56:02.987564 :AAA47DA7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-28 05:56:02.987581 :AAA47DA8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-28 05:56:02.987799 :AAA47DA9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-28 05:56:02.987813 :AAA47DAA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-28 05:56:02.988022 :AAA47DAB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-28 05:56:02.988035 :AAA47DAC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-28 05:56:02.988244 :AAA47DAD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-28 05:56:02.988256 :AAA47DAE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-28 05:56:02.988457 :AAA47DAF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-28 05:56:02.988470 :AAA47DB0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-28 05:56:02.990785 :AAA47DB1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 05:56:24.714268 :AAA484BB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 05:56:24.703 2025-06-28 05:56:24.714269 :AAA484BC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4500 pso_num=25 pso_serial#=182 2025-06-28 05:56:24.714398 :AAA484BD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4500 osp_idx=23 osp_ver=172164 osp_pg=0 (spawn #330266) 2025-06-28 05:56:24.714399 :AAA484BE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:56:24.714399 :AAA484BF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=41 time=4065927891 2025-06-28 05:56:24.714400 :AAA484C0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:56:24.714400 :AAA484C1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:56:24.714400 :AAA484C2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:56:24.714400 :AAA484C3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:56:24.714401 :AAA484C4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:56:24.714873 :AAA484C5: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-06-28 05:56:49.749860 :AAA48CA2: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-06-28 05:57:19.826427 :AAA49689:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 05:57:24.799053 :AAA49878:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 05:57:24.787 2025-06-28 05:57:24.799056 :AAA49879:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14388 pso_num=25 pso_serial#=183 2025-06-28 05:57:24.799181 :AAA4987A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14388 osp_idx=23 osp_ver=172165 osp_pg=0 (spawn #330268) 2025-06-28 05:57:24.799181 :AAA4987B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:57:24.799182 :AAA4987C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=42 time=4065987985 2025-06-28 05:57:24.799182 :AAA4987D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:57:24.799183 :AAA4987E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:57:24.799183 :AAA4987F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:57:24.799184 :AAA49880:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:57:24.799184 :AAA49881:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:57:24.799690 :AAA49882: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-06-28 05:57:54.858777 :AAA4A23D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 05:58:24.864488 :AAA4ABAB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 05:58:24.853 2025-06-28 05:58:24.864491 :AAA4ABAC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18288 pso_num=25 pso_serial#=184 2025-06-28 05:58:24.864607 :AAA4ABAD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18288 osp_idx=23 osp_ver=172166 osp_pg=0 (spawn #330270) 2025-06-28 05:58:24.864608 :AAA4ABAE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:58:24.864608 :AAA4ABAF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=43 time=4066048047 2025-06-28 05:58:24.864608 :AAA4ABB0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:58:24.864609 :AAA4ABB1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:58:24.864609 :AAA4ABB2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:58:24.864610 :AAA4ABB3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:58:24.864610 :AAA4ABB4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:58:24.865086 :AAA4ABB5: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-06-28 05:58:54.964166 :AAA4B57D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 05:59:24.937197 :AAA4BF7F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 05:59:24.926 2025-06-28 05:59:24.937200 :AAA4BF80:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4728 pso_num=25 pso_serial#=185 2025-06-28 05:59:24.937341 :AAA4BF81:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4728 osp_idx=23 osp_ver=172167 osp_pg=0 (spawn #330272) 2025-06-28 05:59:24.937342 :AAA4BF82:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 05:59:24.937342 :AAA4BF83:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=44 time=4066108125 2025-06-28 05:59:24.937343 :AAA4BF84:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 05:59:24.937343 :AAA4BF85:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 05:59:24.937344 :AAA4BF86:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 05:59:24.937344 :AAA4BF87:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 05:59:24.937344 :AAA4BF88:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 05:59:24.937845 :AAA4BF89: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-06-28 05:59:55.029432 :AAA4C960:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 06:00:00.214928 :AAA4CB38:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 06:00:00.206 2025-06-28 06:00:00.214930 :AAA4CB39:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8776 pso_num=25 pso_serial#=186 2025-06-28 06:00:00.215062 :AAA4CB3A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8776 osp_idx=23 osp_ver=172168 osp_pg=0 (spawn #330274) 2025-06-28 06:00:00.215063 :AAA4CB3B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 06:00:00.215063 :AAA4CB3C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=45 time=4066143407 2025-06-28 06:00:00.215064 :AAA4CB3D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 06:00:00.215064 :AAA4CB3E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 06:00:00.215065 :AAA4CB3F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 06:00:00.215065 :AAA4CB40:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 06:00:00.215065 :AAA4CB41:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 06:00:00.215548 :AAA4CB42: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-06-28 06:00:00.215589 :AAA4CB49: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-06-28 06:00:00.215661 :AAA4CB5D: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-06-28 06:00:00.219608 :AAA4CB6C: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-06-28 06:00:00.220750 :AAA4CB74: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-06-28 06:00:00.220776 :AAA4CB77: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-06-28 06:00:00.220815 :AAA4CB82: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-06-28 06:00:00.222682 :AAA4CB8D: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-06-28 06:00:00.222709 :AAA4CB90: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-06-28 06:00:00.222743 :AAA4CB9B: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-06-28 06:00:00.223224 :AAA4CBA6: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-06-28 06:00:00.225692 :AAA4CBAE: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-06-28 06:00:00.231012 :AAA4CBB6: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-06-28 06:00:00.236464 :AAA4CBBE: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-06-28 06:00:00.237872 :AAA4CBC6: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-06-28 06:00:00.240836 :AAA4CBCE: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-06-28 06:00:00.242618 :AAA4CBD6: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-06-28 06:00:00.243589 :AAA4CBDE: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-06-28 06:00:00.246207 :AAA4CBE6: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-06-28 06:00:00.250121 :AAA4CBEE: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-06-28 06:00:00.250487 :AAA4CBFD: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-06-28 06:00:00.250539 :AAA4CC00:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-06-28 06:00:00.250554 :AAA4CC01:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-06-28 06:00:00.253303 :AAA4CC07: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-06-28 06:00:00.253584 :AAA4CC16: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-06-28 06:00:00.253629 :AAA4CC19:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-06-28 06:00:00.253642 :AAA4CC1A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-06-28 06:00:00.256443 :AAA4CC20: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-06-28 06:00:00.256720 :AAA4CC2F: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-06-28 06:00:00.256766 :AAA4CC32:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-06-28 06:00:00.256779 :AAA4CC33:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-06-28 06:00:00.256957 :AAA4CC39: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-06-28 06:00:00.256970 :AAA4CC3C: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-06-28 06:00:00.256992 :AAA4CC48: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-06-28 06:00:00.258541 :AAA4CC52:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-28 06:00:02.211830 :AAA4CCF7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-28 06:00:02.206 2025-06-28 06:00:02.211833 :AAA4CCF8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14664 pso_num=25 pso_serial#=187 2025-06-28 06:00:02.211964 :AAA4CCF9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14664 osp_idx=23 osp_ver=172169 osp_pg=0 (spawn #330275) 2025-06-28 06:00:02.211965 :AAA4CCFA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 06:00:02.211966 :AAA4CCFB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=46 time=4066145407 2025-06-28 06:00:02.211966 :AAA4CCFC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 06:00:02.211966 :AAA4CCFD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 06:00:02.211967 :AAA4CCFE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 06:00:02.211967 :AAA4CCFF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 06:00:02.211967 :AAA4CD00:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 06:00:02.212465 :AAA4CD01: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-06-28 06:00:02.217763 :AAA4CD21: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-06-28 06:00:02.217816 :AAA4CD2B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-06-28 06:00:02.229016 :AAA4CD78:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch: cache buffers chains] 33226689056/0x7bc770a20 150/0x96 0/0x0 wait_id=6 seq_num=7 snap_id=1 2025-06-28 06:00:02.229036 :AAA4CD79:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch: cache buffers chains] 33226689056/0x7bc770a20 150/0x96 0/0x0 wait_id=6 seq_num=7 snap_id=1 2025-06-28 06:00:02.229037 :AAA4CD7A:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=20, exc=20, tot=20 2025-06-28 06:00:02.229203 :AAA4CD7F: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-06-28 06:00:02.234749 :AAA4CDB6: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-06-28 06:00:02.235572 :AAA4CDD3: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-06-28 06:00:02.241079 :AAA4CF09: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-06-28 06:00:02.241228 :AAA4CF18: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-06-28 06:00:02.242020 :AAA4CF40: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-06-28 06:00:02.242229 :AAA4CF48:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-06-28 06:00:02.243912 :AAA4CF49: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-06-28 06:00:02.244003 :AAA4CF4C: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-06-28 06:00:02.347238 :AAA4D049: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-06-28 06:00:02.349378 :AAA4D04B: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-06-28 06:00:02.349415 :AAA4D04E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-06-28 06:00:02.351906 :AAA4D054:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-06-28 06:00:02.355134 :AAA4D055: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-06-28 06:00:02.355212 :AAA4D058: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-06-28 06:00:02.355296 :AAA4D065: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: 14664, J000)