Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250720060006\orcl_j000_16604_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:36169M/63366M, Ph+PgF:42074M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 16604, image: ORACLE.EXE (J000) *** 2025-07-20 06:00:06.554 *** SESSION ID:(201.58851) 2025-07-20 06:00:06.554 *** 2025-07-20 06:00:06.554 Process diagnostic dump for ORACLE.EXE (J000), OS id=16604, pid: 25, proc_ser: 65, sid: 201, sess_ser: 58851 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16604 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.395187 sec, exc=0.395187 sec, total=0.395187 sec wait times: max=0.500000 sec, heur=4.388782 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.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.500005 sec, exc=0.500005 sec, total=0.500005 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.502099 sec, exc=0.502099 sec, total=0.502099 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499980 sec, exc=0.499980 sec, total=0.499980 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.499991 sec, exc=0.499991 sec, total=0.499991 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.500013 sec, exc=0.500013 sec, total=0.500013 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 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.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.491425 sec, exc=0.491425 sec, total=0.491425 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 201 serial 58851 --------------------------------------------------- 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, 06:00:02 - 06:00:06] idle wait at each sample [session created at: 06:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-20 06:00:06.554 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 16604, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-20 05:52:15.235255 :B46E1A14: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-07-20 05:52:15.235430 :B46E1A19: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-07-20 05:52:15.236245 :B46E1A1E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:52:17.088709 :B46E1AC2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:52:17.075 2025-07-20 05:52:17.088711 :B46E1AC3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11772 pso_num=25 pso_serial#=53 2025-07-20 05:52:17.088845 :B46E1AC4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=11772 (legacy spawn) 2025-07-20 05:52:17.095336 :B46E1AC5: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-07-20 05:52:17.095505 :B46E1ACA: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-07-20 05:52:17.096275 :B46E1ACF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:52:17.105016 :B46E1AD2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:52:17.090 2025-07-20 05:52:17.105018 :B46E1AD3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9112 pso_num=25 pso_serial#=54 2025-07-20 05:52:17.105152 :B46E1AD4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=9112 (legacy spawn) 2025-07-20 05:52:17.111657 :B46E1AD5: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-07-20 05:52:17.111844 :B46E1ADE: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-07-20 05:52:17.112637 :B46E1ADF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:52:18.217743 :B46E1B31:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:52:18.210 2025-07-20 05:52:18.217745 :B46E1B32:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19192 pso_num=25 pso_serial#=55 2025-07-20 05:52:18.217879 :B46E1B33:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=19192 (legacy spawn) 2025-07-20 05:52:18.224342 :B46E1B34: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-07-20 05:52:18.224516 :B46E1B39: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-07-20 05:52:18.225296 :B46E1B3E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:52:32.530079 :B46E1FB4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:52:32.521 2025-07-20 05:52:32.530081 :B46E1FB5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10156 pso_num=25 pso_serial#=56 2025-07-20 05:52:32.530218 :B46E1FB6:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10156 (legacy spawn) 2025-07-20 05:52:32.536809 :B46E1FB7: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-07-20 05:52:32.536976 :B46E1FBC: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-07-20 05:52:32.537822 :B46E1FC1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:53:13.902865 :B46E2D1D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:53:13.891 2025-07-20 05:53:13.902867 :B46E2D1E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7564 pso_num=25 pso_serial#=57 2025-07-20 05:53:13.903005 :B46E2D1F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7564 osp_idx=23 osp_ver=204424 osp_pg=0 (spawn #403591) 2025-07-20 05:53:13.903006 :B46E2D20:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 05:53:13.903006 :B46E2D21:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=48 time=1671569798 2025-07-20 05:53:13.903007 :B46E2D22:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 05:53:13.903007 :B46E2D23:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 05:53:13.903008 :B46E2D24:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 05:53:13.903008 :B46E2D25:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 05:53:13.903008 :B46E2D26:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 05:53:13.903483 :B46E2D27: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-07-20 05:53:43.973052 :B46E3797:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:54:13.986533 :B46E4131:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:54:13.975 2025-07-20 05:54:13.986535 :B46E4132:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19380 pso_num=25 pso_serial#=58 2025-07-20 05:54:13.986671 :B46E4133:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19380 osp_idx=23 osp_ver=204425 osp_pg=0 (spawn #403593) 2025-07-20 05:54:13.986672 :B46E4134:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 05:54:13.986672 :B46E4135:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=49 time=1671629876 2025-07-20 05:54:13.986672 :B46E4136:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 05:54:13.986673 :B46E4137:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 05:54:13.986673 :B46E4138:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 05:54:13.986673 :B46E4139:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 05:54:13.986674 :B46E413A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 05:54:13.987156 :B46E413B: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-07-20 05:54:44.069777 :B46E4ADB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:55:14.092765 :B46E5492:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:55:14.081 2025-07-20 05:55:14.092767 :B46E5493:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15708 pso_num=25 pso_serial#=59 2025-07-20 05:55:14.092881 :B46E5494:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15708 osp_idx=23 osp_ver=204426 osp_pg=0 (spawn #403596) 2025-07-20 05:55:14.092882 :B46E5495:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 05:55:14.092882 :B46E5496:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=50 time=1671689986 2025-07-20 05:55:14.092883 :B46E5497:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 05:55:14.092883 :B46E5498:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 05:55:14.092883 :B46E5499:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 05:55:14.092884 :B46E549A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 05:55:14.092884 :B46E549B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 05:55:14.093379 :B46E549C: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-07-20 05:55:39.129560 :B46E5C9D: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-07-20 05:56:09.235951 :B46E6653:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:56:14.184469 :B46E6847:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:56:14.173 2025-07-20 05:56:14.184471 :B46E6848:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19300 pso_num=25 pso_serial#=60 2025-07-20 05:56:14.184601 :B46E6849:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19300 osp_idx=23 osp_ver=204427 osp_pg=0 (spawn #403598) 2025-07-20 05:56:14.184602 :B46E684A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 05:56:14.184602 :B46E684B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=51 time=1671750079 2025-07-20 05:56:14.184602 :B46E684C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 05:56:14.184603 :B46E684D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 05:56:14.184603 :B46E684E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 05:56:14.184603 :B46E684F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 05:56:14.184603 :B46E6850:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 05:56:14.185065 :B46E6851: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-07-20 05:56:44.250153 :B46E7252:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:57:14.239536 :B46E7C03:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:57:14.229 2025-07-20 05:57:14.239539 :B46E7C04:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18360 pso_num=25 pso_serial#=61 2025-07-20 05:57:14.239675 :B46E7C05:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18360 osp_idx=23 osp_ver=204428 osp_pg=0 (spawn #403600) 2025-07-20 05:57:14.239676 :B46E7C06:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 05:57:14.239676 :B46E7C07:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=52 time=1671810126 2025-07-20 05:57:14.239677 :B46E7C08:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 05:57:14.239677 :B46E7C09:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 05:57:14.239677 :B46E7C0A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 05:57:14.239678 :B46E7C0B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 05:57:14.239678 :B46E7C0C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 05:57:14.240155 :B46E7C0D: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-07-20 05:57:44.361162 :B46E85BF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:58:14.342389 :B46E9014:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:58:14.331 2025-07-20 05:58:14.342391 :B46E9015:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7532 pso_num=25 pso_serial#=62 2025-07-20 05:58:14.342526 :B46E9016:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7532 osp_idx=23 osp_ver=204429 osp_pg=0 (spawn #403602) 2025-07-20 05:58:14.342527 :B46E9017:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 05:58:14.342528 :B46E9018:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=53 time=1671870236 2025-07-20 05:58:14.342528 :B46E9019:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 05:58:14.342529 :B46E901A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 05:58:14.342529 :B46E901B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 05:58:14.342529 :B46E901C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 05:58:14.342530 :B46E901D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 05:58:14.343005 :B46E901E: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-07-20 05:58:44.418784 :B46E9AC0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 05:59:14.419437 :B46EA45F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 05:59:14.408 2025-07-20 05:59:14.419439 :B46EA460:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15356 pso_num=25 pso_serial#=63 2025-07-20 05:59:14.419571 :B46EA461:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15356 osp_idx=23 osp_ver=204430 osp_pg=0 (spawn #403604) 2025-07-20 05:59:14.419572 :B46EA462:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 05:59:14.419572 :B46EA463:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=54 time=1671930314 2025-07-20 05:59:14.419573 :B46EA464:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 05:59:14.419573 :B46EA465:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 05:59:14.419573 :B46EA466:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 05:59:14.419574 :B46EA467:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 05:59:14.419574 :B46EA468:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 05:59:14.420051 :B46EA469: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-07-20 05:59:44.524475 :B46EAE09:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 06:00:00.029290 :B46EB311:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 06:00:00.019 2025-07-20 06:00:00.029293 :B46EB312:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9440 pso_num=25 pso_serial#=64 2025-07-20 06:00:00.029482 :B46EB313:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9440 osp_idx=23 osp_ver=204431 osp_pg=0 (spawn #403606) 2025-07-20 06:00:00.029482 :B46EB314:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 06:00:00.029483 :B46EB315:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=55 time=1671975923 2025-07-20 06:00:00.029483 :B46EB316:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 06:00:00.029483 :B46EB317:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 06:00:00.029484 :B46EB318:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 06:00:00.029484 :B46EB319:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 06:00:00.029484 :B46EB31A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 06:00:00.030009 :B46EB31B: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-07-20 06:00:00.030051 :B46EB322: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-07-20 06:00:00.030135 :B46EB335:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:00.034150 :B46EB344: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-07-20 06:00:00.035384 :B46EB34C: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-07-20 06:00:00.035412 :B46EB34F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:00.035455 :B46EB35A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-20 06:00:00.037332 :B46EB365: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-07-20 06:00:00.037366 :B46EB368:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:00.037408 :B46EB373:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-20 06:00:00.037889 :B46EB37E: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-07-20 06:00:00.040379 :B46EB386: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-07-20 06:00:00.046242 :B46EB38E: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-07-20 06:00:00.051739 :B46EB396: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-07-20 06:00:00.053263 :B46EB39E: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-07-20 06:00:00.056294 :B46EB3A6: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-07-20 06:00:00.057653 :B46EB3AE: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-07-20 06:00:00.060660 :B46EB3B6: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-07-20 06:00:00.064745 :B46EB3BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:00.065133 :B46EB3CD: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-07-20 06:00:00.065188 :B46EB3D0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-07-20 06:00:00.065202 :B46EB3D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-07-20 06:00:00.068169 :B46EB3D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:00.068436 :B46EB3E6: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-07-20 06:00:00.068479 :B46EB3E9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-07-20 06:00:00.068492 :B46EB3EA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-07-20 06:00:00.071558 :B46EB3F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:00.071845 :B46EB3FF: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-07-20 06:00:00.071891 :B46EB402:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-07-20 06:00:00.071906 :B46EB403:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-07-20 06:00:00.072077 :B46EB409: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-07-20 06:00:00.072089 :B46EB40C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:00.072112 :B46EB418:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-20 06:00:00.073824 :B46EB422:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 06:00:02.025275 :B46EB4C2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 06:00:02.019 2025-07-20 06:00:02.025278 :B46EB4C3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16604 pso_num=25 pso_serial#=65 2025-07-20 06:00:02.025421 :B46EB4C4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16604 osp_idx=23 osp_ver=204432 osp_pg=0 (spawn #403607) 2025-07-20 06:00:02.025421 :B46EB4C5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 06:00:02.025422 :B46EB4C6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=56 time=1671977923 2025-07-20 06:00:02.025422 :B46EB4C7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 06:00:02.025422 :B46EB4C8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 06:00:02.025423 :B46EB4C9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 06:00:02.025423 :B46EB4CA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 06:00:02.025423 :B46EB4CB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 06:00:02.025916 :B46EB4CC: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-07-20 06:00:02.031285 :B46EB4ED: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-07-20 06:00:02.031340 :B46EB4FA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-20 06:00:02.042422 :B46EB543: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-07-20 06:00:02.047697 :B46EB575: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-07-20 06:00:02.048450 :B46EB59D: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-07-20 06:00:02.053963 :B46EB5E7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-20 06:00:02.054108 :B46EB5F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 06:00:02.054911 :B46EB668: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-07-20 06:00:02.055220 :B46EB6EC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-20 06:00:02.056823 :B46EB756: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-07-20 06:00:02.056875 :B46EB759: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-07-20 06:00:02.056946 :B46EB766: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-07-20 06:00:02.160927 :B46EB855: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-07-20 06:00:02.163012 :B46EB858: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-07-20 06:00:02.163049 :B46EB85B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-20 06:00:02.165506 :B46EB861:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-20 06:00:02.168864 :B46EB862: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-07-20 06:00:02.168949 :B46EB865: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-07-20 06:00:02.169041 :B46EB872: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 16604, J000)