Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250531060006\orcl_j003_14732_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:37249M/63366M, Ph+PgF:44127M/72582M 
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 29
Windows thread id: 14732, image: ORACLE.EXE (J003)


*** 2025-05-31 06:00:06.243
*** SESSION ID:(233.23793) 2025-05-31 06:00:06.243
 

*** 2025-05-31 06:00:06.243
Process diagnostic dump for ORACLE.EXE (J003), OS id=14732,
pid: 29, proc_ser: 135, sid: 233, sess_ser: 23793 
-------------------------------------------------------------------------------
current sql: call dbms_stats.gather_database_stats_job_proc (  )
client details:
  O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 14732
  machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003)
  application name: DBMS_SCHEDULER, hash value=2478762354
  action name: ORA$AT_OS_OPT_SY_12513, hash value=2883132175
Current Wait Stack:
  Not in wait; last wait ended 2.377009 sec ago 
Wait State:
  fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1
Session Wait History:
    elapsed time of 2.377035 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.000172 sec, exc=0.000172 sec, total=0.000172 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.067813 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.000006 sec, exc=0.000006 sec, total=0.000006 sec
    wait times: max=307445734561 min 49 sec
    wait counts: calls=0 os=0
    occurred after 0.752653 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.000002 sec, exc=0.000002 sec, total=0.000002 sec
    wait times: max=307445734561 min 49 sec
    wait counts: calls=0 os=0
    occurred after 0.025227 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.012807 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.000080 sec, exc=0.000080 sec, total=0.000080 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.049540 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.004489 sec, exc=0.004489 sec, total=0.004489 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.007947 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.004395 sec, exc=0.004395 sec, total=0.004395 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.265119 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.000132 sec, exc=0.000132 sec, total=0.000132 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.000319 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.005110 sec, exc=0.005110 sec, total=0.005110 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.007939 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.000001 sec, exc=0.000001 sec, total=0.000001 sec
    wait times: max=307445734561 min 49 sec
    wait counts: calls=0 os=0
    occurred after 0.000049 sec of elapsed time
Sampled Session History of session 233 serial 23793
---------------------------------------------------
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
---------------------------------------------------
  [4 samples,                                              06:00:03 - 06:00:06]
    not in wait at each sample
  [1 sample,                                                          06:00:02]
    waited for 'null event', seq_num: 0
      p1: ''=0x0
      p2: ''=0x0
      p3: ''=0x0
      time_waited: 0.000100 sec (sample interval: 0 sec)
  [1 sample,                                                          06:00:01]
    idle wait at each sample
  [session created at: 06:00:02]
---------------------------------------------------
Sampled Session History Summary:
  longest_non_idle_wait: 'null event'
  [1 sample, 06:00:02 ]
      time_waited: 0.000100 sec (sample interval: 0 sec)
---------------------------------------------------
-------------------------------------------------------------------------------
Process diagnostic dump actual duration=0.000000 sec
  (max dump time=30.000000 sec)

