Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250531100329\orcl_w000_15048_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:37240M/63366M, Ph+PgF:44146M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 15048, image: ORACLE.EXE (W000) *** 2025-05-31 10:03:29.351 *** SESSION ID:(177.13425) 2025-05-31 10:03:29.351 *** 2025-05-31 10:03:29.351 Process diagnostic dump for ORACLE.EXE (W000), OS id=15048, pid: 22, proc_ser: 129, sid: 177, sess_ser: 13425 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=4.872360 sec, exc=4.872360 sec, total=4.872360 sec wait times: max=5.000000 sec, heur=2 min 10 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.000024 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.013488 sec, exc=5.013488 sec, total=5.013488 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=5.015010 sec, exc=5.015010 sec, total=5.015010 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.004616 sec, exc=5.004616 sec, total=5.004616 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.004642 sec, exc=5.004642 sec, total=5.004642 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.004616 sec, exc=5.004616 sec, total=5.004616 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.006209 sec, exc=5.006209 sec, total=5.006209 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.001132 sec, exc=5.001132 sec, total=5.001132 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.014406 sec, exc=5.014406 sec, total=5.014406 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.004646 sec, exc=5.004646 sec, total=5.004646 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=5.014735 sec, exc=5.014735 sec, total=5.014735 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time Sampled Session History of session 177 serial 13425 --------------------------------------------------- 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 --------------------------------------------------- [121 samples, 10:01:29 - 10:03:29] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-31 10:03:29.351 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 15048, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-31 09:38:29.213237*:9E627223:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024CCBB58 curCtx=0x000000000FC8F300 pubTabIdxCnt=0 2025-05-31 09:38:29.213237*:9E627224:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024CCBB58 2025-05-31 09:38:29.213237*:9E627225:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024CCBB58 2025-05-31 09:38:29.213237*:9E627226:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024CCBB58 curCtx=0x000000000FC8F300 xsc->flg4=65792 flags=2 2025-05-31 09:38:29.213237*:9E627227:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024CCBB58 2025-05-31 09:38:29.213788 :9E627228: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-05-31 09:38:29.224600 :9E627230:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-31 09:38:29.225066 :9E627231:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-31 09:38:29.227363 :9E627232:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-31 09:38:29.227702 :9E627233: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-05-31 09:38:29.227738 :9E627236:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-31 09:38:29.228698 :9E62723C: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-05-31 09:38:29.228822 :9E627245: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-05-31 09:38:59.335511 :9E627B78:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:39:01.849335 :9E627C2B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:39:01.837 2025-05-31 09:39:01.849338 :9E627C2C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12024 pso_num=22 pso_serial#=112 2025-05-31 09:39:01.849481 :9E627C2D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12024 (legacy spawn) 2025-05-31 09:39:01.856258 :9E627C2E: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-05-31 09:39:01.856454 :9E627C33: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-05-31 09:39:01.857328 :9E627C38:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:39:01.866442 :9E627C3B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:39:01.853 2025-05-31 09:39:01.866444 :9E627C3C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15128 pso_num=22 pso_serial#=113 2025-05-31 09:39:01.866608 :9E627C3D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15128 (legacy spawn) 2025-05-31 09:39:01.873848 :9E627C3E: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-05-31 09:39:01.874066 :9E627C46: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-05-31 09:39:01.874982 :9E627C48:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:39:05.069358 :9E627D74:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:39:05.056 2025-05-31 09:39:05.069360 :9E627D75:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13284 pso_num=22 pso_serial#=114 2025-05-31 09:39:05.069495 :9E627D76:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13284 (legacy spawn) 2025-05-31 09:39:05.076148 :9E627D77: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-05-31 09:39:05.076320 :9E627D7C: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-05-31 09:39:05.077136 :9E627D81:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:39:05.086002 :9E627D84:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:39:05.071 2025-05-31 09:39:05.086004 :9E627D85:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8276 pso_num=22 pso_serial#=115 2025-05-31 09:39:05.086187 :9E627D86:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8276 (legacy spawn) 2025-05-31 09:39:05.104190 :9E627D87: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-05-31 09:39:05.104353 :9E627D8F: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-05-31 09:39:05.105265 :9E627D91:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:39:24.724232 :9E628392:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:39:24.716 2025-05-31 09:39:24.724234 :9E628393:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14172 pso_num=22 pso_serial#=116 2025-05-31 09:39:24.724376 :9E628394:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14172 (legacy spawn) 2025-05-31 09:39:24.730868 :9E628395: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-05-31 09:39:24.731054 :9E62839E: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-05-31 09:39:24.731890 :9E62839F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:39:26.084683 :9E628418:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:39:26.076 2025-05-31 09:39:26.084685 :9E628419:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13632 pso_num=22 pso_serial#=117 2025-05-31 09:39:26.084826 :9E62841A:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13632 (legacy spawn) 2025-05-31 09:39:26.091297 :9E62841B: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-05-31 09:39:26.091463 :9E628420: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-05-31 09:39:26.092277 :9E628425:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:39:29.345432 :9E62851F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:39:29.340 2025-05-31 09:39:29.345433 :9E628520:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14396 pso_num=22 pso_serial#=118 2025-05-31 09:39:29.345571 :9E628521:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14396 osp_idx=0 osp_ver=252640 osp_pg=0 (spawn #237437) 2025-05-31 09:39:29.345572 :9E628522:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 09:39:29.345572 :9E628523:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=40 time=1660127985 2025-05-31 09:39:29.345573 :9E628524:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 09:39:29.345573 :9E628525:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 09:39:29.345574 :9E628526:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 09:39:29.345574 :9E628527:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 09:39:29.345574 :9E628528:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 09:39:29.346057 :9E628529: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-05-31 09:39:29.346708 :9E62853E: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-05-31 09:39:29.354238 :9E62855A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-31 09:39:29.354599 :9E62855B: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-05-31 09:39:29.354634 :9E62855E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-31 09:39:29.355478 :9E628564: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-05-31 09:39:29.355595 :9E62856D: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-05-31 09:39:59.471576 :9E628ED8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:40:00.292850 :9E628F22:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:40:00.283 2025-05-31 09:40:00.292852 :9E628F23:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9748 pso_num=22 pso_serial#=119 2025-05-31 09:40:00.292989 :9E628F24:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9748 (legacy spawn) 2025-05-31 09:40:00.299542 :9E628F25: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-05-31 09:40:00.299780 :9E628F2C: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-05-31 09:40:00.300806 :9E628F2F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:40:14.565393 :9E62935D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:40:14.551 2025-05-31 09:40:14.565396 :9E62935E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11536 pso_num=22 pso_serial#=120 2025-05-31 09:40:14.565555 :9E62935F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11536 (legacy spawn) 2025-05-31 09:40:14.571889 :9E629360: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-05-31 09:40:14.572077 :9E629365: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-05-31 09:40:14.572883 :9E62936A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:40:14.589465 :9E62936D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:40:14.582 2025-05-31 09:40:14.589467 :9E62936E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12308 pso_num=22 pso_serial#=121 2025-05-31 09:40:14.589600 :9E62936F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12308 (legacy spawn) 2025-05-31 09:40:14.596008 :9E629370: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-05-31 09:40:14.596170 :9E629379: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-05-31 09:40:14.596983 :9E62937A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:40:17.741681 :9E629480:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:40:17.727 2025-05-31 09:40:17.741684 :9E629481:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12296 pso_num=22 pso_serial#=122 2025-05-31 09:40:17.741823 :9E629482:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12296 (legacy spawn) 2025-05-31 09:40:17.748637 :9E629483: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-05-31 09:40:17.748822 :9E62948C: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-05-31 09:40:17.749713 :9E62948D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:40:17.758876 :9E629490:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:40:17.759 2025-05-31 09:40:17.758878 :9E629491:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9468 pso_num=22 pso_serial#=123 2025-05-31 09:40:17.759015 :9E629492:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9468 (legacy spawn) 2025-05-31 09:40:17.765814 :9E629493: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-05-31 09:40:17.765992 :9E62949C: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-05-31 09:40:17.766892 :9E62949D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:40:26.948459 :9E62979B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:40:26.940 2025-05-31 09:40:26.948461 :9E62979C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8432 pso_num=22 pso_serial#=124 2025-05-31 09:40:26.948626 :9E62979D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8432 (legacy spawn) 2025-05-31 09:40:26.955109 :9E62979E: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-05-31 09:40:26.955283 :9E6297A7: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-05-31 09:40:26.956097 :9E6297A8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:40:29.424813 :9E62986E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:40:29.419 2025-05-31 09:40:29.424815 :9E62986F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12156 pso_num=22 pso_serial#=125 2025-05-31 09:40:29.424958 :9E629870:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12156 osp_idx=0 osp_ver=252647 osp_pg=0 (spawn #237439) 2025-05-31 09:40:29.424959 :9E629871:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 09:40:29.424960 :9E629872:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=41 time=1660188079 2025-05-31 09:40:29.424960 :9E629873:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 09:40:29.424960 :9E629874:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 09:40:29.424961 :9E629875:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 09:40:29.424961 :9E629876:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 09:40:29.424961 :9E629877:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 09:40:29.425463 :9E629878: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-05-31 09:40:29.426105 :9E62988D: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-05-31 09:40:29.440292 :9E6298A9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-31 09:40:29.440382 :9E6298AA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-31 09:40:29.441173 :9E6298AB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-31 09:40:29.441541 :9E6298AC: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-05-31 09:40:29.441582 :9E6298AF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-31 09:40:29.449433 :9E6298B5: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-05-31 09:40:29.449501 :9E6298B8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:ktcc.c:879 2025-05-31 09:40:29.449536 :9E6298B9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:ktcc.c:879 2025-05-31 09:40:29.449913 :9E6298BF:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-31 09:40:29.450275 :9E6298C0:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-31 09:40:29.450466 :9E6298C1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-31 09:40:29.450905 :9E6298C2: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-05-31 09:40:29.450932 :9E6298C5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-31 09:40:29.452517 :9E6298CB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-31 09:40:29.452751 :9E6298CC: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-05-31 09:40:29.452781 :9E6298CF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-31 09:40:29.453779 :9E6298D5: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-05-31 09:40:29.453923 :9E6298DD: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-05-31 09:40:59.529398 :9E62A24F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:41:08.577196 :9E62A507:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:41:08.568 2025-05-31 09:41:08.577198 :9E62A508:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9648 pso_num=22 pso_serial#=126 2025-05-31 09:41:08.577330 :9E62A509:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9648 (legacy spawn) 2025-05-31 09:41:08.583754 :9E62A50A: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-05-31 09:41:08.583922 :9E62A50F: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-05-31 09:41:08.584748 :9E62A514:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:41:16.464401 :9E62A793:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:41:16.460 2025-05-31 09:41:16.464403 :9E62A794:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14416 pso_num=22 pso_serial#=127 2025-05-31 09:41:16.464535 :9E62A795:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14416 osp_idx=0 osp_ver=252649 osp_pg=0 (spawn #237441) 2025-05-31 09:41:16.464536 :9E62A796:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 09:41:16.464536 :9E62A797:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=42 time=1660235110 2025-05-31 09:41:16.464536 :9E62A798:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 09:41:16.464537 :9E62A799:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 09:41:16.464537 :9E62A79A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 09:41:16.464537 :9E62A79B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 09:41:16.464538 :9E62A79C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 09:41:16.465024 :9E62A79D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 09:41:16.465066 :9E62A7A5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 09:51:17.314822 :9E636AC7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 09:51:17.835400 :9E636AFE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 09:51:17.830 2025-05-31 09:51:17.835403 :9E636AFF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13176 pso_num=22 pso_serial#=128 2025-05-31 09:51:17.835545 :9E636B00:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13176 osp_idx=0 osp_ver=252650 osp_pg=0 (spawn #237464) 2025-05-31 09:51:17.835546 :9E636B01:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 09:51:17.835546 :9E636B02:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=43 time=1660836485 2025-05-31 09:51:17.835546 :9E636B03:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 09:51:17.835547 :9E636B04:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 09:51:17.835547 :9E636B05:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 09:51:17.835548 :9E636B06:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 09:51:17.835548 :9E636B07:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 09:51:17.836044 :9E636B08:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 09:51:17.836093 :9E636B12:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 10:01:18.825689 :9E642E90:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 10:01:19.288793 :9E642ED4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 10:01:19.284 2025-05-31 10:01:19.288795 :9E642ED5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15048 pso_num=22 pso_serial#=129 2025-05-31 10:01:19.288933 :9E642ED6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15048 osp_idx=0 osp_ver=252651 osp_pg=0 (spawn #237488) 2025-05-31 10:01:19.288933 :9E642ED7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 10:01:19.288934 :9E642ED8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=44 time=1661437938 2025-05-31 10:01:19.288934 :9E642ED9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 10:01:19.288935 :9E642EDA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 10:01:19.288935 :9E642EDB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 10:01:19.288935 :9E642EDC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 10:01:19.288936 :9E642EDD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 10:01:19.289442 :9E642EDE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 10:01:19.289485 :9E642EE6:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 15048, W000)