Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250816180819\orcl_j001_19784_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:35448M/63366M, Ph+PgF:40795M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 19784, image: ORACLE.EXE (J001) *** 2025-08-16 18:08:19.671 *** SESSION ID:(193.4459) 2025-08-16 18:08:19.671 *** 2025-08-16 18:08:19.671 Process diagnostic dump for ORACLE.EXE (J001), OS id=19784, pid: 24, proc_ser: 170, sid: 193, sess_ser: 4459 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 19784 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.000901 sec, exc=0.000901 sec, total=0.000901 sec wait times: max=0.500000 sec, heur=7.502235 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=14 seq_num=15 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 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 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 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.499989 sec, exc=0.499989 sec, total=0.499989 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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.000008 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.504569 sec, exc=0.504569 sec, total=0.504569 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time Sampled Session History of session 193 serial 4459 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [8 samples, 18:08:12 - 18:08:19] idle wait at each sample [session created at: 18:08:12] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-16 18:08:19.671 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 19784, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-16 18:00:46.636517 :C097A8F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.636952 :C097A8F8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.639451 :C097A900:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.640561 :C097A908:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.691566 :C097A910:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.691577 :C097A911:db_trace:ktur.c@3079:ktuabt(): [10444:24:193] ABORT TRANSACTION - xid: 0x0009.020.0001d94b 2025-08-16 18:00:46.691982 :C097A919:db_trace:ktu.c@4871:ktuaex1r(): [10442:24:193] Extension usn 9, ext 2, nex 5 2025-08-16 18:00:46.691987 :C097A91A:db_trace:ktusm.c@2117:ktusmasp(): [10445:24:193] des1:tsn:1 rdba:0x00800cc6 where: kdiwh187: kdisprobe 2025-08-16 18:00:46.693421 :C097A91B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.694288 :C097A923:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.694516 :C097A92B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.694759 :C097A933:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:00:46.696721 :C097A93B:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:00:53.419971 :C097ABE8:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:00:53.409 2025-08-16 18:00:53.419974 :C097ABE9:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=20840 pso_num=24 pso_serial#=163 2025-08-16 18:00:53.420095 :C097ABEA:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=20840 osp_idx=22 osp_ver=738653 osp_pg=0 (spawn #495263) 2025-08-16 18:00:53.420095 :C097ABEB:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:00:53.420096 :C097ABEC:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=108 time=4047922720 2025-08-16 18:00:53.420096 :C097ABED:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:00:53.420097 :C097ABEE:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:00:53.420097 :C097ABEF:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:00:53.420097 :C097ABF0:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:00:53.420098 :C097ABF1:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:00:53.420571 :C097ABF2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:01:23.516822 :C097B6CA:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:01:53.496435 :C097C093:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:01:53.485 2025-08-16 18:01:53.496436 :C097C094:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22448 pso_num=24 pso_serial#=164 2025-08-16 18:01:53.496564 :C097C095:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22448 osp_idx=22 osp_ver=738654 osp_pg=0 (spawn #495265) 2025-08-16 18:01:53.496565 :C097C096:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:01:53.496565 :C097C097:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=109 time=4047982798 2025-08-16 18:01:53.496565 :C097C098:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:01:53.496566 :C097C099:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:01:53.496566 :C097C09A:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:01:53.496567 :C097C09B:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:01:53.496567 :C097C09C:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:01:53.497044 :C097C09D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:02:23.604995 :C097CD40:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:02:53.585722 :C097D6F4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:02:53.574 2025-08-16 18:02:53.585724 :C097D6F5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=19316 pso_num=24 pso_serial#=165 2025-08-16 18:02:53.585846 :C097D6F6:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=19316 osp_idx=22 osp_ver=738655 osp_pg=0 (spawn #495267) 2025-08-16 18:02:53.585846 :C097D6F7:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:02:53.585847 :C097D6F8:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=110 time=4048042892 2025-08-16 18:02:53.585847 :C097D6F9:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:02:53.585848 :C097D6FA:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:02:53.585848 :C097D6FB:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:02:53.585848 :C097D6FC:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:02:53.585848 :C097D6FD:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:02:53.586322 :C097D6FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:03:08.594154 :C097DCA7:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-16 18:03:08.594184*:C097DCA8:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024D4BB58 estart=1755338588 eid=17009298 ctx=0x000000077BD98A08 cwh=0x00000000232801B0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-16 18:03:08.594184*:C097DCA9:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024D4BB58 curCtx=0x000000002328F708 pubTabIdxCnt=0 2025-08-16 18:03:08.594184*:C097DCAA:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024D4BB58 2025-08-16 18:03:08.594184*:C097DCAB:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024D4BB58 2025-08-16 18:03:08.594184*:C097DCAC:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024D4BB58 curCtx=0x000000002328F708 xsc->flg4=65792 flags=2 2025-08-16 18:03:08.594184*:C097DCAD:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024D4BB58 2025-08-16 18:03:08.594794 :C097DCAE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:03:08.600265 :C097DCB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:03:08.601224 :C097DCBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:03:08.601357 :C097DCC7:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-08-16 18:03:38.682270 :C097E6C3:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:03:53.692466 :C097EBD4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:03:53.681 2025-08-16 18:03:53.692468 :C097EBD5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=17272 pso_num=24 pso_serial#=166 2025-08-16 18:03:53.692587 :C097EBD6:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=17272 osp_idx=22 osp_ver=738656 osp_pg=0 (spawn #495271) 2025-08-16 18:03:53.692588 :C097EBD7:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:03:53.692588 :C097EBD8:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=111 time=4048102986 2025-08-16 18:03:53.692588 :C097EBD9:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:03:53.692588 :C097EBDA:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:03:53.692589 :C097EBDB:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:03:53.692589 :C097EBDC:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:03:53.692589 :C097EBDD:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:03:53.693092 :C097EBDE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:04:23.763659 :C097F56F:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:04:53.793235 :C097FF26:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:04:53.780 2025-08-16 18:04:53.793238 :C097FF27:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=20104 pso_num=24 pso_serial#=167 2025-08-16 18:04:53.793360 :C097FF28:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=20104 osp_idx=22 osp_ver=738657 osp_pg=0 (spawn #495273) 2025-08-16 18:04:53.793361 :C097FF29:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:04:53.793361 :C097FF2A:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=112 time=4048163095 2025-08-16 18:04:53.793361 :C097FF2B:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:04:53.793362 :C097FF2C:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:04:53.793362 :C097FF2D:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:04:53.793363 :C097FF2E:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:04:53.793363 :C097FF2F:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:04:53.793935 :C097FF30:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:05:23.887589 :C09808E3:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:05:53.882736 :C09817FC:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:05:53.871 2025-08-16 18:05:53.882738 :C09817FD:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=21744 pso_num=24 pso_serial#=168 2025-08-16 18:05:53.882865 :C09817FE:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=21744 osp_idx=22 osp_ver=738658 osp_pg=0 (spawn #495275) 2025-08-16 18:05:53.882866 :C09817FF:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:05:53.882867 :C0981800:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=113 time=4048223189 2025-08-16 18:05:53.882867 :C0981801:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:05:53.882868 :C0981802:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:05:53.882868 :C0981803:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:05:53.882868 :C0981804:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:05:53.882868 :C0981805:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:05:53.883340 :C0981806:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:06:23.970804 :C0982398:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:06:53.972958 :C0982D55:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:06:53.961 2025-08-16 18:06:53.972960 :C0982D56:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22208 pso_num=24 pso_serial#=169 2025-08-16 18:06:53.973089 :C0982D57:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22208 osp_idx=22 osp_ver=738659 osp_pg=0 (spawn #495277) 2025-08-16 18:06:53.973090 :C0982D58:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:06:53.973090 :C0982D59:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=114 time=4048283267 2025-08-16 18:06:53.973091 :C0982D5A:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:06:53.973091 :C0982D5B:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:06:53.973092 :C0982D5C:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:06:53.973092 :C0982D5D:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:06:53.973092 :C0982D5E:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:06:53.973599 :C0982D5F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:07:24.070512 :C09836C9:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-16 18:07:54.061538 :C09840C4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-16 18:07:54.050 2025-08-16 18:07:54.061540 :C09840C5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=19784 pso_num=24 pso_serial#=170 2025-08-16 18:07:54.061661 :C09840C6:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=19784 osp_idx=22 osp_ver=738660 osp_pg=0 (spawn #495279) 2025-08-16 18:07:54.061661 :C09840C7:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:07:54.061662 :C09840C8:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=115 time=4048343361 2025-08-16 18:07:54.061662 :C09840C9:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:07:54.061662 :C09840CA:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:07:54.061662 :C09840CB:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:07:54.061663 :C09840CC:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:07:54.061663 :C09840CD:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:07:54.062138 :C09840CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.389434 :C0984740:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-16 18:08:10.490888 :C0984833:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-16 18:08:10.490888*:C0984842:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024D5C718 estart=1755338890 eid=16786205 ctx=0x000000077FD6A000 cwh=0x0000000024D50068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-16 18:08:10.490888*:C0984843:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024D5C718 curCtx=0x0000000024D58938 pubTabIdxCnt=0 2025-08-16 18:08:10.490888*:C0984844:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024D5C718 2025-08-16 18:08:10.490888*:C0984845:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024D5C718 2025-08-16 18:08:10.490888*:C0984846:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024D5C718 curCtx=0x0000000024D58938 xsc->flg4=65792 flags=2 2025-08-16 18:08:10.490888*:C0984847:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024D5C718 2025-08-16 18:08:10.496203 :C0984852:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.496245 :C0984855:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-08-16 18:08:10.500345 :C0984865:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.607679 :C098486D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.737186 :C0984875:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.868611 :C098487D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:11.997320 :C09848F4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:11.998412 :C09848FC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.000460 :C0984904:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.004206 :C098490C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.006020 :C0984928:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.008719 :C0984944:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.024651 :C098494C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.025385 :C0984954:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.025976 :C098495C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.026507 :C0984964:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.029625 :C098496C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.030588 :C0984974:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.031460 :C0984975:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.032294 :C0984976:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.032726 :C0984977:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.032734 :C0984978:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.033611 :C0984979:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.034183 :C098497A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.034550 :C098497B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.035721 :C098497C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.067666 :C098497D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.067723 :C0984980:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.068764 :C0984986:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.069687 :C098498E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.070244 :C098498F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.091944 :C098499F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.092000 :C09849A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.092912 :C09849A8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.093818 :C09849B0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.094292 :C09849B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.112436 :C09849F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.112475 :C09849F3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.113233 :C09849F9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.114019 :C0984A01:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.114518 :C0984A02:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.136909 :C0984A0A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.136960 :C0984A0D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.137942 :C0984A13:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.138807 :C0984A1B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.139318 :C0984A1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.160604 :C0984A24:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.160657 :C0984A27:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.161602 :C0984A2D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.162103 :C0984A35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.162490 :C0984A3D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.162672 :C0984A45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.162821 :C0984A4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.162966 :C0984A55:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-08-16 18:08:12.167310 :C0984A56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.167401 :C0984A59:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.167479 :C0984A66:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 24 (osid: 19784, J001)