Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250427221536\orcl_j000_11100_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:37589M/63366M, Ph+PgF:45240M/72582M 
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 22
Windows thread id: 11100, image: ORACLE.EXE (J000)


*** 2025-04-27 22:15:36.722
*** SESSION ID:(177.44095) 2025-04-27 22:15:36.722
 

*** 2025-04-27 22:15:36.722
Process diagnostic dump for ORACLE.EXE (J000), OS id=11100,
pid: 22, proc_ser: 135, sid: 177, sess_ser: 44095 
-------------------------------------------------------------------------------
current sql: <none>
client details:
  O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 11100
  machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000)
Current Wait Stack:
 0: waiting for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=55 seq_num=56 snap_id=1
    wait times: snap=0.070259 sec, exc=0.070259 sec, total=0.070259 sec
    wait times: max=0.500000 sec, heur=27.682798 sec
    wait counts: calls=1 os=1
    in_wait=1 iflags=0x5a8
Wait State:
  fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1
Session Wait History:
    elapsed time of 0.000010 sec since current wait
 0: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=54 seq_num=55 snap_id=1
    wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000006 sec of elapsed time
 1: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=53 seq_num=54 snap_id=1
    wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000009 sec of elapsed time
 2: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=52 seq_num=53 snap_id=1
    wait times: snap=0.504354 sec, exc=0.504354 sec, total=0.504354 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000014 sec of elapsed time
 3: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=51 seq_num=52 snap_id=1
    wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000008 sec of elapsed time
 4: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=50 seq_num=51 snap_id=1
    wait times: snap=0.500005 sec, exc=0.500005 sec, total=0.500005 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000007 sec of elapsed time
 5: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=49 seq_num=50 snap_id=1
    wait times: snap=0.510091 sec, exc=0.510091 sec, total=0.510091 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000008 sec of elapsed time
 6: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=48 seq_num=49 snap_id=1
    wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000012 sec of elapsed time
 7: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=47 seq_num=48 snap_id=1
    wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000014 sec of elapsed time
 8: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=46 seq_num=47 snap_id=1
    wait times: snap=0.499995 sec, exc=0.499995 sec, total=0.499995 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000008 sec of elapsed time
 9: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=45 seq_num=46 snap_id=1
    wait times: snap=0.500002 sec, exc=0.500002 sec, total=0.500002 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000008 sec of elapsed time
Sampled Session History of session 177 serial 44095
---------------------------------------------------
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
---------------------------------------------------
  [28 samples,                                             22:15:09 - 22:15:36]
    idle wait at each sample
  [session created at: 22:15:09]
-------------------------------------------------------------------------------
Process diagnostic dump actual duration=0.000000 sec
  (max dump time=30.000000 sec)

