Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250520220730\orcl_m002_14156_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:37378M/63366M, Ph+PgF:44508M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 14156, image: ORACLE.EXE (M002) *** 2025-05-20 22:07:30.126 *** SESSION ID:(201.47067) 2025-05-20 22:07:30.126 *** 2025-05-20 22:07:30.126 Process diagnostic dump for ORACLE.EXE (M002), OS id=14156, pid: 25, proc_ser: 40, sid: 201, sess_ser: 47067 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'db file sequential read' file#=0x2, block#=0x784a, blocks=0x1 wait_id=1711 seq_num=1712 snap_id=1 wait times: snap=0.002090 sec, exc=0.002090 sec, total=0.002090 sec wait times: max=infinite, heur=0.002090 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.000455 sec since current wait 0: waited for 'db file sequential read' file#=0x2, block#=0x7822, blocks=0x1 wait_id=1710 seq_num=1711 snap_id=1 wait times: snap=0.002956 sec, exc=0.002956 sec, total=0.002956 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000625 sec of elapsed time 1: waited for 'db file sequential read' file#=0x2, block#=0x776a, blocks=0x1 wait_id=1709 seq_num=1710 snap_id=1 wait times: snap=0.001824 sec, exc=0.001824 sec, total=0.001824 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000181 sec of elapsed time 2: waited for 'db file sequential read' file#=0x2, block#=0x772a, blocks=0x1 wait_id=1708 seq_num=1709 snap_id=1 wait times: snap=0.001230 sec, exc=0.001230 sec, total=0.001230 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000150 sec of elapsed time 3: waited for 'db file sequential read' file#=0x2, block#=0x770a, blocks=0x1 wait_id=1707 seq_num=1708 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.000139 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x76f2, blocks=0x1 wait_id=1706 seq_num=1707 snap_id=1 wait times: snap=0.000055 sec, exc=0.000055 sec, total=0.000055 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000142 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x76e2, blocks=0x1 wait_id=1705 seq_num=1706 snap_id=1 wait times: snap=0.000053 sec, exc=0.000053 sec, total=0.000053 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000172 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x76d2, blocks=0x1 wait_id=1704 seq_num=1705 snap_id=1 wait times: snap=0.000077 sec, exc=0.000077 sec, total=0.000077 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000304 sec of elapsed time 7: waited for 'db file sequential read' file#=0x2, block#=0x76ba, blocks=0x1 wait_id=1703 seq_num=1704 snap_id=1 wait times: snap=0.001664 sec, exc=0.001664 sec, total=0.001664 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000319 sec of elapsed time 8: waited for 'db file sequential read' file#=0x2, block#=0x76a2, blocks=0x1 wait_id=1702 seq_num=1703 snap_id=1 wait times: snap=0.003404 sec, exc=0.003404 sec, total=0.003404 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000293 sec of elapsed time 9: waited for 'db file sequential read' file#=0x2, block#=0x768a, blocks=0x1 wait_id=1701 seq_num=1702 snap_id=1 wait times: snap=0.001548 sec, exc=0.001548 sec, total=0.001548 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000326 sec of elapsed time Sampled Session History of session 201 serial 47067 --------------------------------------------------- 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:07:29] waited for 'db file sequential read', seq_num: 1265 p1: 'file#'=0x2 p2: 'block#'=0x592 p3: 'blocks'=0x1 time_waited: >= 0 sec (still in wait) [1 sample, 22:07:28] idle wait at each sample [session created at: 22:07:29] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'db file sequential read' [1 sample, 22:07:29 ] time_waited: >= 0 sec (still in wait) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-20 22:07:30.126 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 14156, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-20 21:58:20.057418 :99CC61EA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-20 21:58:20.057433 :99CC61EB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-20 21:58:20.057648 :99CC61EC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-20 21:58:20.057661 :99CC61ED:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-20 21:58:20.057864 :99CC61EE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-20 21:58:20.057877 :99CC61EF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-20 21:58:20.058081 :99CC61F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-20 21:58:20.058094 :99CC61F1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-20 21:58:20.058290 :99CC61F2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-20 21:58:20.058302 :99CC61F3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-20 21:58:20.060717 :99CC61F4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 21:58:34.818780 :99CC66A2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 21:58:34.807 2025-05-20 21:58:34.818782 :99CC66A3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13052 pso_num=25 pso_serial#=30 2025-05-20 21:58:34.818918 :99CC66A4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13052 osp_idx=23 osp_ver=109169 osp_pg=0 (spawn #202502) 2025-05-20 21:58:34.818918 :99CC66A5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 21:58:34.818919 :99CC66A6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=168 time=754124688 2025-05-20 21:58:34.818921 :99CC66A7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 21:58:34.818921 :99CC66A8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 21:58:34.818921 :99CC66A9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 21:58:34.818922 :99CC66AA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 21:58:34.818922 :99CC66AB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 21:58:34.819411 :99CC66AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 21:59:04.909550 :99CC703E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 21:59:34.914636 :99CC79F7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 21:59:34.903 2025-05-20 21:59:34.914638 :99CC79F8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10660 pso_num=25 pso_serial#=31 2025-05-20 21:59:34.914773 :99CC79F9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10660 osp_idx=23 osp_ver=109170 osp_pg=0 (spawn #202504) 2025-05-20 21:59:34.914773 :99CC79FA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 21:59:34.914774 :99CC79FB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=169 time=754184782 2025-05-20 21:59:34.914774 :99CC79FC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 21:59:34.914775 :99CC79FD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 21:59:34.914775 :99CC79FE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 21:59:34.914776 :99CC79FF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 21:59:34.914776 :99CC7A00:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 21:59:34.915243 :99CC7A01:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.195114 :99CC8422:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.195114*:99CC842E:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DDB898 estart=1747749601 eid=16780800 ctx=0x000000077FD6A000 cwh=0x0000000024DD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-20 22:00:02.195114*:99CC842F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DDB898 curCtx=0x0000000024DD7AB8 pubTabIdxCnt=0 2025-05-20 22:00:02.195114*:99CC8430:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DDB898 2025-05-20 22:00:02.195114*:99CC8431:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DDB898 2025-05-20 22:00:02.195114*:99CC8436:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DDB898 curCtx=0x0000000024DD7AB8 xsc->flg4=65792 flags=2 2025-05-20 22:00:02.195114*:99CC8437:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DDB898 2025-05-20 22:00:02.201289 :99CC8444:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.201345 :99CC8449:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-20 22:00:02.206641 :99CC8465:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-20 22:00:02.207260 :99CC8470:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 e5d5110000000000 2025-05-20 22:00:02.209104 :99CC848F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.209173 :99CC849C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.209182 :99CC84A3:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-05-20 22:00:02.209187 :99CC84A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.209214 :99CC84B0:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.209866 :99CC84BC:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 225900761) 2025-05-20 22:00:02.209870 :99CC84BD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.209891 :99CC84C9:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.209897 :99CC84D5:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65561 1) 2025-05-20 22:00:02.209900 :99CC84D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.209925 :99CC84E2:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.209929 :99CC84EB:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65561) 2025-05-20 22:00:02.209931 :99CC84EF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.209973 :99CC8510:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.210491 :99CC85BE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.210508 :99CC85C5:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-20 22:00:02.211373 :99CC85CC:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 e6d5110000000000 2025-05-20 22:00:02.211760 :99CC85CD:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 225900761) 2025-05-20 22:00:02.211768 :99CC85CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.211806 :99CC85D7:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:02.220151 :99CC8650:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-20 22:00:02.222036 :99CC8651:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.222115 :99CC8654:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-20 22:00:02.222253 :99CC8661:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-20 22:00:02.320027 :99CC876A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:04.012345 :99CC8ABF:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:00:34.146416 :99CC9893:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:00:35.110019 :99CC994F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:00:35.099 2025-05-20 22:00:35.110022 :99CC9950:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13256 pso_num=25 pso_serial#=32 2025-05-20 22:00:35.110150 :99CC9951:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13256 osp_idx=23 osp_ver=109171 osp_pg=0 (spawn #202514) 2025-05-20 22:00:35.110150 :99CC9952:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:00:35.110151 :99CC9953:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=170 time=754244969 2025-05-20 22:00:35.110151 :99CC9954:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:00:35.110151 :99CC9955:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:00:35.110152 :99CC9956:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:00:35.110152 :99CC9957:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:00:35.110153 :99CC9958:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:00:35.110727 :99CC9961:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:01:05.224212 :99CCA41A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:01:35.208299 :99CCADE4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:01:35.197 2025-05-20 22:01:35.208301 :99CCADE5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13456 pso_num=25 pso_serial#=33 2025-05-20 22:01:35.208432 :99CCADE6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13456 osp_idx=23 osp_ver=109172 osp_pg=0 (spawn #202516) 2025-05-20 22:01:35.208433 :99CCADE7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:01:35.208433 :99CCADE8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=171 time=754305079 2025-05-20 22:01:35.208433 :99CCADE9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:01:35.208433 :99CCADEA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:01:35.208434 :99CCADEB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:01:35.208434 :99CCADEC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:01:35.208434 :99CCADED:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:01:35.208939 :99CCADEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:02:05.264385 :99CCB7B4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:02:35.306209 :99CCC17C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:02:35.295 2025-05-20 22:02:35.306211 :99CCC17D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14312 pso_num=25 pso_serial#=34 2025-05-20 22:02:35.306335 :99CCC17E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14312 osp_idx=23 osp_ver=109173 osp_pg=0 (spawn #202518) 2025-05-20 22:02:35.306335 :99CCC17F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:02:35.306336 :99CCC180:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=172 time=754365172 2025-05-20 22:02:35.306336 :99CCC181:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:02:35.306337 :99CCC182:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:02:35.306337 :99CCC183:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:02:35.306337 :99CCC184:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:02:35.306338 :99CCC185:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:02:35.306842 :99CCC186:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:03:05.367771 :99CCCC0F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:03:30.406094 :99CCD43D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:03:30.395 2025-05-20 22:03:30.406096 :99CCD43E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13828 pso_num=25 pso_serial#=35 2025-05-20 22:03:30.406235 :99CCD43F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13828 osp_idx=23 osp_ver=109174 osp_pg=0 (spawn #202521) 2025-05-20 22:03:30.406236 :99CCD440:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:03:30.406236 :99CCD441:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=173 time=754420266 2025-05-20 22:03:30.406237 :99CCD442:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:03:30.406237 :99CCD443:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:03:30.406237 :99CCD444:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:03:30.406238 :99CCD445:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:03:30.406238 :99CCD446:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:03:30.406705 :99CCD447:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:03:35.398775 :99CCD5EF:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:04:05.500520 :99CCDF8C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:04:35.513837 :99CCE96C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:04:35.502 2025-05-20 22:04:35.513839 :99CCE96D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10684 pso_num=25 pso_serial#=36 2025-05-20 22:04:35.513964 :99CCE96E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10684 osp_idx=23 osp_ver=109175 osp_pg=0 (spawn #202523) 2025-05-20 22:04:35.513965 :99CCE96F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:04:35.513965 :99CCE970:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=174 time=754485375 2025-05-20 22:04:35.513965 :99CCE971:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:04:35.513966 :99CCE972:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:04:35.513966 :99CCE973:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:04:35.513967 :99CCE974:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:04:35.513967 :99CCE975:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:04:35.514454 :99CCE976:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:05:05.605449 :99CCF48D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:05:35.609581 :99CD05FC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:05:35.598 2025-05-20 22:05:35.609583 :99CD05FD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14252 pso_num=25 pso_serial#=37 2025-05-20 22:05:35.609718 :99CD05FE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14252 osp_idx=23 osp_ver=109176 osp_pg=0 (spawn #202525) 2025-05-20 22:05:35.609719 :99CD05FF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:05:35.609719 :99CD0600:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=175 time=754545469 2025-05-20 22:05:35.609720 :99CD0601:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:05:35.609720 :99CD0602:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:05:35.609720 :99CD0603:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:05:35.609721 :99CD0604:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:05:35.609721 :99CD0605:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:05:35.610188 :99CD0606:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:06:05.666738 :99CD1177:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:06:35.705623 :99CD1B84:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:06:35.694 2025-05-20 22:06:35.705625 :99CD1B85:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11776 pso_num=25 pso_serial#=38 2025-05-20 22:06:35.705759 :99CD1B86:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11776 osp_idx=23 osp_ver=109177 osp_pg=0 (spawn #202527) 2025-05-20 22:06:35.705760 :99CD1B87:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:06:35.705761 :99CD1B88:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=176 time=754605563 2025-05-20 22:06:35.705761 :99CD1B89:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:06:35.705761 :99CD1B8A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:06:35.705762 :99CD1B8B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:06:35.705762 :99CD1B8C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:06:35.705763 :99CD1B8D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:06:35.706238 :99CD1B8E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:07:05.768400 :99CD2559:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:07:28.036070 :99CD66E1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:07:28.032 2025-05-20 22:07:28.036072 :99CD66E2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6572 pso_num=25 pso_serial#=39 2025-05-20 22:07:28.036246 :99CD66E3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=6572 osp_idx=23 osp_ver=109178 osp_pg=0 (spawn #202529) 2025-05-20 22:07:28.036247 :99CD66E4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:07:28.036247 :99CD66E5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=177 time=754657891 2025-05-20 22:07:28.036248 :99CD66E6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:07:28.036248 :99CD66E7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:07:28.036248 :99CD66E8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:07:28.036248 :99CD66E9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:07:28.036249 :99CD66EA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:07:28.037181 :99CD66EB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:07:28.037225 :99CD66F1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-20 22:07:28.145837 :99CD6723:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-20 22:07:29.329939 :99CD67B3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-20 22:07:29.329 2025-05-20 22:07:29.329941 :99CD67B4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14156 pso_num=25 pso_serial#=40 2025-05-20 22:07:29.330078 :99CD67B5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14156 osp_idx=23 osp_ver=109179 osp_pg=0 (spawn #202531) 2025-05-20 22:07:29.330079 :99CD67B6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-20 22:07:29.330080 :99CD67B7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=178 time=754659188 2025-05-20 22:07:29.330080 :99CD67B8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-20 22:07:29.330080 :99CD67B9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-20 22:07:29.330081 :99CD67BA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-20 22:07:29.330081 :99CD67BB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-20 22:07:29.330081 :99CD67BC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-20 22:07:29.330586 :99CD67BD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-20 22:07:29.330629 :99CD67C3:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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 25 (osid: 14156, M002)