Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250522220008\orcl_j000_13940_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:37315M/63366M, Ph+PgF:44362M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13940, image: ORACLE.EXE (J000) *** 2025-05-22 22:00:08.334 *** SESSION ID:(177.5775) 2025-05-22 22:00:08.334 *** 2025-05-22 22:00:08.334 Process diagnostic dump for ORACLE.EXE (J000), OS id=13940, pid: 22, proc_ser: 89, sid: 177, sess_ser: 5775 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13940 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.322258 sec, exc=0.322258 sec, total=0.322258 sec wait times: max=0.500000 sec, heur=4.318512 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.000018 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.500006 sec, exc=0.500006 sec, total=0.500006 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.499987 sec, exc=0.499987 sec, total=0.499987 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.500011 sec, exc=0.500011 sec, total=0.500011 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499990 sec, exc=0.499990 sec, total=0.499990 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.510098 sec, exc=0.510098 sec, total=0.510098 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499970 sec, exc=0.499970 sec, total=0.499970 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000017 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.500018 sec, exc=0.500018 sec, total=0.500018 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=0 seq_num=1 snap_id=1 wait times: snap=0.486079 sec, exc=0.486079 sec, total=0.486079 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 5775 --------------------------------------------------- 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-05-22 22:00:08.334 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13940, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-22 21:57:35.135553 :9AAA0D9D: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-05-22 21:57:35.135722 :9AAA0DA5: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-05-22 21:57:35.136508 :9AAA0DA7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:57:37.920562 :9AAA0E4F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:57:37.914 2025-05-22 21:57:37.920564 :9AAA0E50:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13588 pso_num=22 pso_serial#=76 2025-05-22 21:57:37.920702 :9AAA0E51:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13588 osp_idx=0 osp_ver=227536 osp_pg=0 (spawn #209165) 2025-05-22 21:57:37.920703 :9AAA0E52:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:57:37.920703 :9AAA0E53:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=242 time=926832813 2025-05-22 21:57:37.920703 :9AAA0E54:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:57:37.920704 :9AAA0E55:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:57:37.920704 :9AAA0E56:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:57:37.920704 :9AAA0E57:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:57:37.920705 :9AAA0E58:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:57:37.921235 :9AAA0E59: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-05-22 21:57:37.921874 :9AAA0E6E: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-05-22 21:57:37.929423 :9AAA0E8A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-22 21:57:37.929847 :9AAA0E8B: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-05-22 21:57:37.929884 :9AAA0E8E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-22 21:57:37.930769 :9AAA0E94: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-05-22 21:57:37.930889 :9AAA0E9D: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-05-22 21:58:08.042643 :9AAA17E0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:58:08.217205 :9AAA1833:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:58:08.214 2025-05-22 21:58:08.217208 :9AAA1834:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8316 pso_num=22 pso_serial#=77 2025-05-22 21:58:08.217344 :9AAA1835:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8316 (legacy spawn) 2025-05-22 21:58:08.223794 :9AAA1836: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-05-22 21:58:08.223964 :9AAA183C: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-05-22 21:58:08.224802 :9AAA1840:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:58:08.233283 :9AAA1843:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:58:08.229 2025-05-22 21:58:08.233285 :9AAA1844:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13764 pso_num=22 pso_serial#=78 2025-05-22 21:58:08.233418 :9AAA1845:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13764 (legacy spawn) 2025-05-22 21:58:08.239901 :9AAA1846: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-05-22 21:58:08.240068 :9AAA184F: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-05-22 21:58:08.240881 :9AAA1850:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:58:11.477799 :9AAA1931:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:58:11.464 2025-05-22 21:58:11.477802 :9AAA1932:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10540 pso_num=22 pso_serial#=79 2025-05-22 21:58:11.477931 :9AAA1933:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10540 (legacy spawn) 2025-05-22 21:58:11.484373 :9AAA1934: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-05-22 21:58:11.484543 :9AAA1939: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-05-22 21:58:11.485346 :9AAA193E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:58:11.494019 :9AAA1941:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:58:11.480 2025-05-22 21:58:11.494021 :9AAA1942:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9360 pso_num=22 pso_serial#=80 2025-05-22 21:58:11.494160 :9AAA1943:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9360 (legacy spawn) 2025-05-22 21:58:11.500666 :9AAA1944: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-05-22 21:58:11.500824 :9AAA194D: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-05-22 21:58:11.501612 :9AAA194E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:58:12.988748 :9AAA19D7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:58:12.983 2025-05-22 21:58:12.988751 :9AAA19D8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12012 pso_num=22 pso_serial#=81 2025-05-22 21:58:12.988940 :9AAA19D9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12012 osp_idx=0 osp_ver=227541 osp_pg=0 (spawn #209167) 2025-05-22 21:58:12.988940 :9AAA19DA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:58:12.988941 :9AAA19DB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=243 time=926867891 2025-05-22 21:58:12.988941 :9AAA19DC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:58:12.988942 :9AAA19DD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:58:12.988942 :9AAA19DE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:58:12.988942 :9AAA19DF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:58:12.988943 :9AAA19E0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:58:12.989434 :9AAA19E1: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-05-22 21:58:12.990082 :9AAA19F6: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-05-22 21:58:12.995574 :9AAA1A12: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-05-22 21:58:12.996539 :9AAA1A1A: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-05-22 21:58:12.996665 :9AAA1A23: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-05-22 21:58:38.026276 :9AAA2194: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-05-22 21:58:38.026298*:9AAA2199:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCCBB58 estart=1747922317 eid=16873109 ctx=0x000000077BD98A08 cwh=0x000000000FC802A0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-22 21:58:38.026298*:9AAA219A:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCCBB58 curCtx=0x000000000FC8F300 pubTabIdxCnt=0 2025-05-22 21:58:38.026298*:9AAA219B:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCCBB58 2025-05-22 21:58:38.026298*:9AAA219C:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCCBB58 2025-05-22 21:58:38.026298*:9AAA219D:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCCBB58 curCtx=0x000000000FC8F300 xsc->flg4=65792 flags=2 2025-05-22 21:58:38.026298*:9AAA219E:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCCBB58 2025-05-22 21:58:38.026859 :9AAA219F: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-05-22 21:58:38.037741 :9AAA21A7:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-22 21:58:38.038204 :9AAA21A8:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-22 21:58:38.040616 :9AAA21A9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-22 21:58:38.040975 :9AAA21AA: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-05-22 21:58:38.041009 :9AAA21AD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-22 21:58:38.041907 :9AAA21B3: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-05-22 21:58:38.042023 :9AAA21BC: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-05-22 21:59:08.143853 :9AAA2B33:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:20.990015 :9AAA2F4D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:20.975 2025-05-22 21:59:20.990018 :9AAA2F4E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14096 pso_num=22 pso_serial#=82 2025-05-22 21:59:20.990163 :9AAA2F4F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14096 (legacy spawn) 2025-05-22 21:59:20.996630 :9AAA2F50: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-05-22 21:59:20.996801 :9AAA2F55: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-05-22 21:59:20.997665 :9AAA2F5A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:21.006323 :9AAA2F5D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:21.001 2025-05-22 21:59:21.006325 :9AAA2F5E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11320 pso_num=22 pso_serial#=83 2025-05-22 21:59:21.006457 :9AAA2F5F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11320 (legacy spawn) 2025-05-22 21:59:21.012966 :9AAA2F60: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-05-22 21:59:21.013126 :9AAA2F69: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-05-22 21:59:21.013964 :9AAA2F6A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:24.205933 :9AAA305D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:24.193 2025-05-22 21:59:24.205935 :9AAA305E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10200 pso_num=22 pso_serial#=84 2025-05-22 21:59:24.206070 :9AAA305F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10200 (legacy spawn) 2025-05-22 21:59:24.212529 :9AAA3060: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-05-22 21:59:24.212714 :9AAA3065: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-05-22 21:59:24.213497 :9AAA306A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:24.222176 :9AAA306D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:24.209 2025-05-22 21:59:24.222178 :9AAA306E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=3752 pso_num=22 pso_serial#=85 2025-05-22 21:59:24.222321 :9AAA306F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=3752 (legacy spawn) 2025-05-22 21:59:24.228904 :9AAA3070: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-05-22 21:59:24.229078 :9AAA3079: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-05-22 21:59:24.229876 :9AAA307A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:29.794534 :9AAA3212:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:29.781 2025-05-22 21:59:29.794536 :9AAA3213:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4800 pso_num=22 pso_serial#=86 2025-05-22 21:59:29.794670 :9AAA3214:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=4800 (legacy spawn) 2025-05-22 21:59:29.801102 :9AAA3215: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-05-22 21:59:29.801278 :9AAA321A: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-05-22 21:59:29.802067 :9AAA321F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:29.810643 :9AAA3222:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:29.797 2025-05-22 21:59:29.810645 :9AAA3223:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11000 pso_num=22 pso_serial#=87 2025-05-22 21:59:29.810781 :9AAA3224:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11000 (legacy spawn) 2025-05-22 21:59:29.817246 :9AAA3225: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-05-22 21:59:29.817412 :9AAA322E: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-05-22 21:59:29.818209 :9AAA322F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:31.971562 :9AAA32C0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:31.963 2025-05-22 21:59:31.971564 :9AAA32C1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13008 pso_num=22 pso_serial#=88 2025-05-22 21:59:31.971705 :9AAA32C2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13008 (legacy spawn) 2025-05-22 21:59:31.978152 :9AAA32C3: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-05-22 21:59:31.978321 :9AAA32C8: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-05-22 21:59:31.979219 :9AAA32CD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-22 21:59:38.124398 :9AAA34C2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-22 21:59:38.119 2025-05-22 21:59:38.124399 :9AAA34C3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13940 pso_num=22 pso_serial#=89 2025-05-22 21:59:38.124535 :9AAA34C4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13940 osp_idx=0 osp_ver=227549 osp_pg=0 (spawn #209169) 2025-05-22 21:59:38.124536 :9AAA34C5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:59:38.124536 :9AAA34C6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=244 time=926953016 2025-05-22 21:59:38.124537 :9AAA34C7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:59:38.124537 :9AAA34C8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:59:38.124538 :9AAA34C9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:59:38.124538 :9AAA34CA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:59:38.124538 :9AAA34CB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:59:38.125032 :9AAA34CC: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-05-22 21:59:38.125708 :9AAA34E1: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-05-22 21:59:38.133239 :9AAA34FD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-22 21:59:38.133623 :9AAA34FE: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-05-22 21:59:38.133660 :9AAA3501:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-22 21:59:38.134557 :9AAA3507: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-05-22 21:59:38.134672 :9AAA3510: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-05-22 22:00:02.038210 :9AAA3E14: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-05-22 22:00:02.038210*:9AAA3E3C:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1747922401 eid=16780919 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-22 22:00:02.038210*:9AAA3E40:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-05-22 22:00:02.038210*:9AAA3E41:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-05-22 22:00:02.038210*:9AAA3E43:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-05-22 22:00:02.038210*:9AAA3E56:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-05-22 22:00:02.038210*:9AAA3E57:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-05-22 22:00:02.045220 :9AAA3E58: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-05-22 22:00:02.045282 :9AAA3E5B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-05-22 22:00:02.056774 :9AAA3FF9: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-05-22 22:00:02.062007 :9AAA4026: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-05-22 22:00:02.062824 :9AAA402F: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-05-22 22:00:02.068874 :9AAA40B6: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-05-22 22:00:02.069033 :9AAA40CD: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-05-22 22:00:02.069300 :9AAA40E0: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-05-22 22:00:02.069699 :9AAA40F7: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-05-22 22:00:02.069873 :9AAA410E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-05-22 22:00:02.071561 :9AAA4147: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-05-22 22:00:02.071623 :9AAA414A: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-05-22 22:00:02.173194 :9AAA416C: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-05-22 22:00:02.175359 :9AAA416F: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-05-22 22:00:02.175399 :9AAA4172:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-05-22 22:00:02.177872 :9AAA4178:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-05-22 22:00:02.181070 :9AAA4179: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-05-22 22:00:02.181158 :9AAA417C: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-05-22 22:00:02.181246 :9AAA4189: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-05-22 22:00:04.012050 :9AAA45C7: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-05-22 22:00:04.012050*:9AAA45C9:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1747922403 eid=16780924 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-22 22:00:04.012050*:9AAA45CA:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-05-22 22:00:04.012050*:9AAA45CB:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-05-22 22:00:04.012050*:9AAA45CC:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-05-22 22:00:04.012050*:9AAA45CD:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-05-22 22:00:04.012050*:9AAA45CE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-05-22 22:00:04.014361 :9AAA45CF: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-05-22 22:00:04.014402 :9AAA45D2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-05-22 22:00:04.021050 :9AAA45D8: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-05-22 22:00:04.021769 :9AAA45E0: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-05-22 22:00:04.022458 :9AAA45E8: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-05-22 22:00:04.022695 :9AAA45F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-05-22 22:00:04.024060 :9AAA45F1: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-05-22 22:00:04.024102 :9AAA45F4: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-05-22 22:00:04.024232 :9AAA4601: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: 13940, J000)