Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250505220006\orcl_j003_10900_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:37483M/63366M, Ph+PgF:44967M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 10900, image: ORACLE.EXE (J003) *** 2025-05-05 22:00:06.731 *** SESSION ID:(233.20837) 2025-05-05 22:00:06.731 *** 2025-05-05 22:00:06.731 Process diagnostic dump for ORACLE.EXE (J003), OS id=10900, pid: 29, proc_ser: 196, sid: 233, sess_ser: 20837 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 10900 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12387, hash value=986179428 Current Wait Stack: Not in wait; last wait ended 2.888223 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.888248 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=41 seq_num=42 snap_id=1 wait times: snap=0.000175 sec, exc=0.000175 sec, total=0.000175 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.061946 sec of elapsed time 1: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x3, filetype=0x2 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000169 sec, exc=0.000169 sec, total=0.000169 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.005940 sec of elapsed time 2: 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.000008 sec, exc=0.000008 sec, total=0.000008 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.755844 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=38 seq_num=39 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.025385 sec of elapsed time 4: 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.000003 sec, exc=0.000003 sec, total=0.000003 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.013035 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000107 sec, exc=0.000107 sec, total=0.000107 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.050845 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.004839 sec, exc=0.004839 sec, total=0.004839 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.008076 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.000118 sec, exc=0.000118 sec, total=0.000118 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.267206 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.006885 sec, exc=0.006885 sec, total=0.006885 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000339 sec of elapsed time 9: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.000150 sec, exc=0.000150 sec, total=0.000150 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.008950 sec of elapsed time Sampled Session History of session 233 serial 20837 --------------------------------------------------- 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:02 - 22:00:06] not in wait at each sample [1 sample, 22:00:01] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-05 22:00:06.731 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 10900, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-05 01:01:00.094811 :92CD0FD1:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 01:02:58.892547 :92CD3728:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 01:02:58.880 2025-05-05 01:02:58.892549 :92CD3729:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11464 pso_num=29 pso_serial#=189 2025-05-05 01:02:58.892694 :92CD372A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11464 osp_idx=27 osp_ver=10388 osp_pg=0 (spawn #149172) 2025-05-05 01:02:58.892695 :92CD372B:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 01:02:58.892696 :92CD372C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=91 time=3677756046 2025-05-05 01:02:58.892696 :92CD372D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 01:02:58.892696 :92CD372E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 01:02:58.892697 :92CD372F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 01:02:58.892697 :92CD3730:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 01:02:58.892697 :92CD3731:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 01:02:58.893212 :92CD3732: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-05-05 01:02:58.893255 :92CD3738: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-05-05 01:02:58.897306 :92CD3750:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:02:58.897358 :92CD3751:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:02:58.897612 :92CD3752:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:02:58.897628 :92CD3753:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:02:58.897837 :92CD3754:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:02:58.897850 :92CD3755:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:02:58.898057 :92CD3756:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:02:58.898070 :92CD3757:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:02:58.898277 :92CD3758:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:02:58.898290 :92CD3759:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:02:58.898496 :92CD375A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:02:58.898508 :92CD375B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:02:58.900897 :92CD3788:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 01:03:47.008791 :92CD489A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 01:03:47.003 2025-05-05 01:03:47.008794 :92CD489B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8096 pso_num=29 pso_serial#=190 2025-05-05 01:03:47.008931 :92CD489C:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=8096 osp_idx=27 osp_ver=10389 osp_pg=0 (spawn #149177) 2025-05-05 01:03:47.008931 :92CD489D:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 01:03:47.008932 :92CD489E:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=92 time=3677804171 2025-05-05 01:03:47.008932 :92CD489F:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 01:03:47.008933 :92CD48A0:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 01:03:47.008933 :92CD48A1:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 01:03:47.008934 :92CD48A2:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 01:03:47.008934 :92CD48A3:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 01:03:47.009420 :92CD48A4: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-05-05 01:03:47.009465 :92CD48AB: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-05-05 01:03:47.016118 :92CD48B8:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 01:33:02.788417 :92CFA151:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 01:33:02.776 2025-05-05 01:33:02.788420 :92CFA152:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12016 pso_num=29 pso_serial#=191 2025-05-05 01:33:02.788551 :92CFA153:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12016 osp_idx=27 osp_ver=10390 osp_pg=0 (spawn #149242) 2025-05-05 01:33:02.788552 :92CFA154:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 01:33:02.788552 :92CFA155:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=93 time=3679559953 2025-05-05 01:33:02.788553 :92CFA156:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 01:33:02.788553 :92CFA157:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 01:33:02.788553 :92CFA158:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 01:33:02.788554 :92CFA159:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 01:33:02.788554 :92CFA15A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 01:33:02.789077 :92CFA15B: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-05-05 01:33:02.789128 :92CFA161: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-05-05 01:33:02.793136 :92CFA17A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:33:02.793186 :92CFA17B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:33:02.793517 :92CFA17C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:33:02.793535 :92CFA17D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:33:02.793751 :92CFA17E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:33:02.793765 :92CFA17F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:33:02.793973 :92CFA180:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:33:02.793989 :92CFA181:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:33:02.794204 :92CFA182:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:33:02.794217 :92CFA183:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:33:02.794440 :92CFA184:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-05 01:33:02.794453 :92CFA185:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-05 01:33:02.796649 :92CFA186:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 02:03:07.188144 :92D205CE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 02:03:07.185 2025-05-05 02:03:07.188145 :92D205CF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8096 pso_num=29 pso_serial#=192 2025-05-05 02:03:07.188280 :92D205D0:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=8096 osp_idx=27 osp_ver=10391 osp_pg=0 (spawn #149314) 2025-05-05 02:03:07.188281 :92D205D1:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 02:03:07.188282 :92D205D2:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=94 time=3681364343 2025-05-05 02:03:07.188282 :92D205D3:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 02:03:07.188283 :92D205D4:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 02:03:07.188283 :92D205D5:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 02:03:07.188283 :92D205D6:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 02:03:07.188284 :92D205D7:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 02:03:07.188887 :92D205D8: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-05-05 02:03:07.188936 :92D205DE: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-05-05 02:03:07.197964 :92D20606:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 03:03:15.518218 :92D6CB2A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 03:03:15.515 2025-05-05 03:03:15.518219 :92D6CB2B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12136 pso_num=29 pso_serial#=193 2025-05-05 03:03:15.518368 :92D6CB2C:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12136 osp_idx=27 osp_ver=10392 osp_pg=0 (spawn #149455) 2025-05-05 03:03:15.518368 :92D6CB2D:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 03:03:15.518369 :92D6CB2E:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=95 time=3684972671 2025-05-05 03:03:15.518370 :92D6CB2F:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 03:03:15.518371 :92D6CB30:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 03:03:15.518371 :92D6CB31:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 03:03:15.518372 :92D6CB32:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 03:03:15.518373 :92D6CB33:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 03:03:15.518928 :92D6CB34: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-05-05 03:03:15.518980 :92D6CB3A: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-05-05 03:03:15.527877 :92D6CB52:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 04:03:23.033176 :92DB93E2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 04:03:23.031 2025-05-05 04:03:23.033177 :92DB93E3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9184 pso_num=29 pso_serial#=194 2025-05-05 04:03:23.033306 :92DB93E4:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=9184 osp_idx=27 osp_ver=10393 osp_pg=0 (spawn #149595) 2025-05-05 04:03:23.033307 :92DB93E5:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 04:03:23.033308 :92DB93E6:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=96 time=3688580203 2025-05-05 04:03:23.033308 :92DB93E7:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 04:03:23.033309 :92DB93E8:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 04:03:23.033309 :92DB93E9:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 04:03:23.033310 :92DB93EA:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 04:03:23.033310 :92DB93EB:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 04:03:23.033860 :92DB93EC: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-05-05 04:03:23.033910 :92DB93F2: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-05-05 04:03:23.042972 :92DB940A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 05:03:30.989741 :92E060C3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 05:03:30.986 2025-05-05 05:03:30.989742 :92E060C4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11840 pso_num=29 pso_serial#=195 2025-05-05 05:03:30.989882 :92E060C5:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11840 osp_idx=27 osp_ver=10394 osp_pg=0 (spawn #149736) 2025-05-05 05:03:30.989883 :92E060C6:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 05:03:30.989884 :92E060C7:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=97 time=3692188140 2025-05-05 05:03:30.989884 :92E060C8:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 05:03:30.989885 :92E060C9:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 05:03:30.989885 :92E060CA:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 05:03:30.989885 :92E060CB:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 05:03:30.989886 :92E060CC:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 05:03:30.990427 :92E060CD: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-05-05 05:03:30.990472 :92E060D3: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-05-05 05:03:30.998816 :92E060EB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-05 22:00:02.049431 :9330F0B8:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-05 22:00:02.038 2025-05-05 22:00:02.049433 :9330F0B9:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10900 pso_num=29 pso_serial#=196 2025-05-05 22:00:02.049547 :9330F0BA:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10900 osp_idx=27 osp_ver=10395 osp_pg=0 (spawn #152123) 2025-05-05 22:00:02.049548 :9330F0BB:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 22:00:02.049549 :9330F0BC:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=98 time=3753179203 2025-05-05 22:00:02.049550 :9330F0BD:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 22:00:02.049550 :9330F0BE:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 22:00:02.049551 :9330F0BF:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 22:00:02.049551 :9330F0C0:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 22:00:02.049551 :9330F0C1:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 22:00:02.050114 :9330F0CB: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-05-05 22:00:02.054840 :9330F0E0: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-05-05 22:00:02.054878 :9330F0E5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-05 22:00:02.072002 :9330F2B7: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-05-05 22:00:02.072227 :9330F2BF: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-05-05 22:00:02.072397 :9330F2C7: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-05-05 22:00:02.072567 :9330F2CF: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-05-05 22:00:02.072730 :9330F2D7: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-05-05 22:00:02.072914 :9330F2DF: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-05-05 22:00:02.073100 :9330F2E7: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-05-05 22:00:02.073259 :9330F2EF: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-05-05 22:00:02.073413 :9330F2F7: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-05-05 22:00:02.073567 :9330F2FF: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-05-05 22:00:02.073726 :9330F307: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-05-05 22:00:02.073879 :9330F30F: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-05-05 22:00:02.074025 :9330F317: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-05-05 22:00:02.074195 :9330F31F: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-05-05 22:00:02.074358 :9330F327: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-05-05 22:00:02.074511 :9330F32F: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-05-05 22:00:02.074668 :9330F337: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-05-05 22:00:02.075015 :9330F33F: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-05-05 22:00:02.075189 :9330F347: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-05-05 22:00:02.075349 :9330F34F: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-05-05 22:00:02.075640 :9330F357: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-05-05 22:00:02.075949 :9330F35F: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-05-05 22:00:02.076237 :9330F367: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-05-05 22:00:02.076880 :9330F36F: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-05-05 22:00:02.077132 :9330F377: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-05-05 22:00:02.103975 :9330F37F: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-05-05 22:00:03.764571 :9330F664: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-05-05 22:00:03.772843*:9330F697:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002B4E00F8 estart=1746453602 eid=16777306 ctx=0x000000077B2E3E40 cwh=0x0000000029C906F8 cpu=15625 buffg=240 interb=0 r=0 rb=0 w=0 wb=0 2025-05-05 22:00:03.772843*:9330F69B:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002B4E00F8 curCtx=0x00000000396E1C60 pubTabIdxCnt=0 2025-05-05 22:00:03.772843*:9330F69D:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002B4E00F8 2025-05-05 22:00:03.772843*:9330F6A1:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002B4E00F8 2025-05-05 22:00:03.772843*:9330F6B2:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002B4E00F8 curCtx=0x00000000396E1C60 xsc->flg4=65792 flags=1 2025-05-05 22:00:03.772843*:9330F6B3:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002B4E00F8 2025-05-05 22:00:03.787195 :9330F6B4: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-05-05 22:00:03.789565 :9330F6D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-05 22:00:03.789800 :9330F6D2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-05 22:00:03.791145 :9330F6D3:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 7, ext 1, nex 3 2025-05-05 22:00:03.791153 :9330F6D4:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x008c12f1 where: ktspbwh1: ktspfsrch 2025-05-05 22:00:03.791376 :9330F6D5: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-05-05 22:00:03.791502 :9330F6D8: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-05-05 22:00:03.792608 :9330F6EA: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-05-05 22:00:03.794452 :9330F6F2: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-05-05 22:00:03.794790 :9330F6FA: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-05-05 22:00:03.850961*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-05-05 22:00:03.850961*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-05 22:00:03.850961*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-05 22:00:03.866587*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-05 22:00:03.866587*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-05 22:00:03.866587*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-05 22:00:03.866587*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-05 22:00:03.944426 :9330F7E2: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-05-05 22:00:05.840575 :9330F92D: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-05-05 22:00:05.840589 :9330F92E:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.00f.0001c528 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 10900, J003)