Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250425221409\orcl_m002_7716_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:37623M/63366M, Ph+PgF:45334M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 7716, image: ORACLE.EXE (M002) *** 2025-04-25 22:14:10.014 *** SESSION ID:(233.19309) 2025-04-25 22:14:10.014 *** 2025-04-25 22:14:10.014 Process diagnostic dump for ORACLE.EXE (M002), OS id=7716, pid: 29, proc_ser: 203, sid: 233, sess_ser: 19309 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'db file sequential read' file#=0x2, block#=0x7e5a, blocks=0x1 wait_id=1774 seq_num=1775 snap_id=1 wait times: snap=0.000552 sec, exc=0.000552 sec, total=0.000552 sec wait times: max=infinite, heur=0.000552 sec wait counts: calls=0 os=0 in_wait=1 iflags=0x5a0 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000140 sec since current wait 0: waited for 'db file sequential read' file#=0x2, block#=0x7e42, blocks=0x1 wait_id=1773 seq_num=1774 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000252 sec of elapsed time 1: waited for 'db file sequential read' file#=0x2, block#=0xec02, blocks=0x1 wait_id=1772 seq_num=1773 snap_id=1 wait times: snap=0.000050 sec, exc=0.000050 sec, total=0.000050 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000255 sec of elapsed time 2: waited for 'db file sequential read' file#=0x2, block#=0x824a, blocks=0x1 wait_id=1771 seq_num=1772 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000154 sec of elapsed time 3: waited for 'db file sequential read' file#=0x2, block#=0x105a, blocks=0x1 wait_id=1770 seq_num=1771 snap_id=1 wait times: snap=0.000052 sec, exc=0.000052 sec, total=0.000052 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000146 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x8652, blocks=0x1 wait_id=1769 seq_num=1770 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000139 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x8642, blocks=0x1 wait_id=1768 seq_num=1769 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000136 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x8632, blocks=0x1 wait_id=1767 seq_num=1768 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000132 sec of elapsed time 7: waited for 'db file sequential read' file#=0x2, block#=0x8622, blocks=0x1 wait_id=1766 seq_num=1767 snap_id=1 wait times: snap=0.000047 sec, exc=0.000047 sec, total=0.000047 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000141 sec of elapsed time 8: waited for 'db file sequential read' file#=0x2, block#=0x118a, blocks=0x1 wait_id=1765 seq_num=1766 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000141 sec of elapsed time 9: waited for 'db file sequential read' file#=0x2, block#=0x7a12, blocks=0x1 wait_id=1764 seq_num=1765 snap_id=1 wait times: snap=0.000102 sec, exc=0.000102 sec, total=0.000102 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000146 sec of elapsed time Sampled Session History of session 233 serial 19309 --------------------------------------------------- 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 --------------------------------------------------- [1 sample, 22:14:09] not in wait at each sample [1 sample, 22:14:08] idle wait at each sample [session created at: 22:14:09] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-25 22:14:10.014 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 7716, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-25 22:00:02.070777 :8EBBE60E: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-04-25 22:00:02.070941 :8EBBE616: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-04-25 22:00:02.071091 :8EBBE61E: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-04-25 22:00:02.071242 :8EBBE626: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-04-25 22:00:02.071429 :8EBBE62E: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-04-25 22:00:02.071685 :8EBBE636: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-04-25 22:00:02.071839 :8EBBE63E: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-04-25 22:00:02.072003 :8EBBE646: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-04-25 22:00:02.072168 :8EBBE64E: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-04-25 22:00:02.072328 :8EBBE656: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-04-25 22:00:02.072498 :8EBBE65E: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-04-25 22:00:02.072663 :8EBBE666: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-04-25 22:00:02.072819 :8EBBE66E: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-04-25 22:00:02.072975 :8EBBE676: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-04-25 22:00:02.073586 :8EBBE67E: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-04-25 22:00:02.102185 :8EBBE686: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-04-25 22:00:03.175427*:8EBBE857:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC13AD0 estart=1745589602 eid=17751270 ctx=0x0000000777968158 cwh=0x0000000036770158 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-04-25 22:00:03.175427*:8EBBE858:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC13AD0 curCtx=0x0000000036671BF8 pubTabIdxCnt=0 2025-04-25 22:00:03.175427*:8EBBE859:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC13AD0 2025-04-25 22:00:03.175427*:8EBBE85A:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC13AD0 2025-04-25 22:00:03.175427*:8EBBE85B:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC8B6F0 estart=1745589602 eid=16777280 ctx=0x000000077B54EAC8 cwh=0x000000002DC80068 cpu=921875 buffg=50924 interb=204800 r=25 rb=204800 w=0 wb=0 2025-04-25 22:00:03.175427*:8EBBE85C:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC8B6F0 curCtx=0x0000000034667FD8 pubTabIdxCnt=0 2025-04-25 22:00:03.175427*:8EBBE85D:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC8B6F0 2025-04-25 22:00:03.175427*:8EBBE85E:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC8B6F0 2025-04-25 22:00:03.175427*:8EBBE85F:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC13AD0 curCtx=0x0000000036671BF8 xsc->flg4=65792 flags=1 2025-04-25 22:00:03.175427*:8EBBE860:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC13AD0 2025-04-25 22:00:03.747734 :8EBBE92F:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 9, ext 1, nex 3 2025-04-25 22:00:03.747746 :8EBBE930:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x008191c2 where: kdiwh22: kdifind 2025-04-25 22:00:03.748029*:8EBBE931:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC8B6F0 curCtx=0x0000000034667FD8 xsc->flg4=65792 flags=2 2025-04-25 22:00:03.748029*:8EBBE932:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC8B6F0 2025-04-25 22:00:03.749233 :8EBBE933: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-04-25 22:00:03.771627 :8EBBE94B: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-04-25 22:00:03.774033 :8EBBE953:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-04-25 22:00:03.774283 :8EBBE954:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-04-25 22:00:03.775425 :8EBBE958: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-04-25 22:00:03.776538 :8EBBE96A: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-04-25 22:00:03.778446 :8EBBE97A: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-04-25 22:00:03.778794 :8EBBE982: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-04-25 22:00:03.841777*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-04-25 22:00:03.841777*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-04-25 22:00:03.841777*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-04-25 22:00:03.841777*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-04-25 22:00:03.841777*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-04-25 22:00:03.841777*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-04-25 22:00:03.841777*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-04-25 22:00:03.921135 :8EBBEA46: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-04-25 22:00:05.803910 :8EBBEBF4: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-04-25 22:00:05.803925 :8EBBEBF5:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0007.002.0000c078 2025-04-25 22:00:08.273222 :8EBBEDFA: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-04-25 22:00:08.274543 :8EBBEE02: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-04-25 22:00:08.284684 :8EBBEE0A: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-04-25 22:00:08.306294 :8EBBEE12: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-04-25 22:00:09.388477 :8EBBEED7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:jslv.c:9203 2025-04-25 22:00:09.400610 :8EBBEEDA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:0] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-25 22:00:09.402101 :8EBBEEE3:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:00:09.786294 :8EBBEF2F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:00:09.778 2025-04-25 22:00:09.786297 :8EBBEF30:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8812 pso_num=29 pso_serial#=193 2025-04-25 22:00:09.786436 :8EBBEF31:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=8812 (legacy spawn) 2025-04-25 22:00:09.794306 :8EBBEF32: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-04-25 22:00:09.794485 :8EBBEF37: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-04-25 22:00:09.795296 :8EBBEF3C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:00:09.804040 :8EBBEF3F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:00:09.810 2025-04-25 22:00:09.804042 :8EBBEF40:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9928 pso_num=29 pso_serial#=194 2025-04-25 22:00:09.804179 :8EBBEF41:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9928 (legacy spawn) 2025-04-25 22:00:09.810701 :8EBBEF42: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-04-25 22:00:09.810867 :8EBBEF4B: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-04-25 22:00:09.811710 :8EBBEF4C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:00:14.234551 :8EBBF0D9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:00:14.226 2025-04-25 22:00:14.234554 :8EBBF0DA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9804 pso_num=29 pso_serial#=195 2025-04-25 22:00:14.234689 :8EBBF0DB:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9804 (legacy spawn) 2025-04-25 22:00:14.241095 :8EBBF0DC: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-04-25 22:00:14.241269 :8EBBF0E1: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-04-25 22:00:14.242102 :8EBBF0E6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:00:17.288124 :8EBBF1FC:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:00:17.283 2025-04-25 22:00:17.288126 :8EBBF1FD:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9012 pso_num=29 pso_serial#=196 2025-04-25 22:00:17.288261 :8EBBF1FE:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=9012 osp_idx=27 osp_ver=9630 osp_pg=0 (spawn #118200) 2025-04-25 22:00:17.288262 :8EBBF1FF:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:00:17.288262 :8EBBF200:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=17 time=2889219078 2025-04-25 22:00:17.288263 :8EBBF201:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:00:17.288263 :8EBBF202:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:00:17.288263 :8EBBF203:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:00:17.288264 :8EBBF204:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:00:17.288264 :8EBBF205:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:00:17.288784 :8EBBF206: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-04-25 22:00:17.288832 :8EBBF20C: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-04-25 22:00:17.293234 :8EBBF21F: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-04-25 22:00:17.317042 :8EBBF227: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-04-25 22:00:17.331214 :8EBBF22F: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-04-25 22:00:17.355460 :8EBBF237: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-04-25 22:00:17.359210 :8EBBF23F: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-04-25 22:00:17.362997 :8EBBF247: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-04-25 22:00:17.367223 :8EBBF24F: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-04-25 22:00:17.368296 :8EBBF257: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-04-25 22:00:18.609123 :8EBBF2B2: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-04-25 22:00:18.651865 :8EBBF2BA: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-04-25 22:00:18.652286 :8EBBF2C2: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-04-25 22:00:18.652619 :8EBBF2CA: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-04-25 22:00:18.652636 :8EBBF2CD: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-04-25 22:00:18.652697 :8EBBF2DA: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-04-25 22:00:18.655384 :8EBBF2E6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:00:22.950825 :8EBBF4C1:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:00:22.942 2025-04-25 22:00:22.950827 :8EBBF4C2:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10656 pso_num=29 pso_serial#=197 2025-04-25 22:00:22.951015 :8EBBF4C3:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=10656 (legacy spawn) 2025-04-25 22:00:22.957652 :8EBBF4C4: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-04-25 22:00:22.957961 :8EBBF4C9: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-04-25 22:00:22.958808 :8EBBF4CE:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:01:08.454891 :8EBC05C3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:01:08.450 2025-04-25 22:01:08.454893 :8EBC05C4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10216 pso_num=29 pso_serial#=198 2025-04-25 22:01:08.455022 :8EBC05C5:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10216 osp_idx=27 osp_ver=9632 osp_pg=0 (spawn #118205) 2025-04-25 22:01:08.455023 :8EBC05C6:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:01:08.455023 :8EBC05C7:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=18 time=2889270250 2025-04-25 22:01:08.455024 :8EBC05C8:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:01:08.455024 :8EBC05C9:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:01:08.455024 :8EBC05CA:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:01:08.455025 :8EBC05CB:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:01:08.455025 :8EBC05CC:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:01:08.455538 :8EBC05CD: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-04-25 22:01:08.455590 :8EBC05D4: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-04-25 22:01:08.461936 :8EBC05E1:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:04:17.792649 :8EBC440F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:04:17.780 2025-04-25 22:04:17.792651 :8EBC4410:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10916 pso_num=29 pso_serial#=199 2025-04-25 22:04:17.792783 :8EBC4411:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10916 osp_idx=27 osp_ver=9633 osp_pg=0 (spawn #118213) 2025-04-25 22:04:17.792783 :8EBC4412:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:04:17.792784 :8EBC4413:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=19 time=2889459578 2025-04-25 22:04:17.792785 :8EBC4414:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:04:17.792785 :8EBC4415:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:04:17.792785 :8EBC4416:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:04:17.792786 :8EBC4417:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:04:17.792786 :8EBC4418:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:04:17.793301 :8EBC4419: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-04-25 22:04:17.793347 :8EBC441F: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-04-25 22:04:17.797398 :8EBC443F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-25 22:04:17.797448 :8EBC4440:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-25 22:04:17.797696 :8EBC4441:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-25 22:04:17.797711 :8EBC4442:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-25 22:04:17.797924 :8EBC4443:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-25 22:04:17.797938 :8EBC4444:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-25 22:04:17.798147 :8EBC4445:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-25 22:04:17.798160 :8EBC4446:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-25 22:04:17.798373 :8EBC4447:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-25 22:04:17.798386 :8EBC4448:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-25 22:04:17.798696 :8EBC4449:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-04-25 22:04:17.798710 :8EBC444A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-04-25 22:04:17.801110 :8EBC446D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:14:07.009519 :8EBD4B4F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:14:06.997 2025-04-25 22:14:07.009521 :8EBD4B50:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9344 pso_num=29 pso_serial#=200 2025-04-25 22:14:07.009661 :8EBD4B51:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9344 (legacy spawn) 2025-04-25 22:14:07.016074 :8EBD4B52: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-04-25 22:14:07.016394 :8EBD4B5D: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-04-25 22:14:07.017205 :8EBD4B5E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:14:07.025744 :8EBD4B61:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:14:07.012 2025-04-25 22:14:07.025746 :8EBD4B62:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=6084 pso_num=29 pso_serial#=201 2025-04-25 22:14:07.025879 :8EBD4B63:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=6084 (legacy spawn) 2025-04-25 22:14:07.032362 :8EBD4B64: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-04-25 22:14:07.032685 :8EBD4B6D: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-04-25 22:14:07.033484 :8EBD4B6E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:14:07.763430 :8EBD4D83:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:14:07.762 2025-04-25 22:14:07.763432 :8EBD4D84:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10204 pso_num=29 pso_serial#=202 2025-04-25 22:14:07.763591 :8EBD4D8D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10204 osp_idx=27 osp_ver=9636 osp_pg=0 (spawn #118237) 2025-04-25 22:14:07.763592 :8EBD4D8E:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:14:07.763592 :8EBD4D8F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=20 time=2890049546 2025-04-25 22:14:07.763593 :8EBD4D90:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:14:07.763593 :8EBD4D91:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:14:07.763593 :8EBD4D92:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:14:07.763594 :8EBD4D93:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:14:07.763594 :8EBD4D94:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:14:07.764894 :8EBD4DCA: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-04-25 22:14:07.764936 :8EBD4DD0: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-04-25 22:14:07.862749 :8EBD513A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-04-25 22:14:09.049607 :8EBD51EF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 04-25 22:14:09.044 2025-04-25 22:14:09.049609 :8EBD51F0:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7716 pso_num=29 pso_serial#=203 2025-04-25 22:14:09.049748 :8EBD51F1:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=7716 osp_idx=27 osp_ver=9637 osp_pg=0 (spawn #118239) 2025-04-25 22:14:09.049748 :8EBD51F2:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:14:09.049749 :8EBD51F3:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=21 time=2890050843 2025-04-25 22:14:09.049749 :8EBD51F4:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:14:09.049750 :8EBD51F5:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:14:09.049750 :8EBD51F6:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:14:09.049750 :8EBD51F7:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:14:09.049751 :8EBD51F8:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:14:09.050271 :8EBD51F9: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-04-25 22:14:09.050316 :8EBD51FF: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 7716, M002)