Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250428220007\orcl_j003_8316_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:37541M/63366M, Ph+PgF:45143M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 8316, image: ORACLE.EXE (J003) *** 2025-04-28 22:00:07.682 *** SESSION ID:(233.19945) 2025-04-28 22:00:07.682 *** 2025-04-28 22:00:07.682 Process diagnostic dump for ORACLE.EXE (J003), OS id=8316, pid: 29, proc_ser: 9, sid: 233, sess_ser: 19945 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 8316 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12350, hash value=2630407211 Current Wait Stack: Not in wait; last wait ended 0.530932 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.530957 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=145 seq_num=146 snap_id=1 wait times: snap=0.000232 sec, exc=0.000232 sec, total=0.000232 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 1: waited for 'log file sequential read' log#=0x274f, block#=0x0, blocks=0x0 wait_id=144 seq_num=145 snap_id=1 wait times: snap=0.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.016366 sec of elapsed time 2: waited for 'log file sequential read' log#=0x274f, block#=0x0, blocks=0x0 wait_id=143 seq_num=144 snap_id=1 wait times: snap=0.000022 sec, exc=0.000022 sec, total=0.000022 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.485925 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x6000, blocks=0x800 wait_id=142 seq_num=143 snap_id=1 wait times: snap=0.000298 sec, exc=0.000298 sec, total=0.000298 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0x5800, blocks=0x800 wait_id=141 seq_num=142 snap_id=1 wait times: snap=0.000286 sec, exc=0.000286 sec, total=0.000286 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000027 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0x5000, blocks=0x800 wait_id=140 seq_num=141 snap_id=1 wait times: snap=0.000305 sec, exc=0.000305 sec, total=0.000305 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.069995 sec of elapsed time 6: waited for 'log file sequential read' log#=0x274f, block#=0x800, blocks=0x800 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000196 sec, exc=0.000196 sec, total=0.000196 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000882 sec of elapsed time 7: waited for 'log file sequential read' log#=0x274f, block#=0x0, blocks=0x0 wait_id=138 seq_num=139 snap_id=1 wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000125 sec of elapsed time 8: waited for 'log file sequential read' log#=0x274f, block#=0x2, blocks=0x7fe wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000188 sec, exc=0.000188 sec, total=0.000188 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000149 sec of elapsed time 9: waited for 'log file sequential read' log#=0x0, block#=0x1, blocks=0x1 wait_id=136 seq_num=137 snap_id=1 wait times: snap=0.000043 sec, exc=0.000043 sec, total=0.000043 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000003 sec of elapsed time Sampled Session History of session 233 serial 19945 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [6 samples, 22:00:02 - 22:00:07] not in wait at each sample [1 sample, 22:00:01] idle wait at each sample [session created at: 22:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-28 22:00:07.682 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 8316, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-27 23:59:50.153237 :8FAD5F40:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04-27 23:59:50.154393 :8FAD5F41:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-27 23:59:50.406698 :8FAD5F4F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-27 23:59:50.396 2025-04-27 23:59:50.406701 :8FAD5F50:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11012 pso_num=29 pso_serial#=1 2025-04-27 23:59:50.406846 :8FAD5F51:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=11012 (legacy spawn) 2025-04-27 23:59:50.421255 :8FAD5F5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:23.454795 :8FAD6DFB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 00:00:47.095056 :8FAD760F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 00:00:47.084 2025-04-28 00:00:47.095058 :8FAD7610:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10932 pso_num=29 pso_serial#=2 2025-04-28 00:00:47.095200 :8FAD7613:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10932 osp_idx=27 osp_ver=9946 osp_pg=0 (spawn #125295) 2025-04-28 00:00:47.095201 :8FAD7614:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-28 00:00:47.095202 :8FAD7615:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=133 time=3069236578 2025-04-28 00:00:47.095202 :8FAD7616:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-28 00:00:47.095202 :8FAD7617:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-28 00:00:47.095203 :8FAD7618:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-28 00:00:47.095203 :8FAD7619:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-28 00:00:47.095203 :8FAD761A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-28 00:00:47.095689 :8FAD761F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.095732 :8FAD7626:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-28 00:00:47.101353 :8FAD7642:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.127125 :8FAD766F:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 4286498451 8468848) 2025-04-28 00:00:47.127133 :8FAD7670:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.127178 :8FAD7678:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-28 00:00:47.127225 :8FAD7688:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.142109 :8FAD7690:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.168340 :8FAD7698:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.172103 :8FAD76A0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.175845 :8FAD76A8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.180264 :8FAD76B0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:47.181363 :8FAD76B8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:48.436163 :8FAD770C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:48.437380*:8FAD7714:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000028CE6B08 estart=1745769648 eid=16778068 ctx=0x000000077392D068 cwh=0x0000000028CA0320 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-04-28 00:00:48.437380*:8FAD7715:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000028CE6B08 curCtx=0x0000000028CEBE30 pubTabIdxCnt=0 2025-04-28 00:00:48.437380*:8FAD7716:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000028CE6B08 2025-04-28 00:00:48.437380*:8FAD7717:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000028CE6B08 2025-04-28 00:00:48.437380*:8FAD7718:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000028CE6B08 curCtx=0x0000000028CEBE30 xsc->flg4=65792 flags=1 2025-04-28 00:00:48.437380*:8FAD7719:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000028CE6B08 2025-04-28 00:00:48.460355 :8FAD771A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:48.460764 :8FAD7722:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:48.461088 :8FAD772A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:48.461108 :8FAD772D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 00:00:48.461180 :8FAD7739:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04-28 00:00:48.463889 :8FAD7747:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 00:10:48.341594 :8FAE4972:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 00:10:48.329 2025-04-28 00:10:48.341597 :8FAE4973:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10760 pso_num=29 pso_serial#=3 2025-04-28 00:10:48.341729 :8FAE4974:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10760 osp_idx=27 osp_ver=9947 osp_pg=0 (spawn #125320) 2025-04-28 00:10:48.341730 :8FAE4975:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-28 00:10:48.341730 :8FAE4976:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=134 time=3069837812 2025-04-28 00:10:48.341731 :8FAE4977:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-28 00:10:48.341731 :8FAE4978:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-28 00:10:48.341731 :8FAE4979:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-28 00:10:48.341731 :8FAE497A:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-28 00:10:48.341732 :8FAE497B:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-28 00:10:48.342247 :8FAE497C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-28 00:10:48.342291 :8FAE4982:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-28 00:10:48.346429 :8FAE499B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-28 00:10:48.346470 :8FAE499C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-28 00:10:48.346731 :8FAE499D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-28 00:10:48.346748 :8FAE499E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-28 00:10:48.346960 :8FAE499F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-28 00:10:48.346974 :8FAE49A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-28 00:10:48.347181 :8FAE49A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-28 00:10:48.347195 :8FAE49A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-28 00:10:48.347399 :8FAE49A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-28 00:10:48.347412 :8FAE49A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-28 00:10:48.347612 :8FAE49A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-28 00:10:48.347627 :8FAE49A6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-28 00:10:48.349896 :8FAE49A7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 00:15:39.892648 :8FAEAFAC:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 00:15:39.887 2025-04-28 00:15:39.892650 :8FAEAFAD:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=4320 pso_num=29 pso_serial#=4 2025-04-28 00:15:39.892782 :8FAEAFAE:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=4320 osp_idx=27 osp_ver=9948 osp_pg=0 (spawn #125332) 2025-04-28 00:15:39.892783 :8FAEAFAF:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-28 00:15:39.892784 :8FAEAFB0:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=135 time=3070129375 2025-04-28 00:15:39.892784 :8FAEAFB1:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-28 00:15:39.892785 :8FAEAFB2:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-28 00:15:39.892785 :8FAEAFB3:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-28 00:15:39.892785 :8FAEAFB4:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-28 00:15:39.892785 :8FAEAFB5:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-28 00:15:39.893271 :8FAEAFB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-28 00:15:39.893311 :8FAEAFBE:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-28 00:15:39.899964 :8FAEAFCA:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 01:00:05.092885 :8FB2383C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 01:00:05.079 2025-04-28 01:00:05.092887 :8FB2383D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8700 pso_num=29 pso_serial#=5 2025-04-28 01:00:05.093022 :8FB2383E:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=8700 (legacy spawn) 2025-04-28 01:00:05.099520 :8FB2383F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 01:00:05.099687 :8FB23844:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04-28 01:00:05.100481 :8FB23849:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 01:00:05.109082 :8FB2384C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 01:00:05.095 2025-04-28 01:00:05.109084 :8FB2384D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9948 pso_num=29 pso_serial#=6 2025-04-28 01:00:05.109222 :8FB2384E:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9948 (legacy spawn) 2025-04-28 01:00:05.115699 :8FB2384F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 01:00:05.115861 :8FB23858:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04-28 01:00:05.116671 :8FB23859:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 01:00:29.159572 :8FB241E0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 01:00:29.146 2025-04-28 01:00:29.159574 :8FB241E1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=4640 pso_num=29 pso_serial#=7 2025-04-28 01:00:29.159718 :8FB241E2:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=4640 (legacy spawn) 2025-04-28 01:00:29.166253 :8FB241E3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 01:00:29.166426 :8FB241E8:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04-28 01:00:29.167242 :8FB241ED:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 01:15:41.957818 :8FB381ED:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 01:15:41.952 2025-04-28 01:15:41.957821 :8FB381EE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7736 pso_num=29 pso_serial#=8 2025-04-28 01:15:41.957995 :8FB381EF:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=7736 osp_idx=27 osp_ver=9952 osp_pg=0 (spawn #125474) 2025-04-28 01:15:41.957996 :8FB381F0:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-28 01:15:41.957996 :8FB381F1:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=136 time=3073731437 2025-04-28 01:15:41.957997 :8FB381F2:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-28 01:15:41.957997 :8FB381F3:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-28 01:15:41.957997 :8FB381F4:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-28 01:15:41.957998 :8FB381F5:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-28 01:15:41.957998 :8FB381F6:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-28 01:15:41.958501 :8FB381F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-28 01:15:41.958547 :8FB381FF:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-28 01:15:41.965011 :8FB38216:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-28 22:00:01.437104 :90162AA4:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-28 22:00:01.430 2025-04-28 22:00:01.437105 :90162AA5:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8316 pso_num=29 pso_serial#=9 2025-04-28 22:00:01.437241 :90162AAA:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=8316 osp_idx=27 osp_ver=9953 osp_pg=0 (spawn #128389) 2025-04-28 22:00:01.437243 :90162AAB:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-28 22:00:01.437244 :90162AAC:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=137 time=3148390921 2025-04-28 22:00:01.437245 :90162AAD:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-28 22:00:01.437245 :90162AAE:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-28 22:00:01.437246 :90162AAF:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-28 22:00:01.437247 :90162AB0:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-28 22:00:01.437247 :90162AB1:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-28 22:00:01.437891 :90162ABF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.442838 :90162AD4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.442879 :90162AD7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-04-28 22:00:01.460419 :90162CAC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.460709 :90162CB4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.460888 :90162CBC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.461055 :90162CC4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.461225 :90162CCC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.461412 :90162CD4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.461579 :90162CDC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.461754 :90162CE4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.461910 :90162CEC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.462063 :90162CF4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.462213 :90162CFC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.462370 :90162D04:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.462520 :90162D0C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.462670 :90162D14:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.462833 :90162D1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.463003 :90162D24:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.463152 :90162D2C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.463310 :90162D34:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.463461 :90162D3C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.463615 :90162D44:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.463767 :90162D4C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.463915 :90162D54:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.464064 :90162D5C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.464225 :90162D64:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.465010 :90162D6C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:01.492449 :90162D86:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.142701 :901630BD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=16 loc='ktm.h LINE:583 ID:ktmpsm' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.144569 :9016318D:db_trace:ktu.c@5576:ktugur(): [10445:29:233] des1:tsn:1 rdba:0x00800356 where: kduwh01: kdusru 2025-04-28 22:00:03.149096 :901631C4:db_trace:ktu.c@5576:ktugur(): [10445:29:233] des1:tsn:1 rdba:0x00800356 where: kduwh01: kdusru 2025-04-28 22:00:03.166353 :901631C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.188486 :901631E8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.190818 :901631F2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-04-28 22:00:03.191046 :901631F3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-04-28 22:00:03.192076 :901631F4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.192175 :901631F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.193168 :90163209:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.194836 :90163211:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.195145 :90163219:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:03.258455*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-04-28 22:00:03.258455*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-04-28 22:00:03.258455*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-04-28 22:00:03.258455*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-04-28 22:00:03.258455*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-04-28 22:00:03.258455*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-04-28 22:00:03.258455*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-04-28 22:00:03.305328*:901632AE:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000037470230 estart=1745848803 eid=16777494 ctx=0x000000079F4EAD08 cwh=0x000000002B4D0518 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-04-28 22:00:03.305328*:901632AF:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000037470230 curCtx=0x0000000037748E98 pubTabIdxCnt=0 2025-04-28 22:00:03.305328*:901632B0:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000037470230 2025-04-28 22:00:03.305328*:901632B1:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000037470230 2025-04-28 22:00:03.320953*:901632EC:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000037470230 curCtx=0x0000000037748E98 xsc->flg4=65792 flags=1 2025-04-28 22:00:03.320953*:901632ED:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000037470230 2025-04-28 22:00:03.336345 :901632EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:05.219052 :90163422:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:05.219067 :90163423:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.01a.0001c3d4 2025-04-28 22:00:07.603985 :90163620:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:07.605324 :9016362A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:07.615589 :90163636:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-28 22:00:07.637502 :90163646:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 8316, J003)