Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250902220008\orcl_j001_22056_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:35009M/63366M, Ph+PgF:39936M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 22056, image: ORACLE.EXE (J001) *** 2025-09-02 22:00:08.750 *** SESSION ID:(193.25189) 2025-09-02 22:00:08.750 *** 2025-09-02 22:00:08.750 Process diagnostic dump for ORACLE.EXE (J001), OS id=22056, pid: 24, proc_ser: 5, sid: 193, sess_ser: 25189 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 22056 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=0.237052 sec, exc=0.237052 sec, total=0.237052 sec wait times: max=0.500000 sec, heur=7.580773 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.000012 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 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=14 seq_num=15 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.000011 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 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.000012 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.500000 sec, exc=0.500000 sec, total=0.500000 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.499980 sec, exc=0.499980 sec, total=0.499980 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=10 seq_num=11 snap_id=1 wait times: snap=0.510143 sec, exc=0.510143 sec, total=0.510143 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499985 sec, exc=0.499985 sec, total=0.499985 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000016 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499278 sec, exc=0.499278 sec, total=0.499278 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.219473 sec, exc=0.219473 sec, total=0.219473 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time Sampled Session History of session 193 serial 25189 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [8 samples, 22:00:01 - 22:00:08] 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-09-02 22:00:08.750 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 22056, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-02 21:50:15.230079 :C826E5FF:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=21936 pso_num=24 pso_serial#=250 2025-09-02 21:50:15.230230 :C826E600:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=21936 osp_idx=22 osp_ver=832159 osp_pg=0 (spawn #552468) 2025-09-02 21:50:15.230230 :C826E601:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:50:15.230231 :C826E602:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=113 time=1235466533 2025-09-02 21:50:15.230231 :C826E603:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:50:15.230232 :C826E604:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:50:15.230232 :C826E605:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:50:15.230232 :C826E606:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:50:15.230233 :C826E607:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:50:15.230847 :C826E608: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-09-02 21:50:30.252644 :C826EABC: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-09-02 21:51:00.322330 :C826F478:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:51:30.369658 :C826FE44:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:51:30.359 2025-09-02 21:51:30.369660 :C826FE45:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=17956 pso_num=24 pso_serial#=251 2025-09-02 21:51:30.369789 :C826FE46:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=17956 osp_idx=22 osp_ver=832160 osp_pg=0 (spawn #552470) 2025-09-02 21:51:30.369790 :C826FE47:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:51:30.369790 :C826FE48:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=114 time=1235541674 2025-09-02 21:51:30.369790 :C826FE49:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:51:30.369791 :C826FE4A:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:51:30.369791 :C826FE4B:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:51:30.369791 :C826FE4C:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:51:30.369792 :C826FE4D:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:51:30.370298 :C826FE4E: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-09-02 21:52:00.415074 :C827087C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:52:30.435241 :C8271266:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:52:30.423 2025-09-02 21:52:30.435244 :C8271267:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22684 pso_num=24 pso_serial#=252 2025-09-02 21:52:30.435368 :C8271268:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22684 osp_idx=22 osp_ver=832161 osp_pg=0 (spawn #552472) 2025-09-02 21:52:30.435368 :C8271269:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:52:30.435369 :C827126A:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=115 time=1235601737 2025-09-02 21:52:30.435369 :C827126B:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:52:30.435370 :C827126C:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:52:30.435370 :C827126D:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:52:30.435370 :C827126E:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:52:30.435370 :C827126F:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:52:30.435895 :C8271270: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-09-02 21:53:00.502654 :C8271BDB:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:53:13.154625 :C8272071:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:53:13.142 2025-09-02 21:53:13.154627 :C8272072:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=6744 pso_num=24 pso_serial#=253 2025-09-02 21:53:13.154758 :C8272073:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=6744 osp_idx=22 osp_ver=832162 osp_pg=0 (spawn #552474) 2025-09-02 21:53:13.154759 :C8272074:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:53:13.154759 :C8272075:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=116 time=1235644455 2025-09-02 21:53:13.154760 :C8272076:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:53:13.154760 :C8272077:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:53:13.154760 :C8272078:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:53:13.154761 :C8272079:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:53:13.154761 :C827207A:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:53:13.155252 :C827207B: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-09-02 21:53:13.155295 :C8272081: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-09-02 21:53:13.159396 :C827209A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-09-02 21:53:13.159439 :C827209B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-09-02 21:53:13.159686 :C827209C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-09-02 21:53:13.159702 :C827209D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-09-02 21:53:13.159967 :C827209E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-09-02 21:53:13.159989 :C827209F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-09-02 21:53:13.160221 :C82720A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-09-02 21:53:13.160235 :C82720A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-09-02 21:53:13.160448 :C82720A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-09-02 21:53:13.160465 :C82720A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-09-02 21:53:13.160673 :C82720A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:kelt.c:517 2025-09-02 21:53:13.160686 :C82720A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:kelt.c:517 2025-09-02 21:53:13.162916 :C82720A6:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:53:30.538552 :C827262C:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:53:30.527 2025-09-02 21:53:30.538554 :C827262D:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18948 pso_num=24 pso_serial#=254 2025-09-02 21:53:30.538673 :C827262E:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=18948 osp_idx=22 osp_ver=832163 osp_pg=0 (spawn #552476) 2025-09-02 21:53:30.538674 :C827262F:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:53:30.538674 :C8272630:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=117 time=1235661830 2025-09-02 21:53:30.538675 :C8272631:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:53:30.538676 :C8272632:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:53:30.538676 :C8272633:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:53:30.538676 :C8272634:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:53:30.538677 :C8272635:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:53:30.539163 :C8272636: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-09-02 21:54:00.625791 :C8273072:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:54:30.637113 :C8273A16:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:54:30.626 2025-09-02 21:54:30.637115 :C8273A17:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22412 pso_num=24 pso_serial#=255 2025-09-02 21:54:30.637253 :C8273A18:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22412 osp_idx=22 osp_ver=832164 osp_pg=0 (spawn #552478) 2025-09-02 21:54:30.637253 :C8273A19:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:54:30.637254 :C8273A1A:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=118 time=1235721940 2025-09-02 21:54:30.637254 :C8273A1B:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:54:30.637254 :C8273A1C:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:54:30.637254 :C8273A1D:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:54:30.637255 :C8273A1E:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:54:30.637255 :C8273A1F:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:54:30.637721 :C8273A20: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-09-02 21:55:00.699194 :C82743BE:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:55:30.711477 :C8274DB3:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:55:30.700 2025-09-02 21:55:30.711480 :C8274DB4:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22932 pso_num=24 pso_serial#=1 2025-09-02 21:55:30.711613 :C8274DB5:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22932 osp_idx=22 osp_ver=832165 osp_pg=0 (spawn #552480) 2025-09-02 21:55:30.711614 :C8274DB6:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:55:30.711615 :C8274DB7:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=119 time=1235782002 2025-09-02 21:55:30.711615 :C8274DB8:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:55:30.711615 :C8274DB9:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:55:30.711615 :C8274DBA:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:55:30.711616 :C8274DBB:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:55:30.711616 :C8274DBC:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:55:30.712094 :C8274DBD: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-09-02 21:56:00.800192 :C8275761:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:56:30.801970 :C827616E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:56:30.791 2025-09-02 21:56:30.801972 :C827616F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22996 pso_num=24 pso_serial#=2 2025-09-02 21:56:30.802093 :C8276170:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22996 osp_idx=22 osp_ver=832166 osp_pg=0 (spawn #552483) 2025-09-02 21:56:30.802094 :C8276171:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:56:30.802095 :C8276172:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=120 time=1235842096 2025-09-02 21:56:30.802095 :C8276173:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:56:30.802096 :C8276174:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:56:30.802096 :C8276175:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:56:30.802096 :C8276176:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:56:30.802096 :C8276177:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:56:30.802602 :C8276178: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-09-02 21:57:00.885855 :C8276B55:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:57:30.922889 :C8277547:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:57:30.911 2025-09-02 21:57:30.922891 :C8277548:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=20968 pso_num=24 pso_serial#=3 2025-09-02 21:57:30.923006 :C8277549:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=20968 osp_idx=22 osp_ver=832167 osp_pg=0 (spawn #552485) 2025-09-02 21:57:30.923007 :C827754A:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:57:30.923007 :C827754B:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=121 time=1235902221 2025-09-02 21:57:30.923008 :C827754C:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:57:30.923008 :C827754D:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:57:30.923008 :C827754E:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:57:30.923009 :C827754F:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:57:30.923009 :C8277550:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:57:30.923529 :C8277551: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-09-02 21:58:00.982995 :C8277F23:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:58:31.009946 :C82788F6:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:58:30.999 2025-09-02 21:58:31.009947 :C82788F7:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=21996 pso_num=24 pso_serial#=4 2025-09-02 21:58:31.010076 :C82788F8:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=21996 osp_idx=22 osp_ver=832168 osp_pg=0 (spawn #552487) 2025-09-02 21:58:31.010077 :C82788F9:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:58:31.010077 :C82788FA:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=122 time=1235962315 2025-09-02 21:58:31.010077 :C82788FB:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:58:31.010078 :C82788FC:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:58:31.010079 :C82788FD:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:58:31.010079 :C82788FE:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:58:31.010079 :C82788FF:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:58:31.010549 :C8278900: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-09-02 21:59:01.104695 :C8279346:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-02 21:59:31.091699 :C8279D13:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-02 21:59:31.080 2025-09-02 21:59:31.091701 :C8279D14:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22056 pso_num=24 pso_serial#=5 2025-09-02 21:59:31.091843 :C8279D15:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22056 osp_idx=22 osp_ver=832169 osp_pg=0 (spawn #552489) 2025-09-02 21:59:31.091843 :C8279D16:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-02 21:59:31.091843 :C8279D17:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=123 time=1236022393 2025-09-02 21:59:31.091844 :C8279D18:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-02 21:59:31.091844 :C8279D19:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-02 21:59:31.091845 :C8279D1A:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-02 21:59:31.091845 :C8279D1B:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-02 21:59:31.091845 :C8279D1C:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-02 21:59:31.092336 :C8279D1D: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-09-02 22:00:01.148233 :C827A83B: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-09-02 22:00:01.148233*:C827A85A:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024D5B898 estart=1756821601 eid=16787259 ctx=0x000000077FD6A000 cwh=0x0000000024D50068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-09-02 22:00:01.148233*:C827A85B:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024D5B898 curCtx=0x0000000024D57AB8 pubTabIdxCnt=0 2025-09-02 22:00:01.148233*:C827A85C:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024D5B898 2025-09-02 22:00:01.148233*:C827A85D:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024D5B898 2025-09-02 22:00:01.154118 :C827A870: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-09-02 22:00:01.154118*:C827A87E:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024D5B898 curCtx=0x0000000024D57AB8 xsc->flg4=65792 flags=2 2025-09-02 22:00:01.154118*:C827A87F:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024D5B898 2025-09-02 22:00:01.155114 :C827A880: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-09-02 22:00:01.155164 :C827A883:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-09-02 22:00:01.160460 :C827A8B1:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-09-02 22:00:01.161062 :C827A8B2:db_trace:kcc.c@13684:kccwbp(): [10021:24:193:1] 0115000000000000 0115000000000000 34a7120000000000 2025-09-02 22:00:01.162658 :C827A8B3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-09-02 22:00:01.162751 :C827A8C1:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-02 22:00:01.162760 :C827A8C7:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-09-02 22:00:01.162764 :C827A8C8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-02 22:00:01.162842 :C827A8DF:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-02 22:00:01.164034 :C827A8E0:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 236327817) 2025-09-02 22:00:01.164041 :C827A8E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-02 22:00:01.164067 :C827A8EC:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-02 22:00:01.164075 :C827A8F9:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65560 1) 2025-09-02 22:00:01.164078 :C827A8FA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-02 22:00:01.164109 :C827A906:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-02 22:00:01.164113 :C827A90E:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65560) 2025-09-02 22:00:01.164115 :C827A912:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-02 22:00:01.164157 :C827A931:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-02 22:00:01.164994 :C827A9FB:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-02 22:00:01.165013 :C827AA03:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-09-02 22:00:01.165836 :C827AA1C:db_trace:kcc.c@13684:kccwbp(): [10021:24:193:1] 0115000000000000 0115000000000000 35a7120000000000 2025-09-02 22:00:01.166208 :C827AA32:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 236327817) 2025-09-02 22:00:01.166214 :C827AA33:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-02 22:00:01.166238 :C827AA3E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-02 22:00:01.175159 :C827AA8D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-09-02 22:00:01.176918 :C827AAB1: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-09-02 22:00:01.176960 :C827AAB3: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-09-02 22:00:01.177008 :C827AACB: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-09-02 22:00:01.272973 :C827ABB5: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-09-02 22:00:04.012341 :C827B030: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: 22056, J001)