Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250910220008\orcl_j000_22788_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:34846M/63366M, Ph+PgF:39532M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 22788, image: ORACLE.EXE (J000) *** 2025-09-10 22:00:08.715 *** SESSION ID:(177.31279) 2025-09-10 22:00:08.715 *** 2025-09-10 22:00:08.715 Process diagnostic dump for ORACLE.EXE (J000), OS id=22788, pid: 22, proc_ser: 186, sid: 177, sess_ser: 31279 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 22788 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) 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.194221 sec, exc=0.194221 sec, total=0.194221 sec wait times: max=0.500000 sec, heur=4.695011 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.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 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499995 sec, exc=0.499995 sec, total=0.499995 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 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.000014 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.500008 sec, exc=0.500008 sec, total=0.500008 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 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.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.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.505102 sec, exc=0.505102 sec, total=0.505102 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 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.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.000009 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.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 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.485519 sec, exc=0.485519 sec, total=0.485519 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 31279 --------------------------------------------------- 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:04 - 22:00:08] 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-09-10 22:00:08.715 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 22788, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-10 21:58:06.896494 :CBB3D257:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20116 pso_num=22 pso_serial#=171 2025-09-10 21:58:06.896627 :CBB3D258:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20116 (legacy spawn) 2025-09-10 21:58:06.903111 :CBB3D259: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-09-10 21:58:06.903144 :CBB3D25C: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-09-10 21:58:06.903300 :CBB3D25F: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-09-10 21:58:06.904082 :CBB3D270:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:58:06.912924 :CBB3D273:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:58:06.899 2025-09-10 21:58:06.912927 :CBB3D274:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24240 pso_num=22 pso_serial#=172 2025-09-10 21:58:06.913077 :CBB3D275:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=24240 (legacy spawn) 2025-09-10 21:58:06.919489 :CBB3D28E: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-09-10 21:58:06.919659 :CBB3D297: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-09-10 21:58:06.920508 :CBB3D298:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:58:07.454041 :CBB3D2CF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:58:07.446 2025-09-10 21:58:07.454044 :CBB3D2D0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19144 pso_num=22 pso_serial#=173 2025-09-10 21:58:07.454186 :CBB3D2D1:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19144 (legacy spawn) 2025-09-10 21:58:07.460701 :CBB3D2D2: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-09-10 21:58:07.460872 :CBB3D2D7: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-09-10 21:58:07.461729 :CBB3D2DC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:58:12.498306 :CBB3D43A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:58:12.484 2025-09-10 21:58:12.498308 :CBB3D43B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23664 pso_num=22 pso_serial#=174 2025-09-10 21:58:12.498452 :CBB3D43C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23664 (legacy spawn) 2025-09-10 21:58:12.504912 :CBB3D43D: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-09-10 21:58:12.505091 :CBB3D442: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-09-10 21:58:12.505875 :CBB3D447:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:58:12.514641 :CBB3D44A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:58:12.499 2025-09-10 21:58:12.514643 :CBB3D44B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23668 pso_num=22 pso_serial#=175 2025-09-10 21:58:12.514786 :CBB3D44C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23668 (legacy spawn) 2025-09-10 21:58:12.521306 :CBB3D44D: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-09-10 21:58:12.521463 :CBB3D456: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-09-10 21:58:12.522230 :CBB3D457:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:58:15.814144 :CBB3D57B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:58:15.801 2025-09-10 21:58:15.814147 :CBB3D57C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21524 pso_num=22 pso_serial#=176 2025-09-10 21:58:15.814298 :CBB3D57D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21524 (legacy spawn) 2025-09-10 21:58:15.820754 :CBB3D57E: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-09-10 21:58:15.820918 :CBB3D583: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-09-10 21:58:15.821714 :CBB3D588:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:58:15.830449 :CBB3D58B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:58:15.817 2025-09-10 21:58:15.830451 :CBB3D58C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20988 pso_num=22 pso_serial#=177 2025-09-10 21:58:15.830583 :CBB3D58D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20988 (legacy spawn) 2025-09-10 21:58:15.837077 :CBB3D58E: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-09-10 21:58:15.837252 :CBB3D597: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-09-10 21:58:15.838031 :CBB3D598:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:58:34.586247 :CBB3DB8D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:58:34.580 2025-09-10 21:58:34.586249 :CBB3DB8E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23588 pso_num=22 pso_serial#=178 2025-09-10 21:58:34.586411 :CBB3DB8F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23588 osp_idx=0 osp_ver=593380 osp_pg=0 (spawn #579159) 2025-09-10 21:58:34.586411 :CBB3DB90:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-10 21:58:34.586412 :CBB3DB91:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=92 time=1927165893 2025-09-10 21:58:34.586412 :CBB3DB92:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-10 21:58:34.586413 :CBB3DB93:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-10 21:58:34.586413 :CBB3DB94:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-10 21:58:34.586413 :CBB3DB95:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-10 21:58:34.586414 :CBB3DB96:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-10 21:58:34.586958 :CBB3DB97: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-09-10 21:58:34.587685 :CBB3DBAC: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-09-10 21:58:34.602697 :CBB3DBC8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-10 21:58:34.602783 :CBB3DBC9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-10 21:58:34.603643 :CBB3DBCA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-10 21:58:34.604010 :CBB3DBCB: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-09-10 21:58:34.604053 :CBB3DBCE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-10 21:58:34.612516 :CBB3DBDF: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-09-10 21:58:34.612584 :CBB3DBE2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:ktcc.c:879 2025-09-10 21:58:34.612623 :CBB3DBE3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:ktcc.c:879 2025-09-10 21:58:34.613005 :CBB3DBE9:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-10 21:58:34.613388 :CBB3DBEA:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-10 21:58:34.613583 :CBB3DBEB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-10 21:58:34.613829 :CBB3DBEC: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-09-10 21:58:34.613861 :CBB3DBEF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-10 21:58:34.615590 :CBB3DBF5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-10 21:58:34.615841 :CBB3DBF6: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-09-10 21:58:34.615877 :CBB3DBF9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-10 21:58:34.616845 :CBB3DBFF: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-09-10 21:59:04.686007 :CBB3E5F9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:09.651628 :CBB3E783:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:09.638 2025-09-10 21:59:09.651630 :CBB3E784:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18848 pso_num=22 pso_serial#=179 2025-09-10 21:59:09.651770 :CBB3E785:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=18848 (legacy spawn) 2025-09-10 21:59:09.671493 :CBB3E786: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-09-10 21:59:09.671654 :CBB3E78B: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-09-10 21:59:09.672668 :CBB3E790:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:13.228401 :CBB3E902:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:13.220 2025-09-10 21:59:13.228404 :CBB3E903:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21264 pso_num=22 pso_serial#=180 2025-09-10 21:59:13.228539 :CBB3E904:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21264 (legacy spawn) 2025-09-10 21:59:13.235033 :CBB3E905: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-09-10 21:59:13.235195 :CBB3E90E: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-09-10 21:59:13.235988 :CBB3E90F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:18.622731 :CBB3EA66:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:18.614 2025-09-10 21:59:18.622733 :CBB3EA67:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23632 pso_num=22 pso_serial#=181 2025-09-10 21:59:18.622878 :CBB3EA68:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23632 (legacy spawn) 2025-09-10 21:59:18.629770 :CBB3EA69: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-09-10 21:59:18.629968 :CBB3EA72: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-09-10 21:59:18.630867 :CBB3EA73:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:25.488930 :CBB3ECDE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:25.474 2025-09-10 21:59:25.488932 :CBB3ECDF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21996 pso_num=22 pso_serial#=182 2025-09-10 21:59:25.489066 :CBB3ECE0:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21996 (legacy spawn) 2025-09-10 21:59:25.495530 :CBB3ECE1: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-09-10 21:59:25.495699 :CBB3ECE8: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-09-10 21:59:25.496494 :CBB3ECEB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:25.505160 :CBB3ECEE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:25.490 2025-09-10 21:59:25.505162 :CBB3ECEF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18948 pso_num=22 pso_serial#=183 2025-09-10 21:59:25.505297 :CBB3ECF0:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=18948 (legacy spawn) 2025-09-10 21:59:25.511776 :CBB3ECF1: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-09-10 21:59:25.511938 :CBB3ECFA: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-09-10 21:59:25.512731 :CBB3ECFB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:28.623995 :CBB3EDE5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:28.615 2025-09-10 21:59:28.623997 :CBB3EDE6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23824 pso_num=22 pso_serial#=184 2025-09-10 21:59:28.624129 :CBB3EDE7:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23824 (legacy spawn) 2025-09-10 21:59:28.631376 :CBB3EDE8: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-09-10 21:59:28.631542 :CBB3EDF0: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-09-10 21:59:28.632338 :CBB3EDF2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:28.641053 :CBB3EDF5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:28.631 2025-09-10 21:59:28.641055 :CBB3EDF6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16524 pso_num=22 pso_serial#=185 2025-09-10 21:59:28.641193 :CBB3EDF7:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=16524 (legacy spawn) 2025-09-10 21:59:28.647689 :CBB3EDF8: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-09-10 21:59:28.647858 :CBB3EE01: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-09-10 21:59:28.648683 :CBB3EE02:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-10 21:59:34.640471 :CBB3EFF1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-10 21:59:34.634 2025-09-10 21:59:34.640473 :CBB3EFF2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22788 pso_num=22 pso_serial#=186 2025-09-10 21:59:34.640603 :CBB3EFF3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22788 osp_idx=0 osp_ver=593388 osp_pg=0 (spawn #579162) 2025-09-10 21:59:34.640603 :CBB3EFF4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-10 21:59:34.640604 :CBB3EFF5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=93 time=1927225940 2025-09-10 21:59:34.640604 :CBB3EFF6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-10 21:59:34.640605 :CBB3EFF7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-10 21:59:34.640605 :CBB3EFF8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-10 21:59:34.640605 :CBB3EFF9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-10 21:59:34.640606 :CBB3EFFA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-10 21:59:34.641140 :CBB3EFFB: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-09-10 21:59:34.641819 :CBB3F010: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-09-10 21:59:34.649303 :CBB3F02C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-10 21:59:34.649682 :CBB3F02D: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-09-10 21:59:34.649716 :CBB3F030:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-10 21:59:34.650591 :CBB3F036: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-09-10 21:59:34.650708 :CBB3F03F: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-09-10 22:00:02.027072 :CBB3FA5B: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-09-10 22:00:02.027072*:CBB3FA6B:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1757512801 eid=16787747 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-09-10 22:00:02.027072*:CBB3FA6C:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-09-10 22:00:02.027072*:CBB3FA6D:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-09-10 22:00:02.027072*:CBB3FA6E:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-09-10 22:00:02.027072*:CBB3FA6F:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-09-10 22:00:02.027072*:CBB3FA70:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-09-10 22:00:02.032797 :CBB3FA87: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-09-10 22:00:02.032842 :CBB3FA90:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-09-10 22:00:02.044187 :CBB3FC30: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-09-10 22:00:02.049189 :CBB3FC4D: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-09-10 22:00:02.050038 :CBB3FC70: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-09-10 22:00:02.056039 :CBB3FCC4: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-09-10 22:00:02.056192 :CBB3FCDB: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-09-10 22:00:02.056437 :CBB3FCEE: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-09-10 22:00:02.056903 :CBB3FD05: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-09-10 22:00:02.057101 :CBB3FD0D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-09-10 22:00:02.058331 :CBB3FD31: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-09-10 22:00:02.058759 :CBB3FD4B: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-09-10 22:00:02.058799 :CBB3FD4D: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-09-10 22:00:02.058830 :CBB3FD54: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-09-10 22:00:02.058891 :CBB3FD61: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-09-10 22:00:02.152046 :CBB3FDBD: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-09-10 22:00:02.154155 :CBB3FDC1: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-09-10 22:00:02.154207 :CBB3FDC4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-09-10 22:00:02.156708 :CBB3FDCA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-09-10 22:00:02.160082 :CBB3FDCB: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-09-10 22:00:02.160163 :CBB3FDCE: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-09-10 22:00:02.160247 :CBB3FDDB: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-09-10 22:00:04.013155 :CBB401C4: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-09-10 22:00:04.013155*:CBB401C6:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1757512803 eid=16787753 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-09-10 22:00:04.013155*:CBB401C7:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-09-10 22:00:04.013155*:CBB401C8:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-09-10 22:00:04.013155*:CBB401C9:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-09-10 22:00:04.013155*:CBB401CA:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-09-10 22:00:04.013155*:CBB401CB:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-09-10 22:00:04.015514 :CBB401CC: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-09-10 22:00:04.015549 :CBB401CF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-09-10 22:00:04.022666 :CBB401D5: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-09-10 22:00:04.023359 :CBB401DD: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-09-10 22:00:04.024058 :CBB401E5: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-09-10 22:00:04.024274 :CBB401ED:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-09-10 22:00:04.026033 :CBB401EE: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-09-10 22:00:04.026073 :CBB401F1: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-09-10 22:00:04.026196 :CBB401FE: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: 22788, J000)