*** 2025-04-27 22:15:36.722
 
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 22 (osid: 11100, J000)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
-------------------------------------------------------------------------------
2025-04-27 22:12:03.741709 :8FA43FB0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=150 time=3062713218
2025-04-27 22:12:03.741709 :8FA43FB1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-04-27 22:12:03.741710 :8FA43FB2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-04-27 22:12:03.741710 :8FA43FB3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-04-27 22:12:03.741710 :8FA43FB4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-04-27 22:12:03.741711 :8FA43FB5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-04-27 22:12:03.742191 :8FA43FB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-04-27 22:12:03.742816 :8FA43FCB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:03.748300 :8FA43FE8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:03.749312 :8FA43FF0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:03.749463 :8FA43FF9:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:08.741847 :8FA44155:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-04-27 22:12:08.741875*:8FA4415A:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCCBB58 estart=1745763128 eid=16833461 ctx=0x000000077BD98A08 cwh=0x000000000FC802A0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0
2025-04-27 22:12:08.741875*:8FA4415B:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCCBB58 curCtx=0x000000000FC8F300 pubTabIdxCnt=0
2025-04-27 22:12:08.741875*:8FA4415C:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCCBB58
2025-04-27 22:12:08.741875*:8FA4415D:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCCBB58
2025-04-27 22:12:08.741875*:8FA4415E:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCCBB58 curCtx=0x000000000FC8F300 xsc->flg4=65792 flags=2
2025-04-27 22:12:08.741875*:8FA4415F:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCCBB58
2025-04-27 22:12:08.742422 :8FA44160:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:08.753501 :8FA44168:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 
2025-04-27 22:12:08.754000 :8FA44169:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 
2025-04-27 22:12:08.756412 :8FA4416A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235
2025-04-27 22:12:08.756769 :8FA4416B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:08.756809 :8FA4416E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235
2025-04-27 22:12:08.757754 :8FA44174:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:08.757883 :8FA4417D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:38.837531 :8FA44B68:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:12:45.443854 :8FA44D5A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:12:45.430
2025-04-27 22:12:45.443856 :8FA44D5B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9112 pso_num=22 pso_serial#=117
2025-04-27 22:12:45.443993 :8FA44D5C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9112 (legacy spawn)
2025-04-27 22:12:45.450347 :8FA44D5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:45.450517 :8FA44D62:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:45.451290 :8FA44D67:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:12:48.197643 :8FA44E53:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:12:48.183
2025-04-27 22:12:48.197645 :8FA44E54:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9468 pso_num=22 pso_serial#=118
2025-04-27 22:12:48.197786 :8FA44E55:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9468 (legacy spawn)
2025-04-27 22:12:48.204245 :8FA44E56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:48.204422 :8FA44E5F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:48.205223 :8FA44E60:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:12:48.213889 :8FA44E63:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:12:48.199
2025-04-27 22:12:48.213892 :8FA44E64:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4864 pso_num=22 pso_serial#=119
2025-04-27 22:12:48.214042 :8FA44E65:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=4864 (legacy spawn)
2025-04-27 22:12:48.220424 :8FA44E66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:48.220602 :8FA44E6F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:48.221389 :8FA44E70:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:12:49.254311 :8FA44F1B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:12:49.246
2025-04-27 22:12:49.254313 :8FA44F1C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10600 pso_num=22 pso_serial#=120
2025-04-27 22:12:49.254457 :8FA44F1D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10600 (legacy spawn)
2025-04-27 22:12:49.260818 :8FA44F1E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:49.260983 :8FA44F23:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:49.261818 :8FA44F28:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:12:51.499720 :8FA44F7C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:12:51.486
2025-04-27 22:12:51.499722 :8FA44F7D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6752 pso_num=22 pso_serial#=121
2025-04-27 22:12:51.499861 :8FA44F7E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=6752 (legacy spawn)
2025-04-27 22:12:51.506314 :8FA44F7F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:51.506482 :8FA44F84:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:51.507310 :8FA44F89:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:12:51.515947 :8FA44F8C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:12:51.502
2025-04-27 22:12:51.515949 :8FA44F8D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2516 pso_num=22 pso_serial#=122
2025-04-27 22:12:51.516084 :8FA44F8E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=2516 (legacy spawn)
2025-04-27 22:12:51.522540 :8FA44FA2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:12:51.522711 :8FA44FAB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:12:51.523508 :8FA44FAC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:13:08.818049 :8FA45555:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:13:08.812
2025-04-27 22:13:08.818051 :8FA45556:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9012 pso_num=22 pso_serial#=123
2025-04-27 22:13:08.818190 :8FA45557:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9012 osp_idx=0 osp_ver=131958 osp_pg=0 (spawn #125039)
2025-04-27 22:13:08.818190 :8FA45558:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A
2025-04-27 22:13:08.818191 :8FA45559:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=151 time=3062778296
2025-04-27 22:13:08.818191 :8FA4555A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-04-27 22:13:08.818191 :8FA4555B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-04-27 22:13:08.818192 :8FA4555C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-04-27 22:13:08.818192 :8FA4555D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-04-27 22:13:08.818192 :8FA4555E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-04-27 22:13:08.818693 :8FA4555F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-04-27 22:13:08.819342 :8FA45574:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:13:08.826858 :8FA45590:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235
2025-04-27 22:13:08.827217 :8FA45591:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:13:08.827252 :8FA45594:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235
2025-04-27 22:13:08.828114 :8FA4559A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:13:08.828235 :8FA455A3:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:13:38.935903 :8FA46018:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:13:51.461367 :8FA463ED:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:13:51.449
2025-04-27 22:13:51.461370 :8FA463EE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10832 pso_num=22 pso_serial#=124
2025-04-27 22:13:51.461501 :8FA463EF:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10832 (legacy spawn)
2025-04-27 22:13:51.467870 :8FA463F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:13:51.468048 :8FA463F5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:13:51.468807 :8FA463FA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:13:53.738373 :8FA464C6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:13:53.730
2025-04-27 22:13:53.738375 :8FA464C7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7964 pso_num=22 pso_serial#=125
2025-04-27 22:13:53.738508 :8FA464C8:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=7964 (legacy spawn)
2025-04-27 22:13:53.744941 :8FA464C9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:13:53.745118 :8FA464CE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:13:53.745951 :8FA464D3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:00.910872 :8FA46738:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:00.896
2025-04-27 22:14:00.910874 :8FA46739:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8088 pso_num=22 pso_serial#=126
2025-04-27 22:14:00.911008 :8FA4673A:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8088 (legacy spawn)
2025-04-27 22:14:00.917441 :8FA4673B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:00.917623 :8FA46740:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:00.918419 :8FA46745:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:00.926961 :8FA46748:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:00.912
2025-04-27 22:14:00.926962 :8FA46749:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7900 pso_num=22 pso_serial#=127
2025-04-27 22:14:00.927097 :8FA4674A:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=7900 (legacy spawn)
2025-04-27 22:14:00.933563 :8FA4674B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:00.933722 :8FA46754:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:00.934514 :8FA46755:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:04.013149 :8FA46876:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:04.000
2025-04-27 22:14:04.013150 :8FA46877:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9868 pso_num=22 pso_serial#=128
2025-04-27 22:14:04.013329 :8FA46878:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9868 (legacy spawn)
2025-04-27 22:14:04.019758 :8FA46879:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:04.019937 :8FA46882:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:04.020752 :8FA46883:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:04.029294 :8FA46886:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:04.016
2025-04-27 22:14:04.029296 :8FA46887:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4072 pso_num=22 pso_serial#=129
2025-04-27 22:14:04.029433 :8FA46888:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=4072 (legacy spawn)
2025-04-27 22:14:04.048588 :8FA46895:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:04.048619 :8FA46898:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:04.048757 :8FA4689F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:04.049588 :8FA468AC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:08.917149 :8FA46A02:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:08.911
2025-04-27 22:14:08.917151 :8FA46A03:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10312 pso_num=22 pso_serial#=130
2025-04-27 22:14:08.917287 :8FA46A04:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10312 osp_idx=0 osp_ver=131965 osp_pg=0 (spawn #125041)
2025-04-27 22:14:08.917287 :8FA46A05:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A
2025-04-27 22:14:08.917287 :8FA46A06:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=152 time=3062838390
2025-04-27 22:14:08.917288 :8FA46A07:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-04-27 22:14:08.917288 :8FA46A08:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-04-27 22:14:08.917289 :8FA46A09:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-04-27 22:14:08.917289 :8FA46A0A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-04-27 22:14:08.917289 :8FA46A0B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-04-27 22:14:08.917762 :8FA46A0C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-04-27 22:14:08.918457 :8FA46A21:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:08.929517 :8FA46A3D:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 
2025-04-27 22:14:08.929986 :8FA46A3E:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 
2025-04-27 22:14:08.932363 :8FA46A3F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235
2025-04-27 22:14:08.932716 :8FA46A40:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:08.932751 :8FA46A43:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235
2025-04-27 22:14:08.933600 :8FA46A49:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:08.933721 :8FA46A52:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:39.042120 :8FA47420:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:40.216350 :8FA474B3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:40.203
2025-04-27 22:14:40.216352 :8FA474B4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9500 pso_num=22 pso_serial#=131
2025-04-27 22:14:40.216485 :8FA474B5:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9500 (legacy spawn)
2025-04-27 22:14:40.222952 :8FA474B6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:40.223125 :8FA474BF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:40.223898 :8FA474C0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:40.232521 :8FA474C3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:40.219
2025-04-27 22:14:40.232523 :8FA474C4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7460 pso_num=22 pso_serial#=132
2025-04-27 22:14:40.232659 :8FA474C5:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=7460 (legacy spawn)
2025-04-27 22:14:40.251649 :8FA474C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:40.251810 :8FA474CF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:40.252652 :8FA474D0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:14:53.683171 :8FA478E7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:14:53.670
2025-04-27 22:14:53.683172 :8FA478E8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6556 pso_num=22 pso_serial#=133
2025-04-27 22:14:53.683312 :8FA478E9:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=6556 (legacy spawn)
2025-04-27 22:14:53.689810 :8FA478EA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:14:53.689989 :8FA478EF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:14:53.690779 :8FA478F4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:15:01.937453 :8FA47BBB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:15:01.929
2025-04-27 22:15:01.937455 :8FA47BBC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2292 pso_num=22 pso_serial#=134
2025-04-27 22:15:01.937590 :8FA47BBD:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=2292 (legacy spawn)
2025-04-27 22:15:01.944018 :8FA47BBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:15:01.944187 :8FA47BC3:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-04-27 22:15:01.945003 :8FA47BC8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-04-27 22:15:09.035529 :8FA47DD9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-27 22:15:09.030
2025-04-27 22:15:09.035531 :8FA47DDA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11100 pso_num=22 pso_serial#=135
2025-04-27 22:15:09.035661 :8FA47DDB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11100 osp_idx=0 osp_ver=131970 osp_pg=0 (spawn #125043)
2025-04-27 22:15:09.035662 :8FA47DDC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A
2025-04-27 22:15:09.035662 :8FA47DDD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=153 time=3062898515
2025-04-27 22:15:09.035663 :8FA47DDE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-04-27 22:15:09.035663 :8FA47DDF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-04-27 22:15:09.035663 :8FA47DE0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-04-27 22:15:09.035664 :8FA47DE1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-04-27 22:15:09.035664 :8FA47DE2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-04-27 22:15:09.036175 :8FA47DE3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-04-27 22:15:09.036828 :8FA47DF8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:15:09.044321 :8FA47E14:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235
2025-04-27 22:15:09.044710 :8FA47E15:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:15:09.044748 :8FA47E18:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235
2025-04-27 22:15:09.045615 :8FA47E1E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-04-27 22:15:09.045735 :8FA47E27:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1
-------------------------------------------------------------------------------
Trace Bucket Dump End: default bucket for process 22 (osid: 11100, J000)