*** 2025-05-31 06:00:06.243
 
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 29 (osid: 14732, J003)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
-------------------------------------------------------------------------------
2025-05-30 23:01:57.269432 :9E30BA8C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-05-30 23:01:57.269432 :9E30BA8D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-05-30 23:01:57.269974 :9E30BA8E: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-30 23:01:57.270018 :9E30BA94: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-30 23:01:57.273978 :9E30BAAC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517
2025-05-30 23:01:57.274028 :9E30BAAD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517
2025-05-30 23:01:57.274283 :9E30BAAE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517
2025-05-30 23:01:57.274299 :9E30BAAF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517
2025-05-30 23:01:57.274519 :9E30BAB0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517
2025-05-30 23:01:57.274533 :9E30BAB1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517
2025-05-30 23:01:57.274738 :9E30BAB2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517
2025-05-30 23:01:57.274751 :9E30BAB3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517
2025-05-30 23:01:57.274965 :9E30BAB4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517
2025-05-30 23:01:57.274978 :9E30BAB5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517
2025-05-30 23:01:57.275181 :9E30BAB6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517
2025-05-30 23:01:57.275193 :9E30BAB7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517
2025-05-30 23:01:57.277491 :9E30BADA:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-30 23:59:01.441493 :9E3529EC:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-30 23:59:01.441
2025-05-30 23:59:01.441495 :9E3529ED:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14960 pso_num=29 pso_serial#=124
2025-05-30 23:59:01.441653 :9E3529EE:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14960 (legacy spawn)
2025-05-30 23:59:01.455526 :9E3529EF: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-30 23:59:04.853525 :9E352B1F: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-30 23:59:04.853682 :9E352B28: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-30 23:59:04.854777 :9E352B29:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-30 23:59:09.769930 :9E352CC7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-30 23:59:09.759
2025-05-30 23:59:09.769933 :9E352CC8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14260 pso_num=29 pso_serial#=125
2025-05-30 23:59:09.770070 :9E352CC9:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14260 (legacy spawn)
2025-05-30 23:59:09.783833 :9E352CCA: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-30 23:59:13.075864 :9E352DB7: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-30 23:59:13.076033 :9E352DBC: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-30 23:59:13.077157 :9E352DC1:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-30 23:59:13.339218 :9E352DF8:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-30 23:59:13.325
2025-05-30 23:59:13.339220 :9E352DF9:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15184 pso_num=29 pso_serial#=126
2025-05-30 23:59:13.339351 :9E352DFA:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15184 (legacy spawn)
2025-05-30 23:59:13.353741 :9E352DFE: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-30 23:59:46.477212 :9E353A17:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-30 23:59:46.620931 :9E353A1A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-30 23:59:46.614
2025-05-30 23:59:46.620933 :9E353A1B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13612 pso_num=29 pso_serial#=127
2025-05-30 23:59:46.621068 :9E353A1C:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13612 (legacy spawn)
2025-05-30 23:59:46.634866 :9E353A1D: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-30 23:59:49.874601 :9E353B2E: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-30 23:59:49.874780 :9E353B37: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-30 23:59:49.875975 :9E353B38:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-30 23:59:50.128289 :9E353B71:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-30 23:59:50.125
2025-05-30 23:59:50.128291 :9E353B72:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13012 pso_num=29 pso_serial#=128
2025-05-30 23:59:50.128426 :9E353B73:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13012 (legacy spawn)
2025-05-30 23:59:50.142653 :9E353B74: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-31 00:00:23.303783 :9E3547C9:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-31 01:00:12.450235 :9E39F28B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-31 01:00:12.445
2025-05-31 01:00:12.450238 :9E39F28C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13756 pso_num=29 pso_serial#=129
2025-05-31 01:00:12.450383 :9E39F28D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13756 osp_idx=27 osp_ver=11858 osp_pg=0 (spawn #236226)
2025-05-31 01:00:12.450383 :9E39F28E: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-31 01:00:12.450384 :9E39F28F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=137 time=1628971094
2025-05-31 01:00:12.450384 :9E39F290:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs
2025-05-31 01:00:12.450384 :9E39F291:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs
2025-05-31 01:00:12.450385 :9E39F292:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs
2025-05-31 01:00:12.450385 :9E39F293:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-05-31 01:00:12.450385 :9E39F294:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-05-31 01:00:12.450895 :9E39F295: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-31 01:00:12.450941 :9E39F29B: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-31 01:00:12.455302 :9E39F2AE: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-31 01:00:12.477499 :9E39F2B6: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-31 01:00:12.491993 :9E39F2BE: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-31 01:00:12.520045 :9E39F2C6: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-31 01:00:12.523774 :9E39F2CE: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-31 01:00:12.527481 :9E39F2D6: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-31 01:00:12.531665 :9E39F2DE: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-31 01:00:12.532763 :9E39F2E6: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-31 01:00:13.486288*:9E39F36E:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000029AA1510 estart=1748624412 eid=16778870 ctx=0x000000077BA4B1C8 cwh=0x0000000029A50B90 cpu=312500 buffg=0 interb=0 r=0 rb=0 w=0 wb=0
2025-05-31 01:00:13.486288*:9E39F36F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000029AA1510 curCtx=0x000000002B4C7648 pubTabIdxCnt=0
2025-05-31 01:00:13.486288*:9E39F370:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000029AA1510
2025-05-31 01:00:13.486288*:9E39F371:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000029AA1510
2025-05-31 01:00:13.486288*:9E39F372:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000029A61970 estart=1748624412 eid=16778861 ctx=0x0000000787AD5BF0 cwh=0x0000000029A50AA0 cpu=312500 buffg=0 interb=0 r=0 rb=0 w=0 wb=0
2025-05-31 01:00:13.486288*:9E39F373:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000029A61970 curCtx=0x0000000029A66278 pubTabIdxCnt=0
2025-05-31 01:00:13.486288*:9E39F374:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000029A61970
2025-05-31 01:00:13.486288*:9E39F375:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000029A61970
2025-05-31 01:00:13.736286*:9E39F382:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000029AA1510 curCtx=0x000000002B4C7648 xsc->flg4=65792 flags=1
2025-05-31 01:00:13.736286*:9E39F383:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000029AA1510
2025-05-31 01:00:13.736286*:9E39F384:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000029A61970 curCtx=0x0000000029A66278 xsc->flg4=65792 flags=2
2025-05-31 01:00:13.736286*:9E39F385:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000029A61970
2025-05-31 01:00:13.807806 :9E39F386: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-31 01:00:13.839243 :9E39F38E: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-31 01:00:13.839580 :9E39F396: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-31 01:00:13.839858 :9E39F39E: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-31 01:00:13.839875 :9E39F3A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-05-31 01:00:13.839947 :9E39F3AB: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-31 01:00:13.843314 :9E39F3BB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-31 01:00:18.771038 :9E39F588:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-31 01:00:18.758
2025-05-31 01:00:18.771041 :9E39F589:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15080 pso_num=29 pso_serial#=130
2025-05-31 01:00:18.771187 :9E39F58A:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15080 (legacy spawn)
2025-05-31 01:00:18.777663 :9E39F58B: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-31 01:00:18.777847 :9E39F590: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-31 01:00:18.778665 :9E39F595:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-31 01:00:25.364436 :9E39F7EC:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-31 01:00:25.350
2025-05-31 01:00:25.364438 :9E39F7ED:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9584 pso_num=29 pso_serial#=131
2025-05-31 01:00:25.364586 :9E39F7EE:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9584 (legacy spawn)
2025-05-31 01:00:25.371091 :9E39F7EF: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-31 01:00:25.371271 :9E39F7F8: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-31 01:00:25.372092 :9E39F7F9:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-31 01:00:25.380679 :9E39F7FC:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-31 01:00:25.366
2025-05-31 01:00:25.380681 :9E39F7FD:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12656 pso_num=29 pso_serial#=132
2025-05-31 01:00:25.380818 :9E39F7FE:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=12656 (legacy spawn)
2025-05-31 01:00:25.399011 :9E39F7FF: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-31 01:00:25.399203 :9E39F808: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-31 01:00:25.400066 :9E39F809:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-31 01:00:28.442912 :9E39F8EF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-31 01:00:28.430
2025-05-31 01:00:28.442914 :9E39F8F0:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15160 pso_num=29 pso_serial#=133
2025-05-31 01:00:28.443053 :9E39F8F1:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15160 (legacy spawn)
2025-05-31 01:00:28.449592 :9E39F8F2: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-31 01:00:28.449768 :9E39F8FB: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-31 01:00:28.450548 :9E39F8FC:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-31 01:00:28.459075 :9E39F8FF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-31 01:00:28.445
2025-05-31 01:00:28.459077 :9E39F900:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14536 pso_num=29 pso_serial#=134
2025-05-31 01:00:28.459210 :9E39F901:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14536 (legacy spawn)
2025-05-31 01:00:28.465619 :9E39F902: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-31 01:00:28.465792 :9E39F90B: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-31 01:00:28.466572 :9E39F90C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted
2025-05-31 06:00:02.062188 :9E511E5E:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-31 06:00:02.055
2025-05-31 06:00:02.062190 :9E511E5F:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14732 pso_num=29 pso_serial#=135
2025-05-31 06:00:02.062316 :9E511E64:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14732 osp_idx=27 osp_ver=11864 osp_pg=0 (spawn #236922)
2025-05-31 06:00:02.062318 :9E511E65: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-31 06:00:02.062318 :9E511E66:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=138 time=1646960704
2025-05-31 06:00:02.062318 :9E511E67:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs
2025-05-31 06:00:02.062319 :9E511E68:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs
2025-05-31 06:00:02.062319 :9E511E69:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs
2025-05-31 06:00:02.062319 :9E511E6A:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-05-31 06:00:02.062320 :9E511E6B:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-05-31 06:00:02.062845 :9E511E71: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-31 06:00:02.067697 :9E511E90: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-31 06:00:02.067735 :9E511E93:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203
2025-05-31 06:00:02.085562 :9E511F37: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-31 06:00:02.085762 :9E511F3F: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-31 06:00:02.085930 :9E511F47: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-31 06:00:02.086083 :9E511F4F: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-31 06:00:02.086238 :9E511F57: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-31 06:00:02.086403 :9E511F5F: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-31 06:00:02.086563 :9E511F67: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-31 06:00:02.086729 :9E511F6F: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-31 06:00:02.086873 :9E511F77: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-31 06:00:02.087026 :9E511F7F: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-31 06:00:02.087174 :9E511F87: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-31 06:00:02.087329 :9E511F8F: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-31 06:00:02.087473 :9E511F97: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-31 06:00:02.087616 :9E511F9F: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-31 06:00:02.087793 :9E511FA7: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-31 06:00:02.087994 :9E511FAF: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-31 06:00:02.088175 :9E511FB7: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-31 06:00:02.108354 :9E511FBF: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-31 06:00:03.555331*:9E51238D:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB03AD0 estart=1748642403 eid=18903119 ctx=0x0000000777968158 cwh=0x000000002DB309C8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0
2025-05-31 06:00:03.555331*:9E51238E:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB03AD0 curCtx=0x0000000034157918 pubTabIdxCnt=0
2025-05-31 06:00:03.555331*:9E51238F:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB03AD0
2025-05-31 06:00:03.555331*:9E512390:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB03AD0
2025-05-31 06:00:03.555331*:9E512391:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB7B6F0 estart=1748642401 eid=16777356 ctx=0x000000077B54EAC8 cwh=0x000000002DB30518 cpu=1234375 buffg=68348 interb=196608 r=24 rb=196608 w=0 wb=0
2025-05-31 06:00:03.555331*:9E512392:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB7B6F0 curCtx=0x00000000320487D0 pubTabIdxCnt=0
2025-05-31 06:00:03.555331*:9E512393:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB7B6F0
2025-05-31 06:00:03.555331*:9E512394:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB7B6F0
2025-05-31 06:00:03.555331*:9E512395:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB03AD0 curCtx=0x0000000034157918 xsc->flg4=65792 flags=1
2025-05-31 06:00:03.555331*:9E512396:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB03AD0
2025-05-31 06:00:03.774065*:9E5124C7:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB7B6F0 curCtx=0x00000000320487D0 xsc->flg4=65792 flags=2
2025-05-31 06:00:03.774065*:9E5124C8:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB7B6F0
2025-05-31 06:00:03.785874 :9E5124C9: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-31 06:00:03.808473 :9E5124D1: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-31 06:00:03.810809 :9E5124D9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235
2025-05-31 06:00:03.811026 :9E5124DA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235
2025-05-31 06:00:03.812849 :9E5124DB: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-31 06:00:03.812990 :9E5124DE: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-31 06:00:03.814192 :9E5124F0: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-31 06:00:03.816026 :9E5124F8: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-31 06:00:03.816345 :9E512500: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-31 06:00:03.883445*: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-31 06:00:03.883445*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze
2025-05-31 06:00:03.883445*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000
2025-05-31 06:00:03.914692*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0
2025-05-31 06:00:03.914692*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin):   qksanPostAnalyzeDump(): Dumping analyze context after compilation  qksanStatus=SUCCESS ecode=0
2025-05-31 06:00:03.914692*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-31 06:00:03.914692*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0
2025-05-31 06:00:03.988310 :9E512508: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-31 06:00:05.926527 :9E512638: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-31 06:00:05.926538 :9E512639:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.008.0001ca2a
-------------------------------------------------------------------------------
Trace Bucket Dump End: default bucket for process 29 (osid: 14732, J003)