Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250708220004\orcl_j002_13600_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:36550M/63366M, Ph+PgF:42677M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 27 Windows thread id: 13600, image: ORACLE.EXE (J002) *** 2025-07-08 22:00:04.607 *** SESSION ID:(219.25077) 2025-07-08 22:00:04.607 *** 2025-07-08 22:00:04.607 Process diagnostic dump for ORACLE.EXE (J002), OS id=13600, pid: 27, proc_ser: 197, sid: 219, sess_ser: 25077 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13600 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) 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.294862 sec, exc=0.294862 sec, total=0.294862 sec wait times: max=0.500000 sec, heur=4.303524 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.000011 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.499992 sec, exc=0.499992 sec, total=0.499992 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 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.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.000014 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.499994 sec, exc=0.499994 sec, total=0.499994 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 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.510107 sec, exc=0.510107 sec, total=0.510107 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.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 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.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.000006 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.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 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.498494 sec, exc=0.498494 sec, total=0.498494 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 219 serial 25077 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [5 samples, 22:00:00 - 22:00:04] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-08 22:00:04.607 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 27 (osid: 13600, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-08 18:00:27.892725 :AF4F6AEA:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 18:00:27.899967 :AF4F6AF8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.901099 :AF4F6B00:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.901662 :AF4F6B08:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.902115 :AF4F6B10:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.902543 :AF4F6B18:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.905060 :AF4F6B20:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.906149 :AF4F6B28:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.955404 :AF4F6B30:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.956263 :AF4F6B38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.956503 :AF4F6B40:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.956716 :AF4F6B48:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 18:00:27.958595 :AF4F6B50:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 19:00:35.784569 :AF5435AB:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 19:00:35.783 2025-07-08 19:00:35.784571 :AF5435AC:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17472 pso_num=27 pso_serial#=190 2025-07-08 19:00:35.784717 :AF5435AD:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=17472 osp_idx=25 osp_ver=143508 osp_pg=0 (spawn #365426) 2025-07-08 19:00:35.784717 :AF5435AE:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-08 19:00:35.784718 :AF5435AF:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=222 time=682011673 2025-07-08 19:00:35.784718 :AF5435B0:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-08 19:00:35.784718 :AF5435B1:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-08 19:00:35.784719 :AF5435B2:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-08 19:00:35.784719 :AF5435B3:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-08 19:00:35.784719 :AF5435B4:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-08 19:00:35.785240 :AF5435B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.785294 :AF5435BC:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 19:00:35.787968 :AF5435C9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.793450 :AF5435D1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.794692 :AF5435D9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.795294 :AF5435E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.795762 :AF5435E9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.796197 :AF5435F1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.798815 :AF5435F9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.800007 :AF543601:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.849506 :AF543609:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.850381 :AF543611:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.850609 :AF543619:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.850819 :AF543621:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 19:00:35.852856 :AF543629:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 20:00:43.512403 :AF58F885:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 20:00:43.512 2025-07-08 20:00:43.512405 :AF58F886:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=9676 pso_num=27 pso_serial#=191 2025-07-08 20:00:43.512549 :AF58F887:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=9676 (legacy spawn) 2025-07-08 20:00:43.518968 :AF58F888:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:43.519163 :AF58F891:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 20:00:43.519941 :AF58F892:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 20:00:43.528653 :AF58F895:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 20:00:43.527 2025-07-08 20:00:43.528655 :AF58F896:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=12296 pso_num=27 pso_serial#=192 2025-07-08 20:00:43.528787 :AF58F897:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=12296 (legacy spawn) 2025-07-08 20:00:43.535148 :AF58F898:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:43.535307 :AF58F8A1:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 20:00:43.536086 :AF58F8A2:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 20:00:44.132026 :AF58F901:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 20:00:44.121 2025-07-08 20:00:44.132028 :AF58F902:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=9536 pso_num=27 pso_serial#=193 2025-07-08 20:00:44.132158 :AF58F903:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=9536 osp_idx=25 osp_ver=143511 osp_pg=0 (spawn #365566) 2025-07-08 20:00:44.132159 :AF58F904:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-08 20:00:44.132160 :AF58F905:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=223 time=685620017 2025-07-08 20:00:44.132160 :AF58F906:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-08 20:00:44.132160 :AF58F907:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-08 20:00:44.132161 :AF58F908:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-08 20:00:44.132161 :AF58F909:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-08 20:00:44.132162 :AF58F90A:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-08 20:00:44.132666 :AF58F90B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.132713 :AF58F911:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 20:00:44.139883 :AF58F91F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.140965 :AF58F927:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.141531 :AF58F92F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.141982 :AF58F937:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.142502 :AF58F93F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.144903 :AF58F947:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.145977 :AF58F94F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.195053 :AF58F957:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.196014 :AF58F95F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.196270 :AF58F967:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.196489 :AF58F96F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:00:44.198296 :AF58F977:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 20:42:35.765547 :AF5C45F6:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 20:42:35.757 2025-07-08 20:42:35.765549 :AF5C45F7:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16032 pso_num=27 pso_serial#=194 2025-07-08 20:42:35.765688 :AF5C45F8:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=16032 (legacy spawn) 2025-07-08 20:42:35.772246 :AF5C45F9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 20:42:35.835809 :AF5C4608:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 20:42:35.836574 :AF5C4612:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 21:00:52.159278 :AF5DB513:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 21:00:52.146 2025-07-08 21:00:52.159280 :AF5DB514:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=18100 pso_num=27 pso_serial#=195 2025-07-08 21:00:52.159410 :AF5DB515:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=18100 osp_idx=25 osp_ver=143513 osp_pg=0 (spawn #365702) 2025-07-08 21:00:52.159411 :AF5DB516:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-08 21:00:52.159411 :AF5DB517:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=224 time=689228048 2025-07-08 21:00:52.159412 :AF5DB518:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-08 21:00:52.159412 :AF5DB519:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-08 21:00:52.159412 :AF5DB51A:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-08 21:00:52.159413 :AF5DB51B:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-08 21:00:52.159413 :AF5DB51C:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-08 21:00:52.159961 :AF5DB51D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.160004 :AF5DB523:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 21:00:52.167868 :AF5DB531:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.168972 :AF5DB539:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.169536 :AF5DB541:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.169991 :AF5DB549:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.170422 :AF5DB551:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.172923 :AF5DB559:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.174005 :AF5DB561:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.222762 :AF5DB569:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.223900 :AF5DB571:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.224835 :AF5DB579:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.225074 :AF5DB581:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.225322 :AF5DB589:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 21:00:52.227225 :AF5DB591:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 22:00:00.029022 :AF625CFA:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 22:00:00.018 2025-07-08 22:00:00.029024 :AF625CFB:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=13928 pso_num=27 pso_serial#=196 2025-07-08 22:00:00.029158 :AF625CFC:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=13928 osp_idx=25 osp_ver=143514 osp_pg=0 (spawn #365837) 2025-07-08 22:00:00.029159 :AF625CFD:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-08 22:00:00.029159 :AF625CFE:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=225 time=692775923 2025-07-08 22:00:00.029159 :AF625CFF:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-08 22:00:00.029160 :AF625D00:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-08 22:00:00.029160 :AF625D01:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-08 22:00:00.029160 :AF625D02:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-08 22:00:00.029160 :AF625D03:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-08 22:00:00.029652 :AF625D04:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.029696 :AF625D0A:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 22:00:00.029771 :AF625D1F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.033768 :AF625D2E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.034994 :AF625D36:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.035023 :AF625D39:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.035063 :AF625D44:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 22:00:00.036812 :AF625D4F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.036836 :AF625D52:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.036870 :AF625D5D:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 22:00:00.037324 :AF625D68:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.039971 :AF625D70:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.045786 :AF625D78:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.051371 :AF625D80:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.052738 :AF625D88:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.055727 :AF625D90:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.056993 :AF625D98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.060041 :AF625DA0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.063469 :AF625DA8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.063877 :AF625DB7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.063930 :AF625DBA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-07-08 22:00:00.063943 :AF625DBB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-07-08 22:00:00.066057 :AF625DC1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.066100 :AF625DC4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-07-08 22:00:00.066111 :AF625DC5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-07-08 22:00:00.068175 :AF625DCB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.068224 :AF625DCE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-07-08 22:00:00.068235 :AF625DCF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-07-08 22:00:00.068410 :AF625DD5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.068424 :AF625DD8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.068465 :AF625DE3:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-08 22:00:00.070062 :AF625DEE:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-08 22:00:00.196288 :AF625E1F:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-08 22:00:00.190 2025-07-08 22:00:00.196290 :AF625E20:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=13600 pso_num=27 pso_serial#=197 2025-07-08 22:00:00.196428 :AF625E21:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=13600 osp_idx=25 osp_ver=143515 osp_pg=0 (spawn #365838) 2025-07-08 22:00:00.196429 :AF625E22:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-08 22:00:00.196430 :AF625E23:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=226 time=692776095 2025-07-08 22:00:00.196430 :AF625E24:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-08 22:00:00.196431 :AF625E25:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-08 22:00:00.196431 :AF625E26:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-08 22:00:00.196431 :AF625E27:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-08 22:00:00.196432 :AF625E28:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-08 22:00:00.196985 :AF625E32:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.202330 :AF625E5E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.202372 :AF625E61:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-07-08 22:00:00.259809 :AF625FF2:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-08 22:00:00.260435 :AF625FF3:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 9b37120000000000 2025-07-08 22:00:00.267933 :AF625FF4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.268011 :AF626002:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-08 22:00:00.268020 :AF626009:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-07-08 22:00:00.268025 :AF62600C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.268509 :AF626031:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-08 22:00:00.269310 :AF626049:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 230771787) 2025-07-08 22:00:00.269316 :AF62604A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.269345 :AF626054:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-08 22:00:00.269354 :AF626060:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65563 1) 2025-07-08 22:00:00.269357 :AF626063:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.269384 :AF62606D:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-08 22:00:00.269388 :AF626075:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65563) 2025-07-08 22:00:00.269390 :AF62607B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.269437 :AF6260A3:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-08 22:00:00.270422 :AF6261A1:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-08 22:00:00.270451 :AF6261A8:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-08 22:00:00.271333 :AF6261A9:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 9c37120000000000 2025-07-08 22:00:00.271720 :AF6261AA:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 230771787) 2025-07-08 22:00:00.271727 :AF6261AB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.271754 :AF6261B6:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-08 22:00:00.314297 :AF6261C3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-07-08 22:00:00.316075 :AF6261CC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.316123 :AF6261D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-08 22:00:00.316229 :AF6261E4:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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 27 (osid: 13600, J002)