Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250821220006\orcl_j002_4492_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:35318M/63366M, Ph+PgF:40516M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 4492, image: ORACLE.EXE (J002) *** 2025-08-21 22:00:06.501 *** SESSION ID:(225.37433) 2025-08-21 22:00:06.501 *** 2025-08-21 22:00:06.501 Process diagnostic dump for ORACLE.EXE (J002), OS id=4492, pid: 28, proc_ser: 255, sid: 225, sess_ser: 37433 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 4492 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.482383 sec, exc=0.482383 sec, total=0.482383 sec wait times: max=0.500000 sec, heur=4.425624 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.000013 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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.000010 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 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=5 seq_num=6 snap_id=1 wait times: snap=0.499110 sec, exc=0.499110 sec, total=0.499110 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.344629 sec, exc=0.344629 sec, total=0.344629 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000017 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 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.000005 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.510099 sec, exc=0.510099 sec, total=0.510099 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499265 sec, exc=0.499265 sec, total=0.499265 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.090059 sec, exc=0.090059 sec, total=0.090059 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 225 serial 37433 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [5 samples, 22:00:02 - 22:00:06] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-21 22:00:06.501 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 4492, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-21 20:15:28.045511 :C2D424F4:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-08-21 20:15:28.049391 :C2D4251C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:15:28.049430 :C2D4251D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:15:28.049684 :C2D4251E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:15:28.049701 :C2D4251F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:15:28.049915 :C2D42520:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:15:28.049928 :C2D42521:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:15:28.050138 :C2D42522:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:15:28.050151 :C2D42523:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:15:28.050365 :C2D42524:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:15:28.050378 :C2D42525:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:15:28.050581 :C2D42526:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:15:28.050595 :C2D42527:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:15:28.052981 :C2D42528:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-21 20:45:32.023764 :C2D67D15:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-21 20:45:32.011 2025-08-21 20:45:32.023767 :C2D67D16:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=22476 pso_num=28 pso_serial#=251 2025-08-21 20:45:32.023896 :C2D67D17:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=22476 osp_idx=26 osp_ver=247904 osp_pg=0 (spawn #512305) 2025-08-21 20:45:32.023897 :C2D67D18:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-21 20:45:32.023897 :C2D67D19:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=70 time=194834018 2025-08-21 20:45:32.023897 :C2D67D1A:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-21 20:45:32.023897 :C2D67D1B:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-21 20:45:32.023898 :C2D67D1C:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-21 20:45:32.023898 :C2D67D1D:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-21 20:45:32.023898 :C2D67D1E:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-21 20:45:32.024373 :C2D67D1F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-21 20:45:32.024413 :C2D67D25:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-08-21 20:45:32.028497 :C2D67D3E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:45:32.028544 :C2D67D3F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:45:32.028795 :C2D67D40:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:45:32.028810 :C2D67D41:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:45:32.029027 :C2D67D42:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:45:32.029041 :C2D67D43:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:45:32.029249 :C2D67D44:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:45:32.029262 :C2D67D45:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:45:32.029470 :C2D67D46:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:45:32.029483 :C2D67D47:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:45:32.029685 :C2D67D48:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 20:45:32.029698 :C2D67D49:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 20:45:32.032155 :C2D67D4A:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-21 21:00:33.931582 :C2D7AA20:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-21 21:00:33.919 2025-08-21 21:00:33.931584 :C2D7AA21:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=19612 pso_num=28 pso_serial#=252 2025-08-21 21:00:33.931717 :C2D7AA22:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=19612 osp_idx=26 osp_ver=247905 osp_pg=0 (spawn #512340) 2025-08-21 21:00:33.931718 :C2D7AA23:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-21 21:00:33.931718 :C2D7AA24:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=71 time=195735940 2025-08-21 21:00:33.931719 :C2D7AA25:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-21 21:00:33.931719 :C2D7AA26:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-21 21:00:33.931719 :C2D7AA27:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-21 21:00:33.931719 :C2D7AA28:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-21 21:00:33.931720 :C2D7AA29:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-21 21:00:33.932276 :C2D7AA2A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-21 21:00:33.932331 :C2D7AA30:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-08-21 21:00:33.936709 :C2D7AA45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:33.960784 :C2D7AA75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:33.975561 :C2D7AA7D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:34.006905 :C2D7AA95:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:34.010683 :C2D7AA9D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:34.014400 :C2D7AAA5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:34.018883 :C2D7AAAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:34.020011 :C2D7AAB5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:35.100894*:C2D7AAEC:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000027A77608 estart=1755781234 eid=16780870 ctx=0x000000077BA4B1C8 cwh=0x0000000029950500 cpu=468750 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-08-21 21:00:35.100894*:C2D7AAED:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000027A77608 curCtx=0x0000000027A76340 pubTabIdxCnt=0 2025-08-21 21:00:35.100894*:C2D7AAEE:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000027A77608 2025-08-21 21:00:35.100894*:C2D7AAEF:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000027A77608 2025-08-21 21:00:35.100894*:C2D7AAF0:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000029961560 estart=1755781234 eid=16780849 ctx=0x0000000787AD5BF0 cwh=0x00000000299507D0 cpu=468750 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-08-21 21:00:35.100894*:C2D7AAF1:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000029961560 curCtx=0x0000000027A785A8 pubTabIdxCnt=0 2025-08-21 21:00:35.100894*:C2D7AAF2:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000029961560 2025-08-21 21:00:35.100894*:C2D7AAF3:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000029961560 2025-08-21 21:00:35.163399*:C2D7AB00:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000027A77608 curCtx=0x0000000027A76340 xsc->flg4=65792 flags=1 2025-08-21 21:00:35.163399*:C2D7AB01:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000027A77608 2025-08-21 21:00:35.163399*:C2D7AB02:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000029961560 curCtx=0x0000000027A785A8 xsc->flg4=65792 flags=2 2025-08-21 21:00:35.163399*:C2D7AB03:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000029961560 2025-08-21 21:00:35.243226 :C2D7AB04:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:35.287775 :C2D7AB0C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:35.288109 :C2D7AB14:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:35.288408 :C2D7AB1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:35.288425 :C2D7AB1F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 21:00:35.288483 :C2D7AB2B:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-08-21 21:00:35.291501 :C2D7AB39:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-21 21:15:35.766603 :C2D8DF58:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-21 21:15:35.754 2025-08-21 21:15:35.766604 :C2D8DF59:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=22496 pso_num=28 pso_serial#=253 2025-08-21 21:15:35.766748 :C2D8DF5A:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=22496 osp_idx=26 osp_ver=247906 osp_pg=0 (spawn #512376) 2025-08-21 21:15:35.766749 :C2D8DF5B:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-21 21:15:35.766749 :C2D8DF5C:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=72 time=196637768 2025-08-21 21:15:35.766750 :C2D8DF5D:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-21 21:15:35.766750 :C2D8DF5E:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-21 21:15:35.766751 :C2D8DF5F:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-21 21:15:35.766751 :C2D8DF60:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-21 21:15:35.766751 :C2D8DF61:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-21 21:15:35.767265 :C2D8DF62:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-21 21:15:35.767305 :C2D8DF68:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-08-21 21:15:35.771323 :C2D8DF90:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:15:35.771366 :C2D8DF91:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:15:35.771622 :C2D8DF92:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:15:35.771639 :C2D8DF93:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:15:35.771853 :C2D8DF94:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:15:35.771867 :C2D8DF95:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:15:35.772077 :C2D8DF96:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:15:35.772089 :C2D8DF97:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:15:35.772304 :C2D8DF98:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:15:35.772316 :C2D8DF99:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:15:35.772516 :C2D8DF9A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:15:35.772529 :C2D8DF9B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:15:35.774926 :C2D8DF9C:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-21 21:45:39.569723 :C2DB36EC:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-21 21:45:39.557 2025-08-21 21:45:39.569725 :C2DB36ED:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21040 pso_num=28 pso_serial#=254 2025-08-21 21:45:39.569859 :C2DB36EE:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=21040 osp_idx=26 osp_ver=247907 osp_pg=0 (spawn #512444) 2025-08-21 21:45:39.569859 :C2DB36EF:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-21 21:45:39.569860 :C2DB36F0:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=73 time=198441565 2025-08-21 21:45:39.569860 :C2DB36F1:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-21 21:45:39.569861 :C2DB36F2:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-21 21:45:39.569861 :C2DB36F3:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-21 21:45:39.569861 :C2DB36F4:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-21 21:45:39.569862 :C2DB36F5:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-21 21:45:39.570355 :C2DB36F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-21 21:45:39.570396 :C2DB36FD:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-08-21 21:45:39.574503 :C2DB3715:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:45:39.574548 :C2DB3716:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:45:39.574814 :C2DB3717:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:45:39.574840 :C2DB3718:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:45:39.575111 :C2DB3719:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:45:39.575125 :C2DB371A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:45:39.575334 :C2DB371B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:45:39.575347 :C2DB371C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:45:39.575557 :C2DB371D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:45:39.575570 :C2DB371E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:45:39.575771 :C2DB371F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-21 21:45:39.575784 :C2DB3720:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-21 21:45:39.578148 :C2DB3721:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-21 22:00:02.044883 :C2DC5721:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-21 22:00:02.043 2025-08-21 22:00:02.044885 :C2DC5722:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=4492 pso_num=28 pso_serial#=255 2025-08-21 22:00:02.045013 :C2DC5723:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=4492 osp_idx=26 osp_ver=247908 osp_pg=0 (spawn #512480) 2025-08-21 22:00:02.045014 :C2DC5724:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-21 22:00:02.045014 :C2DC5725:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=74 time=199304049 2025-08-21 22:00:02.045015 :C2DC5726:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-21 22:00:02.045015 :C2DC5727:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-21 22:00:02.045016 :C2DC5728:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-21 22:00:02.045016 :C2DC5729:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-21 22:00:02.045016 :C2DC572A:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-21 22:00:02.045569 :C2DC5734:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.050733 :C2DC5753:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.050778 :C2DC575E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-08-21 22:00:02.062478 :C2DC57BC:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-21 22:00:02.063067 :C2DC57D6:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 528f120000000000 2025-08-21 22:00:02.064807 :C2DC57F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.064907 :C2DC57FD:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:02.064917 :C2DC5803:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-08-21 22:00:02.064923 :C2DC5805:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.064954 :C2DC580F:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:02.065649 :C2DC5838:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 235140728) 2025-08-21 22:00:02.065653 :C2DC5839:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.065679 :C2DC584B:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:02.065687 :C2DC5858:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65564 1) 2025-08-21 22:00:02.065689 :C2DC5859:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.065719 :C2DC5865:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:02.065723 :C2DC5866:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65564) 2025-08-21 22:00:02.065725 :C2DC586C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.065771 :C2DC58A0:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:02.066542 :C2DC592A:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:02.066566 :C2DC5945:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-21 22:00:02.067436 :C2DC5946:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 538f120000000000 2025-08-21 22:00:02.067872 :C2DC594F:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 235140728) 2025-08-21 22:00:02.067879 :C2DC5950:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.067925 :C2DC595E:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:02.076873 :C2DC59E0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-08-21 22:00:02.077822 :C2DC5A04:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.078566 :C2DC5A23:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.078608 :C2DC5A26:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-21 22:00:02.169388 :C2DC5A65:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-21 22:00:04.022937 :C2DC5EA1:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 28 (osid: 4492, J002)