Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250529220009\orcl_j003_14524_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:37239M/63366M, Ph+PgF:44123M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 14524, image: ORACLE.EXE (J003) *** 2025-05-29 22:00:09.404 *** SESSION ID:(233.23693) 2025-05-29 22:00:09.404 *** 2025-05-29 22:00:09.404 Process diagnostic dump for ORACLE.EXE (J003), OS id=14524, pid: 29, proc_ser: 86, sid: 233, sess_ser: 23693 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 14524 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.134916 sec, exc=0.134916 sec, total=0.134916 sec wait times: max=0.500000 sec, heur=7.663641 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.000003 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.500007 sec, exc=0.500007 sec, total=0.500007 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 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.000003 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.510112 sec, exc=0.510112 sec, total=0.510112 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=10 seq_num=11 snap_id=1 wait times: snap=0.499973 sec, exc=0.499973 sec, total=0.499973 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.500020 sec, exc=0.500020 sec, total=0.500020 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=8 seq_num=9 snap_id=1 wait times: snap=0.500000 sec, exc=0.500000 sec, total=0.500000 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.500011 sec, exc=0.500011 sec, total=0.500011 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.510094 sec, exc=0.510094 sec, total=0.510094 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.500006 sec, exc=0.500006 sec, total=0.500006 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time Sampled Session History of session 233 serial 23693 --------------------------------------------------- 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 --------------------------------------------------- [8 samples, 22:00:01 - 22:00:09] idle wait at each sample [session created at: 22:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-29 22:00:09.404 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 14524, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-29 00:00:26.157729 :9D53753A: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-05-29 00:00:26.157956 :9D537542: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-05-29 00:00:26.158204 :9D53754A: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-05-29 00:00:26.159980 :9D537552:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 00:00:51.908204 :9D537DC3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 00:00:51.897 2025-05-29 00:00:51.908207 :9D537DC4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=4696 pso_num=29 pso_serial#=72 2025-05-29 00:00:51.908347 :9D537DC5:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=4696 osp_idx=27 osp_ver=11801 osp_pg=0 (spawn #229423) 2025-05-29 00:00:51.908348 :9D537DC6:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 00:00:51.908348 :9D537DC7:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=110 time=1452624157 2025-05-29 00:00:51.908348 :9D537DC8:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 00:00:51.908349 :9D537DC9:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 00:00:51.908349 :9D537DCA:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 00:00:51.908349 :9D537DCB:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 00:00:51.908350 :9D537DCC:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 00:00:51.908861 :9D537DCD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 00:01:22.031505 :9D538A90:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 00:01:52.025466 :9D53949B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 00:01:52.014 2025-05-29 00:01:52.025467 :9D53949C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9468 pso_num=29 pso_serial#=73 2025-05-29 00:01:52.025604 :9D53949D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=9468 osp_idx=27 osp_ver=11802 osp_pg=0 (spawn #229425) 2025-05-29 00:01:52.025605 :9D53949E:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 00:01:52.025605 :9D53949F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=111 time=1452684266 2025-05-29 00:01:52.025605 :9D5394A0:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 00:01:52.025607 :9D5394A1:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 00:01:52.025608 :9D5394A2:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 00:01:52.025608 :9D5394A3:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 00:01:52.025608 :9D5394A4:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 00:01:52.026157 :9D5394A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 00:02:22.128262 :9D539EA3:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 00:02:27.065797 :9D53A0A2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 00:02:27.055 2025-05-29 00:02:27.065800 :9D53A0A3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14388 pso_num=29 pso_serial#=74 2025-05-29 00:02:27.065931 :9D53A0A4:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14388 osp_idx=27 osp_ver=11803 osp_pg=0 (spawn #229427) 2025-05-29 00:02:27.065932 :9D53A0A5:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 00:02:27.065932 :9D53A0A6:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=112 time=1452719313 2025-05-29 00:02:27.065933 :9D53A0A7:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 00:02:27.065933 :9D53A0A8:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 00:02:27.065934 :9D53A0A9:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 00:02:27.065934 :9D53A0AA:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 00:02:27.065934 :9D53A0AB:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 00:02:27.066421 :9D53A0AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 00:02:52.088424 :9D53A8DE:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 00:03:22.190658 :9D53B2A0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 00:03:52.187694 :9D53BCBD:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 00:03:52.176 2025-05-29 00:03:52.187696 :9D53BCBE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14436 pso_num=29 pso_serial#=75 2025-05-29 00:03:52.187828 :9D53BCBF:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14436 osp_idx=27 osp_ver=11804 osp_pg=0 (spawn #229430) 2025-05-29 00:03:52.187829 :9D53BCC0:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 00:03:52.187829 :9D53BCC1:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=113 time=1452804438 2025-05-29 00:03:52.187829 :9D53BCC2:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 00:03:52.187830 :9D53BCC3:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 00:03:52.187830 :9D53BCC4:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 00:03:52.187831 :9D53BCC5:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 00:03:52.187831 :9D53BCC6:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 00:03:52.188338 :9D53BCC7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 00:04:22.270767 :9D53C723:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 00:04:52.292305 :9D53D129:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 00:04:52.281 2025-05-29 00:04:52.292306 :9D53D12A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14532 pso_num=29 pso_serial#=76 2025-05-29 00:04:52.292437 :9D53D12B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14532 osp_idx=27 osp_ver=11805 osp_pg=0 (spawn #229432) 2025-05-29 00:04:52.292438 :9D53D12C:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 00:04:52.292438 :9D53D12D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=114 time=1452864547 2025-05-29 00:04:52.292438 :9D53D12E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 00:04:52.292439 :9D53D12F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 00:04:52.292439 :9D53D130:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 00:04:52.292439 :9D53D131:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 00:04:52.292439 :9D53D132:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 00:04:52.292974 :9D53D133:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 00:05:22.363907 :9D53DAFE:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 00:05:52.396877 :9D53EAA1:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 00:05:52.385 2025-05-29 00:05:52.396879 :9D53EAA2:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=580 pso_num=29 pso_serial#=77 2025-05-29 00:05:52.397017 :9D53EAA3:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=580 osp_idx=27 osp_ver=11806 osp_pg=0 (spawn #229435) 2025-05-29 00:05:52.397018 :9D53EAA4:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 00:05:52.397019 :9D53EAA5:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=115 time=1452924641 2025-05-29 00:05:52.397020 :9D53EAA6:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 00:05:52.397021 :9D53EAA7:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 00:05:52.397021 :9D53EAA8:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 00:05:52.397022 :9D53EAA9:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 00:05:52.397022 :9D53EAAA:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 00:05:52.397583 :9D53EAAB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 00:06:22.486388 :9D53F608:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:11.828078 :9D582784:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:11.815 2025-05-29 01:00:11.828080 :9D582785:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12772 pso_num=29 pso_serial#=78 2025-05-29 01:00:11.828212 :9D582786:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=12772 (legacy spawn) 2025-05-29 01:00:11.834659 :9D582787: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-05-29 01:00:11.834833 :9D58278C: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-05-29 01:00:11.835640 :9D582791:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:11.844312 :9D582794:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:11.830 2025-05-29 01:00:11.844314 :9D582795:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=3236 pso_num=29 pso_serial#=79 2025-05-29 01:00:11.844462 :9D582796:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=3236 (legacy spawn) 2025-05-29 01:00:11.850990 :9D582797: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-05-29 01:00:11.851155 :9D58279D: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-05-29 01:00:11.851948 :9D5827A1:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:26.546638 :9D582C0D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:26.532 2025-05-29 01:00:26.546640 :9D582C0E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10888 pso_num=29 pso_serial#=80 2025-05-29 01:00:26.546781 :9D582C0F:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=10888 (legacy spawn) 2025-05-29 01:00:26.553231 :9D582C10: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-05-29 01:00:26.553400 :9D582C15: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-05-29 01:00:26.554218 :9D582C1A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:26.562881 :9D582C1D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:26.547 2025-05-29 01:00:26.562883 :9D582C1E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14456 pso_num=29 pso_serial#=81 2025-05-29 01:00:26.563021 :9D582C1F:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14456 (legacy spawn) 2025-05-29 01:00:26.569455 :9D582C20: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-05-29 01:00:26.569618 :9D582C29: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-05-29 01:00:26.570434 :9D582C2A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:28.581893 :9D582CD8:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:28.573 2025-05-29 01:00:28.581895 :9D582CD9:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13376 pso_num=29 pso_serial#=82 2025-05-29 01:00:28.582045 :9D582CDA:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13376 (legacy spawn) 2025-05-29 01:00:28.588547 :9D582CDB: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-05-29 01:00:28.588734 :9D582CE0: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-05-29 01:00:28.589607 :9D582CE5:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:29.633569 :9D582D44:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:29.620 2025-05-29 01:00:29.633571 :9D582D45:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12920 pso_num=29 pso_serial#=83 2025-05-29 01:00:29.633712 :9D582D46:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=12920 (legacy spawn) 2025-05-29 01:00:29.648129 :9D582D47: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-05-29 01:00:29.648299 :9D582D4C: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-05-29 01:00:29.649068 :9D582D51:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:29.657674 :9D582D54:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:29.646 2025-05-29 01:00:29.657677 :9D582D55:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13924 pso_num=29 pso_serial#=84 2025-05-29 01:00:29.657865 :9D582D56:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13924 (legacy spawn) 2025-05-29 01:00:29.664342 :9D582D57: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-05-29 01:00:29.664512 :9D582D60: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-05-29 01:00:29.665306 :9D582D61:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 01:00:32.739752 :9D582E7B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 01:00:32.734 2025-05-29 01:00:32.739754 :9D582E7C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10360 pso_num=29 pso_serial#=85 2025-05-29 01:00:32.739887 :9D582E7D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10360 osp_idx=27 osp_ver=11814 osp_pg=0 (spawn #229559) 2025-05-29 01:00:32.739887 :9D582E7E:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 01:00:32.739888 :9D582E7F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=116 time=1456205000 2025-05-29 01:00:32.739888 :9D582E80:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 01:00:32.739889 :9D582E81:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 01:00:32.739889 :9D582E82:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 01:00:32.739889 :9D582E83:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 01:00:32.739889 :9D582E84:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 01:00:32.740405 :9D582E85: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-05-29 01:00:32.740462 :9D582E8B: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-05-29 01:00:32.744926 :9D582EA0: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-05-29 01:00:32.768906 :9D582ECD: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-05-29 01:00:32.784121 :9D582ED8: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-05-29 01:00:32.813159 :9D582EE6: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-05-29 01:00:32.816850 :9D582EEE: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-05-29 01:00:32.820558 :9D582EF6: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-05-29 01:00:32.824718 :9D582EFE: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-05-29 01:00:32.825787 :9D582F06: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-05-29 01:00:34.074677 :9D582F5F: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-05-29 01:00:34.104620 :9D582F67: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-05-29 01:00:34.104918 :9D582F6F: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-05-29 01:00:34.105188 :9D582F77: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-05-29 01:00:34.105205 :9D582F7A: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-05-29 01:00:34.105268 :9D582F87: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-05-29 01:00:34.107930 :9D582F94:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-29 22:00:01.650496 :9DBACA32:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-29 22:00:01.645 2025-05-29 22:00:01.650497 :9DBACA33:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14524 pso_num=29 pso_serial#=86 2025-05-29 22:00:01.650632 :9DBACA37:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14524 osp_idx=27 osp_ver=11815 osp_pg=0 (spawn #232475) 2025-05-29 22:00:01.650632 :9DBACA38:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 22:00:01.650632 :9DBACA39:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=117 time=1531762422 2025-05-29 22:00:01.650633 :9DBACA3A:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 22:00:01.650633 :9DBACA3B:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 22:00:01.650633 :9DBACA3C:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 22:00:01.650633 :9DBACA3D:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 22:00:01.650634 :9DBACA3E:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 22:00:01.651069 :9DBACA48:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.656329 :9DBACA76: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-05-29 22:00:01.656360 :9DBACA79:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-29 22:00:01.699059 :9DBACCF8:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-29 22:00:01.699745 :9DBACCF9:db_trace:kcc.c@13684:kccwbp(): [10021:29:233:1] 0115000000000000 0115000000000000 e0e7110000000000 2025-05-29 22:00:01.708703 :9DBACCFA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.708777 :9DBACD08:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 22:00:01.708787 :9DBACD0E:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-05-29 22:00:01.708792 :9DBACD0F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.708823 :9DBACD1D:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 22:00:01.709524 :9DBACD27:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 226797932) 2025-05-29 22:00:01.709529 :9DBACD28:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.709557 :9DBACD3D:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 22:00:01.709569 :9DBACD40:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65565 1) 2025-05-29 22:00:01.709572 :9DBACD41:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.709605 :9DBACD51:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 22:00:01.709609 :9DBACD59:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65565) 2025-05-29 22:00:01.709611 :9DBACD5A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.709654 :9DBACD75:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 22:00:01.711233 :9DBACE31:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 22:00:01.711243 :9DBACE39:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-29 22:00:01.712178 :9DBACE40:db_trace:kcc.c@13684:kccwbp(): [10021:29:233:1] 0115000000000000 0115000000000000 e1e7110000000000 2025-05-29 22:00:01.712604 :9DBACE41:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 226797932) 2025-05-29 22:00:01.712609 :9DBACE42:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.712633 :9DBACE53:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-29 22:00:01.747841 :9DBACE62:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:jslv.c:9203 2025-05-29 22:00:01.749527 :9DBACE63: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-05-29 22:00:01.749570 :9DBACE66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.749634 :9DBACE73: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 14524, J003)