Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250811220005\orcl_j003_14924_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:35559M/63366M, Ph+PgF:40968M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 14924, image: ORACLE.EXE (J003) *** 2025-08-11 22:00:05.905 *** SESSION ID:(233.31651) 2025-08-11 22:00:05.905 *** 2025-08-11 22:00:05.905 Process diagnostic dump for ORACLE.EXE (J003), OS id=14924, pid: 29, proc_ser: 207, sid: 233, sess_ser: 31651 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 14924 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12905, hash value=1427042001 Current Wait Stack: Not in wait; last wait ended 2.829063 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.829090 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000167 sec, exc=0.000167 sec, total=0.000167 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.067026 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000007 sec, exc=0.000007 sec, total=0.000007 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.040713 sec of elapsed time 2: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x3, filetype=0x2 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.000162 sec, exc=0.000162 sec, total=0.000162 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.719770 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.026844 sec of elapsed time 4: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.012891 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.000074 sec, exc=0.000074 sec, total=0.000074 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.050067 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.006058 sec, exc=0.006058 sec, total=0.006058 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007904 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.000113 sec, exc=0.000113 sec, total=0.000113 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.263652 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.004994 sec, exc=0.004994 sec, total=0.004994 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000217 sec of elapsed time 9: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.000117 sec, exc=0.000117 sec, total=0.000117 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007874 sec of elapsed time Sampled Session History of session 233 serial 31651 --------------------------------------------------- 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:01 - 22:00:05] not in wait at each sample [1 sample, 22:00:00] 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-08-11 22:00:05.905 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 14924, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-11 00:00:43.039609 :BE115E49: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-08-11 00:00:43.040081 :BE115E51: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-08-11 00:00:43.040513 :BE115E59: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-08-11 00:00:43.043040 :BE115E61: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-08-11 00:00:43.044147 :BE115E69: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-08-11 00:00:43.095067 :BE115E7D: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-08-11 00:00:43.096039 :BE115E85: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-08-11 00:00:43.096279 :BE115E8D: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-08-11 00:00:43.096495 :BE115E95: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-08-11 00:00:43.098314 :BE115E9D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:08.134255 :BE15E97D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:08.121 2025-08-11 01:00:08.134257 :BE15E97E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=6128 pso_num=29 pso_serial#=198 2025-08-11 01:00:08.134394 :BE15E97F:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=6128 (legacy spawn) 2025-08-11 01:00:08.140851 :BE15E980: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-08-11 01:00:08.141032 :BE15E987: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-08-11 01:00:08.141817 :BE15E98A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:13.729409 :BE15EB4B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:13.724 2025-08-11 01:00:13.729411 :BE15EB4C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=20008 pso_num=29 pso_serial#=199 2025-08-11 01:00:13.729552 :BE15EB4D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=20008 osp_idx=27 osp_ver=15753 osp_pg=0 (spawn #476244) 2025-08-11 01:00:13.729553 :BE15EB4E:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-11 01:00:13.729553 :BE15EB4F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=215 time=3554683033 2025-08-11 01:00:13.729554 :BE15EB50:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-11 01:00:13.729554 :BE15EB51:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-11 01:00:13.729555 :BE15EB52:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-11 01:00:13.729555 :BE15EB53:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-11 01:00:13.729556 :BE15EB54:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-11 01:00:13.730054 :BE15EB55: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-08-11 01:00:13.730095 :BE15EB5B: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-08-11 01:00:13.734294 :BE15EB6A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-08-11 01:00:13.734336 :BE15EB6B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-08-11 01:00:13.734587 :BE15EB6C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-08-11 01:00:13.734603 :BE15EB6D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-08-11 01:00:13.734819 :BE15EB6E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-08-11 01:00:13.734832 :BE15EB6F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-08-11 01:00:13.735037 :BE15EB70:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-08-11 01:00:13.735050 :BE15EB71:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-08-11 01:00:13.735327 :BE15EB72:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-08-11 01:00:13.735340 :BE15EB73:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-08-11 01:00:13.735545 :BE15EB74:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-08-11 01:00:13.735558 :BE15EB75:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-08-11 01:00:13.737901 :BE15EB76:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:20.641865 :BE15ED4C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:20.633 2025-08-11 01:00:20.641867 :BE15ED4D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7436 pso_num=29 pso_serial#=200 2025-08-11 01:00:20.642000 :BE15ED4E:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=7436 (legacy spawn) 2025-08-11 01:00:20.648484 :BE15ED4F: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-08-11 01:00:20.648660 :BE15ED57: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-08-11 01:00:20.649462 :BE15ED59:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:20.804034 :BE15ED68:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:20.789 2025-08-11 01:00:20.804037 :BE15ED69:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=19852 pso_num=29 pso_serial#=201 2025-08-11 01:00:20.804172 :BE15ED6A:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=19852 (legacy spawn) 2025-08-11 01:00:20.810614 :BE15ED6B: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-08-11 01:00:20.810777 :BE15ED74: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-08-11 01:00:20.811593 :BE15ED75:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:20.820368 :BE15ED78:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:20.805 2025-08-11 01:00:20.820370 :BE15ED79:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=20928 pso_num=29 pso_serial#=202 2025-08-11 01:00:20.820506 :BE15ED7A:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=20928 (legacy spawn) 2025-08-11 01:00:20.826934 :BE15ED7B: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-08-11 01:00:20.826963 :BE15ED7E: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-08-11 01:00:20.827116 :BE15ED86: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-08-11 01:00:20.827920 :BE15ED92:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:24.015960 :BE15EE97:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:24.002 2025-08-11 01:00:24.015962 :BE15EE98:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=19176 pso_num=29 pso_serial#=203 2025-08-11 01:00:24.016102 :BE15EE99:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=19176 (legacy spawn) 2025-08-11 01:00:24.022675 :BE15EE9A: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-08-11 01:00:24.022852 :BE15EE9F: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-08-11 01:00:24.023703 :BE15EEA4:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:24.032580 :BE15EEA7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:24.018 2025-08-11 01:00:24.032582 :BE15EEA8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=21220 pso_num=29 pso_serial#=204 2025-08-11 01:00:24.032721 :BE15EEA9:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=21220 (legacy spawn) 2025-08-11 01:00:24.040083 :BE15EEAA: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-08-11 01:00:24.040269 :BE15EEB3: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-08-11 01:00:24.041127 :BE15EEB4:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:31.767792 :BE15F245:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:31.762 2025-08-11 01:00:31.767795 :BE15F246:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7960 pso_num=29 pso_serial#=205 2025-08-11 01:00:31.767942 :BE15F247:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=7960 osp_idx=27 osp_ver=15759 osp_pg=0 (spawn #476245) 2025-08-11 01:00:31.767943 :BE15F248:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-11 01:00:31.767943 :BE15F249:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=216 time=3554701079 2025-08-11 01:00:31.767944 :BE15F24A:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-11 01:00:31.767944 :BE15F24B:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-11 01:00:31.767944 :BE15F24C:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-11 01:00:31.767944 :BE15F24D:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-11 01:00:31.767945 :BE15F24E:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-11 01:00:31.768486 :BE15F24F: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-08-11 01:00:31.768532 :BE15F255: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-08-11 01:00:31.776644 :BE15F264:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 01:00:51.171272 :BE15F8CD:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 01:00:51.166 2025-08-11 01:00:51.171274 :BE15F8CE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=1216 pso_num=29 pso_serial#=206 2025-08-11 01:00:51.171401 :BE15F8CF:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=1216 osp_idx=27 osp_ver=15760 osp_pg=0 (spawn #476247) 2025-08-11 01:00:51.171402 :BE15F8D0:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-11 01:00:51.171402 :BE15F8D1:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=217 time=3554720454 2025-08-11 01:00:51.171403 :BE15F8D2:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-11 01:00:51.171403 :BE15F8D3:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-11 01:00:51.171403 :BE15F8D4:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-11 01:00:51.171403 :BE15F8D5:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-11 01:00:51.171404 :BE15F8D6:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-11 01:00:51.171886 :BE15F8D7: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-08-11 01:00:51.171931 :BE15F8DD: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-08-11 01:00:51.179708 :BE15F8EB: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-08-11 01:00:51.180856 :BE15F8F3: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-08-11 01:00:51.181435 :BE15F8FB: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-08-11 01:00:51.181909 :BE15F903: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-08-11 01:00:51.182370 :BE15F90B: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-08-11 01:00:51.184911 :BE15F913: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-08-11 01:00:51.186015 :BE15F91B: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-08-11 01:00:51.236798 :BE15F92E: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-08-11 01:00:51.237801 :BE15F936: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-08-11 01:00:51.238058 :BE15F93E: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-08-11 01:00:51.238281 :BE15F946: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-08-11 01:00:51.240139 :BE15F94E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-11 22:00:01.295145 :BE76F91B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-11 22:00:01.287 2025-08-11 22:00:01.295147 :BE76F91C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14924 pso_num=29 pso_serial#=207 2025-08-11 22:00:01.295296 :BE76F923:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14924 osp_idx=27 osp_ver=15761 osp_pg=0 (spawn #479156) 2025-08-11 22:00:01.295297 :BE76F924:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-11 22:00:01.295298 :BE76F925:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=218 time=3630270595 2025-08-11 22:00:01.295298 :BE76F926:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-11 22:00:01.295299 :BE76F927:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-11 22:00:01.295299 :BE76F928:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-11 22:00:01.295299 :BE76F929:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-11 22:00:01.295300 :BE76F92A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-11 22:00:01.295821 :BE76F933: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-08-11 22:00:01.301154 :BE76F952: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-08-11 22:00:01.301186 :BE76F955:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-08-11 22:00:01.319215 :BE76FB1B: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-08-11 22:00:01.319461 :BE76FB23: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-08-11 22:00:01.319746 :BE76FB2B: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-08-11 22:00:01.319918 :BE76FB33: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-08-11 22:00:01.320095 :BE76FB3B: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-08-11 22:00:01.320250 :BE76FB43: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-08-11 22:00:01.320399 :BE76FB4B: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-08-11 22:00:01.320549 :BE76FB53: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-08-11 22:00:01.320706 :BE76FB5B: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-08-11 22:00:01.320853 :BE76FB63: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-08-11 22:00:01.321068 :BE76FB6B: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-08-11 22:00:01.321343 :BE76FB73: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-08-11 22:00:01.321489 :BE76FB7B: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-08-11 22:00:01.321639 :BE76FB83: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-08-11 22:00:01.321787 :BE76FB8B: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-08-11 22:00:01.321931 :BE76FB93: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-08-11 22:00:01.322103 :BE76FB9C: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-08-11 22:00:01.322269 :BE76FBA4: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-08-11 22:00:01.322416 :BE76FBAC: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-08-11 22:00:01.322559 :BE76FBB4: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-08-11 22:00:01.322703 :BE76FBBE: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-08-11 22:00:01.322859 :BE76FBC6: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-08-11 22:00:01.323002 :BE76FBCE: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-08-11 22:00:01.323141 :BE76FBD6: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-08-11 22:00:01.343895 :BE76FBED: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-08-11 22:00:02.646829*:BE76FE4D:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000318F3AD0 estart=1754920801 eid=21320534 ctx=0x0000000777968158 cwh=0x00000000319209C8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-08-11 22:00:02.646829*:BE76FE4F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000318F3AD0 curCtx=0x00000000561C7918 pubTabIdxCnt=0 2025-08-11 22:00:02.646829*:BE76FE51:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000318F3AD0 2025-08-11 22:00:02.646829*:BE76FE54:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000318F3AD0 2025-08-11 22:00:02.646829*:BE76FE55:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000003196B6F0 estart=1754920800 eid=16777516 ctx=0x000000077B54EAC8 cwh=0x0000000031920518 cpu=1125000 buffg=62964 interb=196608 r=24 rb=196608 w=0 wb=0 2025-08-11 22:00:02.646829*:BE76FE57:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003196B6F0 curCtx=0x00000000560A87D0 pubTabIdxCnt=0 2025-08-11 22:00:02.646829*:BE76FE58:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003196B6F0 2025-08-11 22:00:02.646829*:BE76FE59:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003196B6F0 2025-08-11 22:00:02.646829*:BE76FE5C:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000318F3AD0 curCtx=0x00000000561C7918 xsc->flg4=65792 flags=1 2025-08-11 22:00:02.646829*:BE76FE5D:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000318F3AD0 2025-08-11 22:00:02.976863 :BE76FF15:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 8, ext 1, nex 2 2025-08-11 22:00:02.976870 :BE76FF16:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x008102a7 where: kdiwh22: kdifind 2025-08-11 22:00:02.992307 :BE76FF31:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 8, ext 2, nex 3 2025-08-11 22:00:02.992316 :BE76FF32:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x00815e00 where: kdiwh22: kdifind 2025-08-11 22:00:02.992316*:BE76FF33:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003196B6F0 curCtx=0x00000000560A87D0 xsc->flg4=65792 flags=2 2025-08-11 22:00:02.992316*:BE76FF34:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003196B6F0 2025-08-11 22:00:02.997400 :BE76FF35: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-08-11 22:00:03.019835 :BE76FF57: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-08-11 22:00:03.022088 :BE76FF5F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-08-11 22:00:03.022321 :BE76FF60:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-08-11 22:00:03.023393 :BE76FF61: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-08-11 22:00:03.023499 :BE76FF64: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-08-11 22:00:03.024485 :BE76FF76: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-08-11 22:00:03.026160 :BE76FF7E: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-08-11 22:00:03.026477 :BE76FF86: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-08-11 22:00:03.094451*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-08-11 22:00:03.094451*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-08-11 22:00:03.094451*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-08-11 22:00:03.094451*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-08-11 22:00:03.094451*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-08-11 22:00:03.094451*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-08-11 22:00:03.094451*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-08-11 22:00:03.175247 :BE76FFEB: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-08-11 22:00:05.093033 :BE770129: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-08-11 22:00:05.093044 :BE77012A:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0007.01e.0000c9b3 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 14924, J003)