Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250502220005\orcl_j001_12100_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:37578M/63366M, Ph+PgF:45122M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 12100, image: ORACLE.EXE (J001) *** 2025-05-02 22:00:05.484 *** SESSION ID:(201.31275) 2025-05-02 22:00:05.484 *** 2025-05-02 22:00:05.484 Process diagnostic dump for ORACLE.EXE (J001), OS id=12100, pid: 25, proc_ser: 119, sid: 201, sess_ser: 31275 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12100 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.476493 sec, exc=0.476493 sec, total=0.476493 sec wait times: max=0.500000 sec, heur=4.226307 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=8 seq_num=9 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499426 sec, exc=0.499426 sec, total=0.499426 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.141196 sec, exc=0.141196 sec, total=0.141196 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.510109 sec, exc=0.510109 sec, total=0.510109 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 4: 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.000010 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 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.000010 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.510095 sec, exc=0.510095 sec, total=0.510095 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499235 sec, exc=0.499235 sec, total=0.499235 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.089686 sec, exc=0.089686 sec, total=0.089686 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 31275 --------------------------------------------------- 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:01 - 22:00:05] idle wait at each sample [session created at: 22:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-02 22:00:05.484 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 12100, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-02 21:46:55.095963 :91D730B2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:46:55.084 2025-05-02 21:46:55.095965 :91D730B3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11672 pso_num=25 pso_serial#=106 2025-05-02 21:46:55.096098 :91D730B4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11672 osp_idx=23 osp_ver=72780 osp_pg=0 (spawn #141894) 2025-05-02 21:46:55.096099 :91D730B5: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-02 21:46:55.096099 :91D730B6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=80 time=3493204578 2025-05-02 21:46:55.096100 :91D730B7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:46:55.096100 :91D730B8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:46:55.096101 :91D730B9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:46:55.096101 :91D730BA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:46:55.096101 :91D730BB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:46:55.096573 :91D730BC: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-02 21:47:25.184271 :91D73A9E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:47:55.185700 :91D74445:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:47:55.175 2025-05-02 21:47:55.185702 :91D74446:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=1156 pso_num=25 pso_serial#=107 2025-05-02 21:47:55.185837 :91D74447:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=1156 osp_idx=23 osp_ver=72781 osp_pg=0 (spawn #141896) 2025-05-02 21:47:55.185838 :91D74448: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-02 21:47:55.185838 :91D74449:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=81 time=3493264656 2025-05-02 21:47:55.185839 :91D7444A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:47:55.185840 :91D7444B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:47:55.185840 :91D7444C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:47:55.185840 :91D7444D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:47:55.185841 :91D7444E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:47:55.186338 :91D7444F: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-02 21:48:25.278196 :91D74E32:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:48:55.286841 :91D75803:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:48:55.276 2025-05-02 21:48:55.286843 :91D75804:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8312 pso_num=25 pso_serial#=108 2025-05-02 21:48:55.286990 :91D75805:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8312 osp_idx=23 osp_ver=72782 osp_pg=0 (spawn #141898) 2025-05-02 21:48:55.286991 :91D75806: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-02 21:48:55.286991 :91D75807:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=82 time=3493324765 2025-05-02 21:48:55.286992 :91D75808:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:48:55.286992 :91D75809:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:48:55.286992 :91D7580A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:48:55.286993 :91D7580B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:48:55.286993 :91D7580C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:48:55.287481 :91D7580D: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-02 21:49:25.350175 :91D761FD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:49:55.364672 :91D76BDF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:49:55.354 2025-05-02 21:49:55.364674 :91D76BE0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12156 pso_num=25 pso_serial#=109 2025-05-02 21:49:55.364807 :91D76BE1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12156 osp_idx=23 osp_ver=72783 osp_pg=0 (spawn #141901) 2025-05-02 21:49:55.364808 :91D76BE2: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-02 21:49:55.364808 :91D76BE3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=83 time=3493384843 2025-05-02 21:49:55.364809 :91D76BE4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:49:55.364809 :91D76BE5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:49:55.364809 :91D76BE6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:49:55.364810 :91D76BE7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:49:55.364810 :91D76BE8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:49:55.365306 :91D76BE9: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-02 21:50:25.449293 :91D77564:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:50:55.454117 :91D77F5B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:50:55.443 2025-05-02 21:50:55.454119 :91D77F5C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6552 pso_num=25 pso_serial#=110 2025-05-02 21:50:55.454251 :91D77F5D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=6552 osp_idx=23 osp_ver=72784 osp_pg=0 (spawn #141903) 2025-05-02 21:50:55.454252 :91D77F5E: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-02 21:50:55.454252 :91D77F5F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=84 time=3493444937 2025-05-02 21:50:55.454252 :91D77F60:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:50:55.454253 :91D77F61:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:50:55.454253 :91D77F62:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:50:55.454253 :91D77F63:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:50:55.454254 :91D77F64:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:50:55.454742 :91D77F65: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-02 21:51:25.531825 :91D78A31:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:51:55.535844 :91D79400:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:51:55.524 2025-05-02 21:51:55.535847 :91D79401:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11128 pso_num=25 pso_serial#=111 2025-05-02 21:51:55.535983 :91D79402:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11128 osp_idx=23 osp_ver=72785 osp_pg=0 (spawn #141905) 2025-05-02 21:51:55.535984 :91D79403: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-02 21:51:55.535984 :91D79404:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=85 time=3493505015 2025-05-02 21:51:55.535985 :91D79405:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:51:55.535985 :91D79406:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:51:55.535986 :91D79407:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:51:55.535986 :91D79408:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:51:55.535986 :91D79409:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:51:55.536455 :91D7940A: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-02 21:52:25.647378 :91D79DD8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:52:50.595098 :91D7A609:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:52:50.584 2025-05-02 21:52:50.595101 :91D7A60A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11676 pso_num=25 pso_serial#=112 2025-05-02 21:52:50.595232 :91D7A60B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11676 osp_idx=23 osp_ver=72786 osp_pg=0 (spawn #141907) 2025-05-02 21:52:50.595232 :91D7A60C: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-02 21:52:50.595233 :91D7A60D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=86 time=3493560078 2025-05-02 21:52:50.595234 :91D7A60E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:52:50.595234 :91D7A60F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:52:50.595234 :91D7A610:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:52:50.595235 :91D7A611:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:52:50.595235 :91D7A612:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:52:50.595761 :91D7A613: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-02 21:52:55.585914 :91D7A80A: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-02 21:53:25.683628 :91D7B1AB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:53:55.683344 :91D7BB69:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:53:55.672 2025-05-02 21:53:55.683346 :91D7BB6A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10696 pso_num=25 pso_serial#=113 2025-05-02 21:53:55.683483 :91D7BB6B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10696 osp_idx=23 osp_ver=72787 osp_pg=0 (spawn #141909) 2025-05-02 21:53:55.683484 :91D7BB6C: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-02 21:53:55.683484 :91D7BB6D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=87 time=3493625156 2025-05-02 21:53:55.683484 :91D7BB6E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:53:55.683485 :91D7BB6F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:53:55.683485 :91D7BB70:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:53:55.683486 :91D7BB71:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:53:55.683486 :91D7BB72:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:53:55.683982 :91D7BB73: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-02 21:54:25.735474 :91D7C5A3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:54:55.777205 :91D7CF77:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:54:55.766 2025-05-02 21:54:55.777207 :91D7CF78:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7552 pso_num=25 pso_serial#=114 2025-05-02 21:54:55.777338 :91D7CF79:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7552 osp_idx=23 osp_ver=72788 osp_pg=0 (spawn #141911) 2025-05-02 21:54:55.777339 :91D7CF7A: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-02 21:54:55.777339 :91D7CF7B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=88 time=3493685250 2025-05-02 21:54:55.777339 :91D7CF7C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:54:55.777340 :91D7CF7D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:54:55.777340 :91D7CF7E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:54:55.777340 :91D7CF7F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:54:55.777341 :91D7CF80:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:54:55.777855 :91D7CF81: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-02 21:55:25.871412 :91D7D960:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:55:55.851965 :91D7E377:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:55:55.841 2025-05-02 21:55:55.851967 :91D7E378:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11020 pso_num=25 pso_serial#=115 2025-05-02 21:55:55.852097 :91D7E379:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11020 osp_idx=23 osp_ver=72789 osp_pg=0 (spawn #141913) 2025-05-02 21:55:55.852098 :91D7E37A: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-02 21:55:55.852099 :91D7E37B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=89 time=3493745328 2025-05-02 21:55:55.852099 :91D7E37C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:55:55.852100 :91D7E37D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:55:55.852100 :91D7E37E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:55:55.852100 :91D7E37F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:55:55.852101 :91D7E380:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:55:55.852580 :91D7E381: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-02 21:56:25.935056 :91D7EE3E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:56:55.967748 :91D7F807:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:56:55.957 2025-05-02 21:56:55.967750 :91D7F808:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=2192 pso_num=25 pso_serial#=116 2025-05-02 21:56:55.967883 :91D7F809:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=2192 osp_idx=23 osp_ver=72790 osp_pg=0 (spawn #141917) 2025-05-02 21:56:55.967883 :91D7F80A: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-02 21:56:55.967884 :91D7F80B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=90 time=3493805437 2025-05-02 21:56:55.967884 :91D7F80C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:56:55.967885 :91D7F80D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:56:55.967885 :91D7F80E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:56:55.967885 :91D7F80F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:56:55.967886 :91D7F810:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:56:55.968368 :91D7F811: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-02 21:57:26.022786 :91D801F6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:57:56.061904 :91D80BB9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:57:56.051 2025-05-02 21:57:56.061906 :91D80BBA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8224 pso_num=25 pso_serial#=117 2025-05-02 21:57:56.062042 :91D80BBB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8224 osp_idx=23 osp_ver=72791 osp_pg=0 (spawn #141919) 2025-05-02 21:57:56.062042 :91D80BBC: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-02 21:57:56.062042 :91D80BBD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=91 time=3493865531 2025-05-02 21:57:56.062043 :91D80BBE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:57:56.062043 :91D80BBF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:57:56.062043 :91D80BC0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:57:56.062044 :91D80BC1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:57:56.062044 :91D80BC2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:57:56.062519 :91D80BC3: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-02 21:58:26.116532 :91D8157D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:58:56.150144 :91D81F14:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:58:56.139 2025-05-02 21:58:56.150146 :91D81F15:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11440 pso_num=25 pso_serial#=118 2025-05-02 21:58:56.150281 :91D81F16:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11440 osp_idx=23 osp_ver=72792 osp_pg=0 (spawn #141921) 2025-05-02 21:58:56.150282 :91D81F17: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-02 21:58:56.150282 :91D81F18:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=92 time=3493925625 2025-05-02 21:58:56.150282 :91D81F19:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:58:56.150283 :91D81F1A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:58:56.150283 :91D81F1B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:58:56.150283 :91D81F1C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:58:56.150284 :91D81F1D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:58:56.150804 :91D81F1E: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-02 21:59:26.238562 :91D82901:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-02 21:59:56.224697 :91D832DF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-02 21:59:56.214 2025-05-02 21:59:56.224699 :91D832E0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12100 pso_num=25 pso_serial#=119 2025-05-02 21:59:56.224828 :91D832E1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12100 osp_idx=23 osp_ver=72793 osp_pg=0 (spawn #141924) 2025-05-02 21:59:56.224829 :91D832E2: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-02 21:59:56.224829 :91D832E3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=93 time=3493985703 2025-05-02 21:59:56.224830 :91D832E4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:59:56.224830 :91D832E5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:59:56.224830 :91D832E6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:59:56.224831 :91D832E7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:59:56.224831 :91D832E8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:59:56.225404 :91D832E9: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-02 22:00:01.229240 :91D83603: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-02 22:00:01.229240*:91D83635:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DDC718 estart=1746194400 eid=16779688 ctx=0x000000077FD6A000 cwh=0x0000000024DD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-02 22:00:01.229240*:91D83636:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 pubTabIdxCnt=0 2025-05-02 22:00:01.229240*:91D83637:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DDC718 2025-05-02 22:00:01.229240*:91D83638:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DDC718 2025-05-02 22:00:01.229240*:91D83645:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 xsc->flg4=65792 flags=2 2025-05-02 22:00:01.229240*:91D83646:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DDC718 2025-05-02 22:00:01.236115 :91D83647: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-02 22:00:01.236172 :91D8364A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-02 22:00:01.248250 :91D83879: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-02 22:00:01.253636 :91D8389F: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-02 22:00:01.254432 :91D838A7: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-02 22:00:01.260281 :91D83943: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-02 22:00:01.260434 :91D83959: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-02 22:00:01.260719 :91D83971:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] 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-02 22:00:01.261308 :91D83993: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-02 22:00:01.261496 :91D839A8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-02 22:00:01.263196 :91D839B6: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-02 22:00:01.263250 :91D839B9: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-02 22:00:01.263315 :91D839C6: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-02 22:00:01.354089 :91D839DF: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-02 22:00:04.015232 :91D83EB8: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 12100, J001)