Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250626220009\orcl_j002_17364_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:36296M/63366M, Ph+PgF:42426M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 27 Windows thread id: 17364, image: ORACLE.EXE (J002) *** 2025-06-26 22:00:09.183 *** SESSION ID:(219.9963) 2025-06-26 22:00:09.183 *** 2025-06-26 22:00:09.183 Process diagnostic dump for ORACLE.EXE (J002), OS id=17364, pid: 27, proc_ser: 182, sid: 219, sess_ser: 9963 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 17364 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) 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.171409 sec, exc=0.171409 sec, total=0.171409 sec wait times: max=0.500000 sec, heur=7.127719 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.000007 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.500216 sec, exc=0.500216 sec, total=0.500216 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 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.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.000008 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.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.000009 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.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.000011 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.500114 sec, exc=0.500114 sec, total=0.500114 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 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.500002 sec, exc=0.500002 sec, total=0.500002 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 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.506297 sec, exc=0.506297 sec, total=0.506297 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 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.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.000011 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.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.000007 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.486960 sec, exc=0.486960 sec, total=0.486960 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 219 serial 9963 --------------------------------------------------- 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:02 - 22:00:09] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.016000 sec (max dump time=30.000000 sec) *** 2025-06-26 22:00:09.199 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 27 (osid: 17364, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-26 21:01:01.582061 :AA090815:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 21:01:01.582062 :AA090816:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=34 time=3947404750 2025-06-26 21:01:01.582062 :AA090817:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 21:01:01.582063 :AA090818:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 21:01:01.582063 :AA090819:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 21:01:01.582063 :AA09081A:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 21:01:01.582064 :AA09081B:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 21:01:01.582557 :AA09081C: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-06-26 21:01:01.582601 :AA090822: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-06-26 21:01:01.589765 :AA090830: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-06-26 21:01:01.590832 :AA090838: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-06-26 21:01:01.591392 :AA090840: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-06-26 21:01:01.591858 :AA090848: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-06-26 21:01:01.592368 :AA090850: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-06-26 21:01:01.595110 :AA090858: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-06-26 21:01:01.596246 :AA090860: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-06-26 21:01:01.644672 :AA090868: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-06-26 21:01:01.645953 :AA090870: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-06-26 21:01:01.646835 :AA090878: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-06-26 21:01:01.647072 :AA090880: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-06-26 21:01:01.647315 :AA090888: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-06-26 21:01:01.648998 :AA090890:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-26 21:02:00.343046 :AA091BDF:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-26 21:02:00.331 2025-06-26 21:02:00.343047 :AA091BE0:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15292 pso_num=27 pso_serial#=177 2025-06-26 21:02:00.343184 :AA091BE1:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=15292 osp_idx=25 osp_ver=103205 osp_pg=0 (spawn #325692) 2025-06-26 21:02:00.343185 :AA091BE2:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 21:02:00.343185 :AA091BE3:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=35 time=3947463532 2025-06-26 21:02:00.343186 :AA091BE4:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 21:02:00.343186 :AA091BE5:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 21:02:00.343187 :AA091BE6:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 21:02:00.343187 :AA091BE7:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 21:02:00.343187 :AA091BE8:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 21:02:00.343748 :AA091BE9: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-06-26 21:02:00.343802 :AA091BEF: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-06-26 21:02:00.352312 :AA091C04:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-26 21:22:02.751735 :AA0AB5A7:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-26 21:22:02.739 2025-06-26 21:22:02.751737 :AA0AB5A8:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16944 pso_num=27 pso_serial#=178 2025-06-26 21:22:02.751873 :AA0AB5A9:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=16944 osp_idx=25 osp_ver=103206 osp_pg=0 (spawn #325737) 2025-06-26 21:22:02.751873 :AA0AB5AA:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 21:22:02.751874 :AA0AB5AB:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=36 time=3948665938 2025-06-26 21:22:02.751874 :AA0AB5AC:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 21:22:02.751875 :AA0AB5AD:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 21:22:02.751875 :AA0AB5AE:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 21:22:02.751875 :AA0AB5AF:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 21:22:02.751876 :AA0AB5B0:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 21:22:02.752357 :AA0AB5B1: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-06-26 21:22:02.752396 :AA0AB5B7: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-06-26 21:22:02.756503 :AA0AB5D0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:22:02.756545 :AA0AB5D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:22:02.756881 :AA0AB5D2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:22:02.756900 :AA0AB5D3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:22:02.757119 :AA0AB5D4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:22:02.757133 :AA0AB5D5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:22:02.757346 :AA0AB5D6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:22:02.757359 :AA0AB5D7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:22:02.757563 :AA0AB5D8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:22:02.757575 :AA0AB5D9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:22:02.757777 :AA0AB5DA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:22:02.757791 :AA0AB5DB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:22:02.760052 :AA0AB5DC:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-26 21:52:06.439773 :AA0D10E1:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-26 21:52:06.427 2025-06-26 21:52:06.439775 :AA0D10E2:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17920 pso_num=27 pso_serial#=179 2025-06-26 21:52:06.439908 :AA0D10E3:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=17920 osp_idx=25 osp_ver=103207 osp_pg=0 (spawn #325805) 2025-06-26 21:52:06.439908 :AA0D10E4:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 21:52:06.439909 :AA0D10E5:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=37 time=3950469625 2025-06-26 21:52:06.439909 :AA0D10E6:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 21:52:06.439910 :AA0D10E7:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 21:52:06.439910 :AA0D10E8:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 21:52:06.439910 :AA0D10E9:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 21:52:06.439911 :AA0D10EA:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 21:52:06.440410 :AA0D10EB: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-06-26 21:52:06.440447 :AA0D10F1: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-06-26 21:52:06.444504 :AA0D110A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:52:06.444548 :AA0D110B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:52:06.444798 :AA0D110C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:52:06.444816 :AA0D110D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:52:06.445026 :AA0D110E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:52:06.445038 :AA0D110F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:52:06.445246 :AA0D1110:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:52:06.445259 :AA0D1111:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:52:06.445467 :AA0D1112:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:52:06.445479 :AA0D1113:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:52:06.445676 :AA0D1114:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-26 21:52:06.445689 :AA0D1115:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-26 21:52:06.448054 :AA0D1116:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-26 22:00:00.037917 :AA0DAFCD:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-26 22:00:00.028 2025-06-26 22:00:00.037919 :AA0DAFCE:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=18264 pso_num=27 pso_serial#=180 2025-06-26 22:00:00.038062 :AA0DAFCF:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=18264 osp_idx=25 osp_ver=103208 osp_pg=0 (spawn #325824) 2025-06-26 22:00:00.038063 :AA0DAFD0:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 22:00:00.038063 :AA0DAFD1:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=38 time=3950943219 2025-06-26 22:00:00.038063 :AA0DAFD2:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 22:00:00.038064 :AA0DAFD3:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 22:00:00.038064 :AA0DAFD4:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 22:00:00.038064 :AA0DAFD5:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 22:00:00.038065 :AA0DAFD6:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 22:00:00.038575 :AA0DAFD7: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-06-26 22:00:00.038618 :AA0DAFDE: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-06-26 22:00:00.038698 :AA0DAFF2: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-06-26 22:00:00.042594 :AA0DB001: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-06-26 22:00:00.043754 :AA0DB009: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-06-26 22:00:00.043779 :AA0DB00C: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-06-26 22:00:00.043818 :AA0DB017: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-06-26 22:00:00.045655 :AA0DB022: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-06-26 22:00:00.045684 :AA0DB025: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-06-26 22:00:00.045740 :AA0DB030: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-06-26 22:00:00.046198 :AA0DB03B: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-06-26 22:00:00.048649 :AA0DB043: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-06-26 22:00:00.053979 :AA0DB04B: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-06-26 22:00:00.059456 :AA0DB053: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-06-26 22:00:00.060931 :AA0DB05B: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-06-26 22:00:00.063949 :AA0DB063: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-06-26 22:00:00.065363 :AA0DB06B: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-06-26 22:00:00.068281 :AA0DB073: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-06-26 22:00:00.071711 :AA0DB07B: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-06-26 22:00:00.072104 :AA0DB08A: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-06-26 22:00:00.072152 :AA0DB08D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-06-26 22:00:00.072165 :AA0DB08E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-06-26 22:00:00.074312 :AA0DB094: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-06-26 22:00:00.074359 :AA0DB097:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-06-26 22:00:00.074371 :AA0DB098:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-06-26 22:00:00.076217 :AA0DB09E: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-06-26 22:00:00.076257 :AA0DB0A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-06-26 22:00:00.076268 :AA0DB0A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-06-26 22:00:00.076427 :AA0DB0A8: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-06-26 22:00:00.076443 :AA0DB0AB: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-06-26 22:00:00.076492 :AA0DB0B6: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-06-26 22:00:00.078093 :AA0DB0C1:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-26 22:00:01.334834 :AA0DB11B:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-26 22:00:01.325 2025-06-26 22:00:01.334836 :AA0DB11C:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17600 pso_num=27 pso_serial#=181 2025-06-26 22:00:01.334982 :AA0DB11D:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=17600 (legacy spawn) 2025-06-26 22:00:01.341487 :AA0DB11E: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-06-26 22:00:01.341669 :AA0DB123: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-06-26 22:00:01.342462 :AA0DB128:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-26 22:00:02.042109 :AA0DB1A9:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-26 22:00:02.036 2025-06-26 22:00:02.042112 :AA0DB1AA:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17364 pso_num=27 pso_serial#=182 2025-06-26 22:00:02.042323 :AA0DB1AB:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=17364 osp_idx=25 osp_ver=103210 osp_pg=0 (spawn #325825) 2025-06-26 22:00:02.042323 :AA0DB1AC:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 22:00:02.042324 :AA0DB1AD:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=39 time=3950945235 2025-06-26 22:00:02.042325 :AA0DB1AE:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 22:00:02.042326 :AA0DB1AF:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 22:00:02.042327 :AA0DB1B0:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 22:00:02.042327 :AA0DB1B1:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 22:00:02.042327 :AA0DB1B2:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 22:00:02.042988 :AA0DB1C0: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-06-26 22:00:02.049206 :AA0DB200: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-06-26 22:00:02.049270 :AA0DB20A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-06-26 22:00:02.054611 :AA0DB22B:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-26 22:00:02.055254 :AA0DB241:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 ba1f120000000000 2025-06-26 22:00:02.056979 :AA0DB24A: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-06-26 22:00:02.057056 :AA0DB258: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-06-26 22:00:02.057065 :AA0DB25E:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-06-26 22:00:02.057069 :AA0DB25F: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-06-26 22:00:02.057096 :AA0DB26C: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-06-26 22:00:02.057842 :AA0DB277:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 229582404) 2025-06-26 22:00:02.057847 :AA0DB278: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-06-26 22:00:02.057873 :AA0DB283: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-06-26 22:00:02.057884 :AA0DB290:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65563 1) 2025-06-26 22:00:02.057887 :AA0DB291: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-06-26 22:00:02.057914 :AA0DB29D: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-06-26 22:00:02.057918 :AA0DB2A6:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65563) 2025-06-26 22:00:02.057920 :AA0DB2AA: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-06-26 22:00:02.057962 :AA0DB2C8: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-06-26 22:00:02.058690 :AA0DB35F: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-06-26 22:00:02.058722 :AA0DB369:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-26 22:00:02.059673 :AA0DB370:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 bb1f120000000000 2025-06-26 22:00:02.060040 :AA0DB371:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 229582404) 2025-06-26 22:00:02.060045 :AA0DB372: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-06-26 22:00:02.060071 :AA0DB37D: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-06-26 22:00:02.068742 :AA0DB3DF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-06-26 22:00:02.069482 :AA0DB3E1:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=24 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-26 22:00:02.069696 :AA0DB3E3:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=24 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-26 22:00:02.069758 :AA0DB3E5:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=24 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-26 22:00:02.070200 :AA0DB3E6: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-06-26 22:00:02.070242 :AA0DB3EA: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-06-26 22:00:02.070357 :AA0DB3FE: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-06-26 22:00:02.161966 :AA0DB49F:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-26 22:00:04.033754 :AA0DB8E8:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 27 (osid: 17364, J002)