Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250805220009\orcl_j000_18312_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:35685M/63366M, Ph+PgF:41205M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 18312, image: ORACLE.EXE (J000) *** 2025-08-05 22:00:09.439 *** SESSION ID:(177.37587) 2025-08-05 22:00:09.439 *** 2025-08-05 22:00:09.439 Process diagnostic dump for ORACLE.EXE (J000), OS id=18312, pid: 22, proc_ser: 131, sid: 177, sess_ser: 37587 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 18312 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.414949 sec, exc=0.414949 sec, total=0.414949 sec wait times: max=0.500000 sec, heur=5.431631 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.000013 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 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.000016 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499981 sec, exc=0.499981 sec, total=0.499981 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000015 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.510283 sec, exc=0.510283 sec, total=0.510283 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=6 seq_num=7 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 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.000009 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.510104 sec, exc=0.510104 sec, total=0.510104 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.510101 sec, exc=0.510101 sec, total=0.510101 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=2 seq_num=3 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499972 sec, exc=0.499972 sec, total=0.499972 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.486143 sec, exc=0.486143 sec, total=0.486143 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 177 serial 37587 --------------------------------------------------- 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 --------------------------------------------------- [6 samples, 22:00:04 - 22:00:09] idle wait at each sample [session created at: 22:00:04] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-05 22:00:09.439 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 18312, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-05 21:57:53.426740 :BBD7A0A5:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19852 (legacy spawn) 2025-08-05 21:57:53.433224 :BBD7A0A6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:57:53.433388 :BBD7A0AB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:57:53.434208 :BBD7A0B0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:57:57.319130 :BBD7A1DD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:57:57.313 2025-08-05 21:57:57.319131 :BBD7A1DE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16084 pso_num=22 pso_serial#=117 2025-08-05 21:57:57.319271 :BBD7A1DF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16084 osp_idx=0 osp_ver=484689 osp_pg=0 (spawn #459144) 2025-08-05 21:57:57.319272 :BBD7A1E0:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-05 21:57:57.319273 :BBD7A1E1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=117 time=3111746626 2025-08-05 21:57:57.319273 :BBD7A1E2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-05 21:57:57.319273 :BBD7A1E3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-05 21:57:57.319274 :BBD7A1E4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-05 21:57:57.319274 :BBD7A1E5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-05 21:57:57.319274 :BBD7A1E6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-05 21:57:57.319762 :BBD7A1E7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-05 21:57:57.320394 :BBD7A1FC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:57:57.327931 :BBD7A218:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-05 21:57:57.328295 :BBD7A219:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:57:57.328331 :BBD7A21C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-05 21:57:57.329179 :BBD7A222:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:57:57.329308 :BBD7A22B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:58:27.426150 :BBD7ABCE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:58:27.528711 :BBD7ABE9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:58:27.519 2025-08-05 21:58:27.528712 :BBD7ABEA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19576 pso_num=22 pso_serial#=118 2025-08-05 21:58:27.528853 :BBD7ABEB:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19576 (legacy spawn) 2025-08-05 21:58:27.535360 :BBD7ABEC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:27.535530 :BBD7ABF1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:58:27.536346 :BBD7ABF6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:58:37.680212 :BBD7AF37:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:58:37.666 2025-08-05 21:58:37.680214 :BBD7AF38:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19972 pso_num=22 pso_serial#=119 2025-08-05 21:58:37.680353 :BBD7AF39:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19972 (legacy spawn) 2025-08-05 21:58:37.686869 :BBD7AF3A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:37.687051 :BBD7AF41:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:58:37.687890 :BBD7AF44:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:58:37.696582 :BBD7AF47:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:58:37.681 2025-08-05 21:58:37.696584 :BBD7AF48:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19212 pso_num=22 pso_serial#=120 2025-08-05 21:58:37.696761 :BBD7AF49:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19212 (legacy spawn) 2025-08-05 21:58:37.703287 :BBD7AF4A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:37.703448 :BBD7AF53:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:58:37.704231 :BBD7AF54:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:58:40.881270 :BBD7B047:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:58:40.868 2025-08-05 21:58:40.881272 :BBD7B048:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11076 pso_num=22 pso_serial#=121 2025-08-05 21:58:40.881409 :BBD7B049:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11076 (legacy spawn) 2025-08-05 21:58:40.903706 :BBD7B04A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:40.903736 :BBD7B04D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:40.903882 :BBD7B054:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:58:40.904698 :BBD7B061:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:58:40.913526 :BBD7B064:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:58:40.900 2025-08-05 21:58:40.913528 :BBD7B065:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=1400 pso_num=22 pso_serial#=122 2025-08-05 21:58:40.913700 :BBD7B066:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=1400 (legacy spawn) 2025-08-05 21:58:40.920106 :BBD7B067:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:40.920276 :BBD7B070:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:58:40.921112 :BBD7B071:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:58:54.156227 :BBD7B477:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:58:54.148 2025-08-05 21:58:54.156229 :BBD7B478:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19680 pso_num=22 pso_serial#=123 2025-08-05 21:58:54.156374 :BBD7B479:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19680 (legacy spawn) 2025-08-05 21:58:54.163022 :BBD7B47A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:54.163217 :BBD7B47F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:58:54.164096 :BBD7B484:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:58:57.393350 :BBD7B5A2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:58:57.387 2025-08-05 21:58:57.393352 :BBD7B5A3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18820 pso_num=22 pso_serial#=124 2025-08-05 21:58:57.393485 :BBD7B5A4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18820 osp_idx=0 osp_ver=484696 osp_pg=0 (spawn #459146) 2025-08-05 21:58:57.393486 :BBD7B5A5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-05 21:58:57.393486 :BBD7B5A6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=118 time=3111806704 2025-08-05 21:58:57.393487 :BBD7B5A7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-05 21:58:57.393487 :BBD7B5A8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-05 21:58:57.393488 :BBD7B5A9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-05 21:58:57.393488 :BBD7B5AA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-05 21:58:57.393488 :BBD7B5AB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-05 21:58:57.394018 :BBD7B5AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-05 21:58:57.394672 :BBD7B5C1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:57.405788 :BBD7B5DD:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-05 21:58:57.406264 :BBD7B5DE:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-05 21:58:57.408563 :BBD7B5DF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-05 21:58:57.408909 :BBD7B5E0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:57.408945 :BBD7B5E3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-05 21:58:57.409859 :BBD7B5E9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:58:57.410002 :BBD7B5F2:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:59:27.488633 :BBD7C015:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:59:35.632136 :BBD7C28D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:59:35.623 2025-08-05 21:59:35.632138 :BBD7C28E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19796 pso_num=22 pso_serial#=125 2025-08-05 21:59:35.632280 :BBD7C28F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19796 (legacy spawn) 2025-08-05 21:59:35.638786 :BBD7C290:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:35.638954 :BBD7C295:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:59:35.639755 :BBD7C29A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:59:50.383282 :BBD7C73F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:59:50.369 2025-08-05 21:59:50.383285 :BBD7C740:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12568 pso_num=22 pso_serial#=126 2025-08-05 21:59:50.383469 :BBD7C741:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12568 (legacy spawn) 2025-08-05 21:59:50.389909 :BBD7C742:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:50.390094 :BBD7C74B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:59:50.390914 :BBD7C74C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:59:50.399594 :BBD7C74F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:59:50.400 2025-08-05 21:59:50.399596 :BBD7C750:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18616 pso_num=22 pso_serial#=127 2025-08-05 21:59:50.399734 :BBD7C751:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=18616 (legacy spawn) 2025-08-05 21:59:50.406164 :BBD7C752:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:50.406336 :BBD7C757:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:59:50.407130 :BBD7C75C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:59:53.494659 :BBD7C852:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:59:53.488 2025-08-05 21:59:53.494662 :BBD7C853:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20368 pso_num=22 pso_serial#=128 2025-08-05 21:59:53.494838 :BBD7C854:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20368 (legacy spawn) 2025-08-05 21:59:53.501177 :BBD7C855:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:53.597031 :BBD7C858:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:53.624381 :BBD7C860:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:59:53.625395 :BBD7C86C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:59:53.634322 :BBD7C86F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:59:53.629 2025-08-05 21:59:53.634324 :BBD7C870:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20316 pso_num=22 pso_serial#=129 2025-08-05 21:59:53.634470 :BBD7C871:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20316 (legacy spawn) 2025-08-05 21:59:53.641037 :BBD7C872:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:53.641201 :BBD7C87B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:59:53.642048 :BBD7C87C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:59:56.328781 :BBD7C96D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:59:56.321 2025-08-05 21:59:56.328782 :BBD7C96E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9700 pso_num=22 pso_serial#=130 2025-08-05 21:59:56.328914 :BBD7C96F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9700 (legacy spawn) 2025-08-05 21:59:56.335398 :BBD7C970:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:56.335577 :BBD7C975:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 21:59:56.336393 :BBD7C97A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-05 21:59:57.508279 :BBD7C9DF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-05 21:59:57.503 2025-08-05 21:59:57.508281 :BBD7C9E0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18312 pso_num=22 pso_serial#=131 2025-08-05 21:59:57.508423 :BBD7C9E1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18312 osp_idx=0 osp_ver=484703 osp_pg=0 (spawn #459148) 2025-08-05 21:59:57.508424 :BBD7C9E2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-05 21:59:57.508425 :BBD7C9E3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=119 time=3111866814 2025-08-05 21:59:57.508425 :BBD7C9E4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-05 21:59:57.508425 :BBD7C9E5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-05 21:59:57.508426 :BBD7C9E6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-05 21:59:57.508426 :BBD7C9E7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-05 21:59:57.508426 :BBD7C9E8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-05 21:59:57.508911 :BBD7C9E9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-05 21:59:57.509553 :BBD7C9FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:57.517147 :BBD7CA1A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-05 21:59:57.517529 :BBD7CA1B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:57.517568 :BBD7CA1E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-05 21:59:57.518441 :BBD7CA24:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 21:59:57.518559 :BBD7CA2C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 22:00:02.039152 :BBD7CD7C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-05 22:00:02.039152*:BBD7CD9E:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1754402401 eid=16785537 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-05 22:00:02.039152*:BBD7CD9F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-08-05 22:00:02.039152*:BBD7CDA0:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-08-05 22:00:02.039152*:BBD7CDA1:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-08-05 22:00:02.044858 :BBD7CDA8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] 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-08-05 22:00:02.044858*:BBD7CDC1:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-08-05 22:00:02.044858*:BBD7CDC2:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-08-05 22:00:02.045938 :BBD7CDC3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.045990 :BBD7CDC6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-08-05 22:00:02.057389 :BBD7CF71:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.062339 :BBD7CF94:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.063154 :BBD7CFA6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.068761 :BBD7CFFD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.068911 :BBD7D014:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.069187 :BBD7D027:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] 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-08-05 22:00:02.069677 :BBD7D03E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.069990 :BBD7D05B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-08-05 22:00:02.071406 :BBD7D097:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] 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-08-05 22:00:02.071449 :BBD7D099:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.071483 :BBD7D0A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.071581 :BBD7D0B2:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 22:00:02.164106 :BBD7D0FD:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-05 22:00:02.166262 :BBD7D103:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.166304 :BBD7D106:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-08-05 22:00:02.168809 :BBD7D10C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-08-05 22:00:02.172190 :BBD7D10D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.172267 :BBD7D110:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-05 22:00:02.172358 :BBD7D11D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-05 22:00:04.002252 :BBD7D517:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-05 22:00:04.002252*:BBD7D519:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1754402403 eid=16785542 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-05 22:00:04.002252*:BBD7D51A:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-08-05 22:00:04.002252*:BBD7D51B:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-08-05 22:00:04.002252*:BBD7D51C:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-08-05 22:00:04.002252*:BBD7D51D:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-08-05 22:00:04.002252*:BBD7D51E:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-08-05 22:00:04.004499 :BBD7D51F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:04.004544 :BBD7D522:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-08-05 22:00:04.011304 :BBD7D528:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:04.011991 :BBD7D530:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:04.012706 :BBD7D538:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:04.012914 :BBD7D540:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-08-05 22:00:04.014299 :BBD7D541:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-05 22:00:04.014343 :BBD7D544:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-05 22:00:04.014447 :BBD7D551:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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 22 (osid: 18312, J000)