Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250513220006\orcl_j003_9988_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:37408M/63366M, Ph+PgF:44705M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 9988, image: ORACLE.EXE (J003) *** 2025-05-13 22:00:06.721 *** SESSION ID:(233.21831) 2025-05-13 22:00:06.721 *** 2025-05-13 22:00:06.721 Process diagnostic dump for ORACLE.EXE (J003), OS id=9988, pid: 29, proc_ser: 182, sid: 233, sess_ser: 21831 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 9988 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12427, hash value=4181568622 Current Wait Stack: Not in wait; last wait ended 2.741183 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.741209 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.000186 sec, exc=0.000186 sec, total=0.000186 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.067531 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.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.762074 sec of elapsed time 2: 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.026774 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.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.012859 sec of elapsed time 4: 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.051121 sec of elapsed time 5: 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.011766 sec, exc=0.011766 sec, total=0.011766 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007850 sec of elapsed time 6: 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.000108 sec, exc=0.000108 sec, total=0.000108 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.264746 sec of elapsed time 7: 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.005917 sec, exc=0.005917 sec, total=0.005917 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000213 sec of elapsed time 8: 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.000124 sec, exc=0.000124 sec, total=0.000124 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007978 sec of elapsed time 9: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.000000 sec, exc=0.000000 sec, total=0.000000 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.000053 sec of elapsed time Sampled Session History of session 233 serial 21831 --------------------------------------------------- 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-13 22:00:06.721 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 9988, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-13 01:32:43.943415 :9652B1F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-13 01:32:43.943428 :9652B1F1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-13 01:32:43.943643 :9652B1F2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-13 01:32:43.943656 :9652B1F3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-13 01:32:43.943861 :9652B1F4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-13 01:32:43.943873 :9652B1F5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-13 01:32:43.946103 :9652B1F6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 01:33:03.728807 :9652B7A8:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 01:33:03.726 2025-05-13 01:33:03.728809 :9652B7A9:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12956 pso_num=29 pso_serial#=173 2025-05-13 01:33:03.728943 :9652B7AA:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=12956 (legacy spawn) 2025-05-13 01:33:03.746208 :9652B7AE: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-13 01:33:03.746367 :9652B7B7: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-13 01:33:03.747186 :9652B7B8:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 02:02:47.968603 :9654FED2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 02:02:47.964 2025-05-13 02:02:47.968604 :9654FED3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=6268 pso_num=29 pso_serial#=174 2025-05-13 02:02:47.968748 :9654FED4:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=6268 osp_idx=27 osp_ver=10883 osp_pg=0 (spawn #176389) 2025-05-13 02:02:47.968749 :9654FED5: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-13 02:02:47.968749 :9654FED6:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=53 time=77577829 2025-05-13 02:02:47.968750 :9654FED7:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 02:02:47.968751 :9654FED8:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 02:02:47.968751 :9654FED9:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 02:02:47.968751 :9654FEDA:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 02:02:47.968752 :9654FEDB:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 02:02:47.969275 :9654FEDC: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-13 02:02:47.969321 :9654FEE2: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-13 02:02:47.978328 :9654FF0A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 03:02:56.487258 :96599C09:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 03:02:56.484 2025-05-13 03:02:56.487259 :96599C0A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11284 pso_num=29 pso_serial#=175 2025-05-13 03:02:56.487406 :96599C0B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11284 osp_idx=27 osp_ver=10884 osp_pg=0 (spawn #176528) 2025-05-13 03:02:56.487407 :96599C0C: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-13 03:02:56.487407 :96599C0D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=54 time=81186344 2025-05-13 03:02:56.487408 :96599C0E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 03:02:56.487408 :96599C0F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 03:02:56.487409 :96599C10:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 03:02:56.487409 :96599C11:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 03:02:56.487410 :96599C12:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 03:02:56.487941 :96599C13: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-13 03:02:56.487985 :96599C1A: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-13 03:02:56.497185 :96599C40:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 04:03:04.582952 :965E37FB:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 04:03:04.580 2025-05-13 04:03:04.582953 :965E37FC:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7452 pso_num=29 pso_serial#=176 2025-05-13 04:03:04.583092 :965E37FD:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=7452 osp_idx=27 osp_ver=10885 osp_pg=0 (spawn #176666) 2025-05-13 04:03:04.583092 :965E37FE: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-13 04:03:04.583093 :965E37FF:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=55 time=84794438 2025-05-13 04:03:04.583094 :965E3800:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 04:03:04.583094 :965E3801:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 04:03:04.583094 :965E3802:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 04:03:04.583095 :965E3803:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 04:03:04.583095 :965E3804:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 04:03:04.583656 :965E3805: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-13 04:03:04.583705 :965E380B: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-13 04:03:04.592739 :965E3823:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 05:03:12.160171 :9662D063:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 05:03:12.156 2025-05-13 05:03:12.160172 :9662D064:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11116 pso_num=29 pso_serial#=177 2025-05-13 05:03:12.160306 :9662D065:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11116 osp_idx=27 osp_ver=10886 osp_pg=0 (spawn #176805) 2025-05-13 05:03:12.160307 :9662D066: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-13 05:03:12.160308 :9662D067:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=56 time=88402016 2025-05-13 05:03:12.160308 :9662D068:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 05:03:12.160309 :9662D069:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 05:03:12.160309 :9662D06A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 05:03:12.160309 :9662D06B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 05:03:12.160310 :9662D06C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 05:03:12.160901 :9662D06D: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-13 05:03:12.160948 :9662D073: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-13 05:03:12.169994 :9662D08B:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 06:03:20.125270 :96676578:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 06:03:20.121 2025-05-13 06:03:20.125271 :96676579:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10896 pso_num=29 pso_serial#=178 2025-05-13 06:03:20.125401 :9667657A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10896 osp_idx=27 osp_ver=10887 osp_pg=0 (spawn #176943) 2025-05-13 06:03:20.125401 :9667657B: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-13 06:03:20.125402 :9667657C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=57 time=92009985 2025-05-13 06:03:20.125402 :9667657D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 06:03:20.125403 :9667657E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 06:03:20.125403 :9667657F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 06:03:20.125403 :96676580:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 06:03:20.125404 :96676581:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 06:03:20.125972 :96676582: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-13 06:03:20.126024 :96676588: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-13 06:03:20.135134 :966765A0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 07:03:28.754197 :966C006C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 07:03:28.750 2025-05-13 07:03:28.754198 :966C006D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12512 pso_num=29 pso_serial#=179 2025-05-13 07:03:28.754336 :966C006E:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12512 osp_idx=27 osp_ver=10888 osp_pg=0 (spawn #177083) 2025-05-13 07:03:28.754336 :966C006F: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-13 07:03:28.754337 :966C0070:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=58 time=95618610 2025-05-13 07:03:28.754337 :966C0071:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:03:28.754338 :966C0072:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:03:28.754338 :966C0073:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:03:28.754338 :966C0074:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:03:28.754338 :966C0075:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:03:28.754861 :966C0076: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-13 07:03:28.754912 :966C007C: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-13 07:03:28.764160 :966C0094:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 08:03:36.846077 :9670EA44:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 08:03:36.843 2025-05-13 08:03:36.846078 :9670EA45:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10596 pso_num=29 pso_serial#=180 2025-05-13 08:03:36.846217 :9670EA46:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10596 osp_idx=27 osp_ver=10889 osp_pg=0 (spawn #177226) 2025-05-13 08:03:36.846218 :9670EA47: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-13 08:03:36.846219 :9670EA48:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=59 time=99226704 2025-05-13 08:03:36.846219 :9670EA49:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 08:03:36.846219 :9670EA4A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 08:03:36.846220 :9670EA4B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 08:03:36.846220 :9670EA4C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 08:03:36.846221 :9670EA4D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 08:03:36.846746 :9670EA4E: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-13 08:03:36.846794 :9670EA54: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-13 08:03:36.856056 :9670EA7C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 09:03:44.852942 :9675AD1B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 09:03:44.849 2025-05-13 09:03:44.852944 :9675AD1C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12956 pso_num=29 pso_serial#=181 2025-05-13 09:03:44.853085 :9675AD1D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12956 osp_idx=27 osp_ver=10890 osp_pg=0 (spawn #177365) 2025-05-13 09:03:44.853086 :9675AD1E: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-13 09:03:44.853086 :9675AD1F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=60 time=102834704 2025-05-13 09:03:44.853086 :9675AD20:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 09:03:44.853087 :9675AD21:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 09:03:44.853087 :9675AD22:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 09:03:44.853088 :9675AD23:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 09:03:44.853088 :9675AD24:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 09:03:44.853633 :9675AD25: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-13 09:03:44.853685 :9675AD2B: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-13 09:03:44.862657 :9675AD43:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-13 22:00:02.153674 :96B136A0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-13 22:00:02.147 2025-05-13 22:00:02.153675 :96B136A1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9988 pso_num=29 pso_serial#=182 2025-05-13 22:00:02.153816 :96B136A7:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=9988 osp_idx=27 osp_ver=10891 osp_pg=0 (spawn #179157) 2025-05-13 22:00:02.153817 :96B136A8: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-13 22:00:02.153818 :96B136A9:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=61 time=149412016 2025-05-13 22:00:02.153819 :96B136AA:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 22:00:02.153819 :96B136AB:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 22:00:02.153820 :96B136AC:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 22:00:02.153821 :96B136AD:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 22:00:02.153822 :96B136AE:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 22:00:02.154375 :96B136AF: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-13 22:00:02.159177 :96B136CE: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-13 22:00:02.159216 :96B136D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-13 22:00:02.176917 :96B138A1: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-13 22:00:02.177242 :96B138A9: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-13 22:00:02.177439 :96B138B1: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-13 22:00:02.177608 :96B138B9: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-13 22:00:02.177779 :96B138C1: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-13 22:00:02.177939 :96B138C9: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-13 22:00:02.178105 :96B138D1: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-13 22:00:02.178263 :96B138D9: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-13 22:00:02.178427 :96B13910: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-13 22:00:02.178579 :96B13918: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-13 22:00:02.178738 :96B13920: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-13 22:00:02.178891 :96B13928: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-13 22:00:02.179040 :96B13930: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-13 22:00:02.179215 :96B13938: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-13 22:00:02.179377 :96B13940: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-13 22:00:02.179527 :96B13948: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-13 22:00:02.179679 :96B13950: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-13 22:00:02.180108 :96B13958: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-13 22:00:02.180337 :96B13960: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-13 22:00:02.180502 :96B13968: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-13 22:00:02.180797 :96B13970: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-13 22:00:02.181058 :96B13978: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-13 22:00:02.181305 :96B13980: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-13 22:00:02.181920 :96B13988: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-13 22:00:02.208646 :96B13990: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-13 22:00:03.615824*:96B13C12:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000030183AD0 estart=1747144803 eid=18389146 ctx=0x0000000777968158 cwh=0x0000000029C90AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-05-13 22:00:03.615824*:96B13C13:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000030183AD0 curCtx=0x000000003B8AC4B8 pubTabIdxCnt=0 2025-05-13 22:00:03.615824*:96B13C14:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000030183AD0 2025-05-13 22:00:03.615824*:96B13C15:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000030183AD0 2025-05-13 22:00:03.615824*:96B13C16:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000301BAAF8 estart=1747144801 eid=16777322 ctx=0x000000077B54EAC8 cwh=0x0000000029C90608 cpu=1203125 buffg=66108 interb=204800 r=25 rb=204800 w=0 wb=0 2025-05-13 22:00:03.615824*:96B13C17:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000301BAAF8 curCtx=0x000000003B4C1240 pubTabIdxCnt=0 2025-05-13 22:00:03.615824*:96B13C18:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000301BAAF8 2025-05-13 22:00:03.615824*:96B13C19:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000301BAAF8 2025-05-13 22:00:03.615824*:96B13C1A:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000030183AD0 curCtx=0x000000003B8AC4B8 xsc->flg4=65792 flags=1 2025-05-13 22:00:03.615824*:96B13C1B:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000030183AD0 2025-05-13 22:00:03.897074*:96B13C1F:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000301BAAF8 curCtx=0x000000003B4C1240 xsc->flg4=65792 flags=2 2025-05-13 22:00:03.897074*:96B13C20:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000301BAAF8 2025-05-13 22:00:03.903485 :96B13C26: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-13 22:00:03.926509 :96B13C5E: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-13 22:00:03.928881 :96B13C66:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-13 22:00:03.929147 :96B13C67:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-13 22:00:03.930217 :96B13C68: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-13 22:00:03.930325 :96B13C6B: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-13 22:00:03.931317 :96B13C7D: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-13 22:00:03.933147 :96B13C85: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-13 22:00:03.933490 :96B13C8D: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-13 22:00:03.991011*: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-13 22:00:03.991011*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-13 22:00:03.991011*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-13 22:00:03.991011*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-13 22:00:03.991011*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-13 22:00:03.991011*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-13 22:00:03.991011*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-13 22:00:04.069701 :96B13D7A: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-13 22:00:05.938099 :96B13F14: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-13 22:00:05.938110 :96B13F15:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0005.019.0000c0b1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 9988, J003)