Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250526220008\orcl_j003_12548_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:37279M/63366M, Ph+PgF:44233M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 12548, image: ORACLE.EXE (J003) *** 2025-05-26 22:00:08.938 *** SESSION ID:(233.23553) 2025-05-26 22:00:08.938 *** 2025-05-26 22:00:08.938 Process diagnostic dump for ORACLE.EXE (J003), OS id=12548, pid: 29, proc_ser: 17, sid: 233, sess_ser: 23553 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12548 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12498, hash value=3656603050 Current Wait Stack: Not in wait; last wait ended 1.040920 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 1.040944 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=130 seq_num=131 snap_id=1 wait times: snap=0.000223 sec, exc=0.000223 sec, total=0.000223 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 1: waited for 'log file sequential read' log#=0x27f3, block#=0x0, blocks=0x0 wait_id=129 seq_num=130 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.005948 sec of elapsed time 2: waited for 'log file sequential read' log#=0x27f3, block#=0x0, blocks=0x0 wait_id=128 seq_num=129 snap_id=1 wait times: snap=0.000017 sec, exc=0.000017 sec, total=0.000017 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.559066 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x5800, blocks=0x800 wait_id=127 seq_num=128 snap_id=1 wait times: snap=0.000285 sec, exc=0.000285 sec, total=0.000285 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#=0x5000, blocks=0x800 wait_id=126 seq_num=127 snap_id=1 wait times: snap=0.000269 sec, exc=0.000269 sec, total=0.000269 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000019 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0x4800, blocks=0x800 wait_id=125 seq_num=126 snap_id=1 wait times: snap=0.000326 sec, exc=0.000326 sec, total=0.000326 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.051469 sec of elapsed time 6: waited for 'log file sequential read' log#=0x27f3, block#=0x800, blocks=0x800 wait_id=124 seq_num=125 snap_id=1 wait times: snap=0.000201 sec, exc=0.000201 sec, total=0.000201 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002649 sec of elapsed time 7: waited for 'log file sequential read' log#=0x27f3, block#=0x0, blocks=0x0 wait_id=123 seq_num=124 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.000121 sec of elapsed time 8: waited for 'log file sequential read' log#=0x27f3, block#=0x2, blocks=0x7fe wait_id=122 seq_num=123 snap_id=1 wait times: snap=0.000227 sec, exc=0.000227 sec, total=0.000227 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000133 sec of elapsed time 9: waited for 'log file sequential read' log#=0x0, block#=0x1, blocks=0x1 wait_id=121 seq_num=122 snap_id=1 wait times: snap=0.000047 sec, exc=0.000047 sec, total=0.000047 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 23553 --------------------------------------------------- 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:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-26 22:00:08.938 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 12548, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-26 01:00:00.812846 :9C079BAB:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14524 osp_idx=27 osp_ver=11738 osp_pg=0 (spawn #219573) 2025-05-26 01:00:00.812847 :9C079BAC: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-26 01:00:00.812848 :9C079BAD:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=82 time=1196973063 2025-05-26 01:00:00.812848 :9C079BAE:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 01:00:00.812849 :9C079BAF:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 01:00:00.812849 :9C079BB0:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 01:00:00.812850 :9C079BB1:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 01:00:00.812850 :9C079BB2:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 01:00:00.813429 :9C079BB3: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-26 01:00:30.898408 :9C07A62A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 01:15:51.894670 :9C08DC94:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 01:15:51.882 2025-05-26 01:15:51.894673 :9C08DC95:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13924 pso_num=29 pso_serial#=10 2025-05-26 01:15:51.894823 :9C08DC96:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13924 osp_idx=27 osp_ver=11739 osp_pg=0 (spawn #219614) 2025-05-26 01:15:51.894824 :9C08DC97: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-26 01:15:51.894824 :9C08DC98:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=83 time=1197924141 2025-05-26 01:15:51.894824 :9C08DC99:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 01:15:51.894825 :9C08DC9A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 01:15:51.894825 :9C08DC9B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 01:15:51.894826 :9C08DC9C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 01:15:51.894826 :9C08DC9D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 01:15:51.895362 :9C08DC9E: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-26 01:15:51.895401 :9C08DCA4: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-26 01:15:51.899491 :9C08DCBD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:15:51.899536 :9C08DCBE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:15:51.899798 :9C08DCBF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:15:51.899814 :9C08DCC0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:15:51.900033 :9C08DCC1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:15:51.900047 :9C08DCC2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:15:51.900256 :9C08DCC3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:15:51.900270 :9C08DCC4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:15:51.900481 :9C08DCC5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:15:51.900493 :9C08DCC6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:15:51.900693 :9C08DCC7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:15:51.900705 :9C08DCC8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:15:51.903074 :9C08DCC9:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 01:35:54.691168 :9C0A64D5:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 01:35:54.677 2025-05-26 01:35:54.691170 :9C0A64D6:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9628 pso_num=29 pso_serial#=11 2025-05-26 01:35:54.691380 :9C0A64D7:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9628 (legacy spawn) 2025-05-26 01:35:54.698311 :9C0A64DB: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-26 01:35:54.698520 :9C0A64E0: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-05-26 01:35:54.699313 :9C0A64E5:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 01:45:56.082507 :9C0B2857:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 01:45:56.070 2025-05-26 01:45:56.082509 :9C0B2858:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10124 pso_num=29 pso_serial#=12 2025-05-26 01:45:56.082650 :9C0B2859:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10124 osp_idx=27 osp_ver=11741 osp_pg=0 (spawn #219682) 2025-05-26 01:45:56.082651 :9C0B285A: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-26 01:45:56.082651 :9C0B285B:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=84 time=1199728329 2025-05-26 01:45:56.082652 :9C0B285C:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 01:45:56.082652 :9C0B285D:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 01:45:56.082653 :9C0B285E:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 01:45:56.082653 :9C0B285F:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 01:45:56.082653 :9C0B2860:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 01:45:56.083152 :9C0B2861: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-26 01:45:56.083197 :9C0B2867: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-26 01:45:56.087240 :9C0B2880:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:45:56.087283 :9C0B2881:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:45:56.087531 :9C0B2882:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:45:56.087547 :9C0B2883:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:45:56.087759 :9C0B2884:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:45:56.087772 :9C0B2885:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:45:56.087973 :9C0B2886:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:45:56.087986 :9C0B2887:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:45:56.088188 :9C0B2888:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:45:56.088200 :9C0B2889:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:45:56.088404 :9C0B288A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-26 01:45:56.088417 :9C0B288B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-26 01:45:56.090772 :9C0B288C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 08:12:54.469599 :9C297DA0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 08:12:54.463 2025-05-26 08:12:54.469602 :9C297DA1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15336 pso_num=29 pso_serial#=13 2025-05-26 08:12:54.472544 :9C297DA2:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15336 osp_idx=27 osp_ver=11742 osp_pg=0 (spawn #220578) 2025-05-26 08:12:54.472545 :9C297DA3: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-26 08:12:54.472545 :9C297DA4:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=85 time=1222946704 2025-05-26 08:12:54.472546 :9C297DA5:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 08:12:54.472546 :9C297DA6:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 08:12:54.472547 :9C297DA7:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 08:12:54.472547 :9C297DA8:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 08:12:54.472548 :9C297DA9:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 08:12:54.475166 :9C297DAA: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-26 08:12:54.475213 :9C297DB0: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-26 08:12:54.475589 :9C297DB1:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 08:12:56.674978 :9C297EE9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 08:12:56.666 2025-05-26 08:12:56.674979 :9C297EEA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11720 pso_num=29 pso_serial#=14 2025-05-26 08:12:56.675110 :9C297EEB:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11720 osp_idx=27 osp_ver=11743 osp_pg=0 (spawn #220580) 2025-05-26 08:12:56.675111 :9C297EEC: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-26 08:12:56.675112 :9C297EED:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=86 time=1222948922 2025-05-26 08:12:56.675112 :9C297EEE:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 08:12:56.675113 :9C297EEF:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 08:12:56.675113 :9C297EF0:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 08:12:56.675113 :9C297EF1:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 08:12:56.675114 :9C297EF2:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 08:12:56.675630 :9C297EF3: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-26 08:12:56.675668 :9C297EF9: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-26 08:12:56.676010 :9C297EFA:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 08:12:57.134090 :9C297F9A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 08:12:57.119 2025-05-26 08:12:57.134092 :9C297F9B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=6428 pso_num=29 pso_serial#=15 2025-05-26 08:12:57.134222 :9C297F9C:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=6428 (legacy spawn) 2025-05-26 08:12:57.140714 :9C297F9D: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-26 08:12:57.141194 :9C297FA6: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-05-26 08:12:57.142049 :9C297FA7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 08:12:57.150572 :9C297FAA:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 08:12:57.135 2025-05-26 08:12:57.150574 :9C297FAB:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10020 pso_num=29 pso_serial#=16 2025-05-26 08:12:57.150722 :9C297FAC:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=10020 (legacy spawn) 2025-05-26 08:12:57.157226 :9C297FAD: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-26 08:12:57.157548 :9C297FB6: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-05-26 08:12:57.158371 :9C297FB7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-26 22:00:02.076552 :9C6A59E2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-26 22:00:02.070 2025-05-26 22:00:02.076554 :9C6A59E3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12548 pso_num=29 pso_serial#=17 2025-05-26 22:00:02.076672 :9C6A59E4:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12548 osp_idx=27 osp_ver=11746 osp_pg=0 (spawn #222484) 2025-05-26 22:00:02.076673 :9C6A59E5: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-26 22:00:02.076673 :9C6A59E6:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=87 time=1272574329 2025-05-26 22:00:02.076674 :9C6A59E7:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 22:00:02.076674 :9C6A59E8:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 22:00:02.076675 :9C6A59E9:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 22:00:02.076675 :9C6A59EA:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 22:00:02.076676 :9C6A59EB:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 22:00:02.077217 :9C6A59EE: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-26 22:00:02.082339 :9C6A5A1C: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-26 22:00:02.082381 :9C6A5A20:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-26 22:00:02.100073 :9C6A5BFA: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-26 22:00:02.100375 :9C6A5C02: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-26 22:00:02.100668 :9C6A5C0A: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-26 22:00:02.100865 :9C6A5C12: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-26 22:00:02.101035 :9C6A5C1A: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-26 22:00:02.101202 :9C6A5C22: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-26 22:00:02.101361 :9C6A5C2A: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-26 22:00:02.101535 :9C6A5C32: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-26 22:00:02.101707 :9C6A5C3A: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-26 22:00:02.101859 :9C6A5C42: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-26 22:00:02.102010 :9C6A5C4A: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-26 22:00:02.102171 :9C6A5C52: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-26 22:00:02.102330 :9C6A5C5A: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-26 22:00:02.102480 :9C6A5C62: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-26 22:00:02.102633 :9C6A5C6A: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-26 22:00:02.102802 :9C6A5C72: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-26 22:00:02.102962 :9C6A5C7A: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-26 22:00:02.103112 :9C6A5C82: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-26 22:00:02.103275 :9C6A5C8A: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-26 22:00:02.103648 :9C6A5C92: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-26 22:00:02.103832 :9C6A5C9A: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-26 22:00:02.103984 :9C6A5CA2: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-26 22:00:02.104250 :9C6A5CAA: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-26 22:00:02.104493 :9C6A5CB2: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-26 22:00:02.104729 :9C6A5CBA: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-26 22:00:02.105421 :9C6A5CC2: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-26 22:00:02.124918 :9C6A5CCE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-05-26 22:00:02.132340 :9C6A5CDE: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-26 22:00:03.204430*:9C6A5FF9:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB03AD0 estart=1748268002 eid=18823548 ctx=0x0000000777968158 cwh=0x0000000029990AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-05-26 22:00:03.204430*:9C6A5FFA:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB03AD0 curCtx=0x000000003F9EC4B8 pubTabIdxCnt=0 2025-05-26 22:00:03.204430*:9C6A5FFB:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB03AD0 2025-05-26 22:00:03.204430*:9C6A5FFC:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB03AD0 2025-05-26 22:00:03.204430*:9C6A5FFD:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB3AAF8 estart=1748268002 eid=16777351 ctx=0x000000077B54EAC8 cwh=0x0000000029990608 cpu=906250 buffg=51139 interb=196608 r=24 rb=196608 w=0 wb=0 2025-05-26 22:00:03.204430*:9C6A5FFE:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB3AAF8 curCtx=0x000000003F801240 pubTabIdxCnt=0 2025-05-26 22:00:03.204430*:9C6A5FFF:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB3AAF8 2025-05-26 22:00:03.204430*:9C6A6000:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB3AAF8 2025-05-26 22:00:03.204430*:9C6A6001:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB03AD0 curCtx=0x000000003F9EC4B8 xsc->flg4=65792 flags=1 2025-05-26 22:00:03.204430*:9C6A6002:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB03AD0 2025-05-26 22:00:03.782571*:9C6A60CD:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB3AAF8 curCtx=0x000000003F801240 xsc->flg4=65792 flags=2 2025-05-26 22:00:03.782571*:9C6A60CE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB3AAF8 2025-05-26 22:00:03.782743 :9C6A60CF: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-26 22:00:03.804891 :9C6A6108: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-26 22:00:03.807211 :9C6A6110:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-26 22:00:03.807453 :9C6A6111:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-26 22:00:03.808447 :9C6A6112: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-26 22:00:03.808553 :9C6A6115: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-26 22:00:03.809519 :9C6A6127: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-26 22:00:03.811327 :9C6A612F: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-26 22:00:03.811659 :9C6A6137: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-26 22:00:03.876317*: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-26 22:00:03.876317*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-26 22:00:03.876317*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-26 22:00:03.876317*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-26 22:00:03.876317*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-26 22:00:03.876317*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-26 22:00:03.876317*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-26 22:00:03.959614 :9C6A61CD: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-26 22:00:05.857345 :9C6A6386: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-26 22:00:05.857357 :9C6A6387:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0008.001.0000ca94 2025-05-26 22:00:08.368302 :9C6A6504: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-26 22:00:08.369952 :9C6A650C: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-26 22:00:08.380864 :9C6A6514: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-26 22:00:08.405485 :9C6A651C: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: 12548, J003)