Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250604220005\orcl_j002_16188_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:36946M/63366M, Ph+PgF:43664M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 16188, image: ORACLE.EXE (J002) *** 2025-06-04 22:00:05.597 *** SESSION ID:(225.24591) 2025-06-04 22:00:05.597 *** 2025-06-04 22:00:05.597 Process diagnostic dump for ORACLE.EXE (J002), OS id=16188, pid: 28, proc_ser: 4, sid: 225, sess_ser: 24591 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16188 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.377376 sec, exc=0.377376 sec, total=0.377376 sec wait times: max=0.500000 sec, heur=4.498923 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.000013 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499984 sec, exc=0.499984 sec, total=0.499984 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=7 seq_num=8 snap_id=1 wait times: snap=0.510114 sec, exc=0.510114 sec, total=0.510114 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=6 seq_num=7 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.000013 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.510094 sec, exc=0.510094 sec, total=0.510094 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500008 sec, exc=0.500008 sec, total=0.500008 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=2 seq_num=3 snap_id=1 wait times: snap=0.499990 sec, exc=0.499990 sec, total=0.499990 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=1 seq_num=2 snap_id=1 wait times: snap=0.509311 sec, exc=0.509311 sec, total=0.509311 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.091964 sec, exc=0.091964 sec, total=0.091964 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 225 serial 24591 --------------------------------------------------- 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:01 - 22:00:05] idle wait at each sample [session created at: 22:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-04 22:00:05.597 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 16188, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-04 11:00:05.088432 :A02A239D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.089004 :A02A23A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.089544 :A02A23AD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.089997 :A02A23B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.092500 :A02A23BD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.093653 :A02A23C5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.143138 :A02A23CD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.144049 :A02A23D5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.144303 :A02A23DD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.144521 :A02A23E5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 11:00:05.146198 :A02A23ED:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 11:01:03.871095 :A02A3825:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 11:01:03.863 2025-06-04 11:01:03.871097 :A02A3826:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=10856 pso_num=28 pso_serial#=251 2025-06-04 11:01:03.871303 :A02A3827:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=10856 osp_idx=26 osp_ver=175994 osp_pg=0 (spawn #250968) 2025-06-04 11:01:03.871304 :A02A3828:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-04 11:01:03.871304 :A02A3829:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=210 time=2010622516 2025-06-04 11:01:03.871305 :A02A382A:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-06-04 11:01:03.871306 :A02A382B:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-06-04 11:01:03.871306 :A02A382C:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-06-04 11:01:03.871306 :A02A382D:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-04 11:01:03.871307 :A02A382E:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-04 11:01:03.871897 :A02A382F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-04 11:01:03.871942 :A02A3835:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 11:01:03.879749 :A02A3847:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 11:16:05.886481 :A02B6429:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 11:16:05.874 2025-06-04 11:16:05.886482 :A02B642A:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=15128 pso_num=28 pso_serial#=252 2025-06-04 11:16:05.886618 :A02B642B:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=15128 osp_idx=26 osp_ver=175995 osp_pg=0 (spawn #251003) 2025-06-04 11:16:05.886619 :A02B642C:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-04 11:16:05.886619 :A02B642D:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=211 time=2011524532 2025-06-04 11:16:05.886619 :A02B642E:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-06-04 11:16:05.886620 :A02B642F:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-06-04 11:16:05.886620 :A02B6430:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-06-04 11:16:05.886621 :A02B6431:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-04 11:16:05.886621 :A02B6432:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-04 11:16:05.887143 :A02B6433:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-04 11:16:05.887186 :A02B6439:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 11:16:05.891181 :A02B6452:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-06-04 11:16:05.891230 :A02B6453:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-06-04 11:16:05.891485 :A02B6454:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-06-04 11:16:05.891500 :A02B6455:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-06-04 11:16:05.891716 :A02B6456:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-06-04 11:16:05.891729 :A02B6457:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-06-04 11:16:05.891932 :A02B6458:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-06-04 11:16:05.891944 :A02B6459:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-06-04 11:16:05.892148 :A02B645A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-06-04 11:16:05.892160 :A02B645B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-06-04 11:16:05.892365 :A02B645C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-06-04 11:16:05.892377 :A02B645D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-06-04 11:16:05.894689 :A02B645E:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 12:52:01.246037 :A032B418:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 12:52:01.246 2025-06-04 12:52:01.246039 :A032B419:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=16228 pso_num=28 pso_serial#=253 2025-06-04 12:52:01.246211 :A032B41D:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=16228 (legacy spawn) 2025-06-04 12:52:01.252896 :A032B41E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 12:52:01.253052 :A032B427:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 12:52:01.253852 :A032B428:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 13:00:18.579896 :A0335556:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 13:00:18.572 2025-06-04 13:00:18.579898 :A0335557:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=14952 pso_num=28 pso_serial#=254 2025-06-04 13:00:18.580037 :A0335558:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=14952 (legacy spawn) 2025-06-04 13:00:18.586491 :A0335559:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:18.586828 :A0335562:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 13:00:18.587650 :A0335563:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 13:00:19.208910 :A03355D7:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 13:00:19.197 2025-06-04 13:00:19.208911 :A03355D8:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=14368 pso_num=28 pso_serial#=255 2025-06-04 13:00:19.209053 :A03355D9:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=14368 osp_idx=26 osp_ver=175998 osp_pg=0 (spawn #251239) 2025-06-04 13:00:19.209054 :A03355DA:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-04 13:00:19.209054 :A03355DB:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=212 time=2017777844 2025-06-04 13:00:19.209055 :A03355DC:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-06-04 13:00:19.209055 :A03355DD:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-06-04 13:00:19.209056 :A03355DE:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-06-04 13:00:19.209056 :A03355DF:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-04 13:00:19.209056 :A03355E0:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-04 13:00:19.209557 :A03355E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.209607 :A03355E8:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 13:00:19.217563 :A03355F5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.218711 :A03355FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.219364 :A0335605:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.219846 :A033560D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.220289 :A0335615:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.222805 :A033561D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.224040 :A0335625:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.273399 :A033562D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.274299 :A0335635:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.274543 :A033563D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.274782 :A0335645:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 13:00:19.277102 :A033564D:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 16:00:06.767523 :A0412F1A:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 16:00:06.755 2025-06-04 16:00:06.767525 :A0412F1B:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=15984 pso_num=28 pso_serial#=1 2025-06-04 16:00:06.767662 :A0412F1C:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=15984 (legacy spawn) 2025-06-04 16:00:06.774205 :A0412F1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 16:00:06.774380 :A0412F22:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 16:00:06.775188 :A0412F27:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 16:00:28.707442 :A04135DB:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 16:00:28.694 2025-06-04 16:00:28.707445 :A04135DC:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=14880 pso_num=28 pso_serial#=2 2025-06-04 16:00:28.707594 :A04135DD:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=14880 (legacy spawn) 2025-06-04 16:00:28.714211 :A04135F1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 16:00:28.714385 :A04135FA:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 16:00:28.715182 :A04135FB:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 22:00:00.029428 :A05CB641:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 22:00:00.020 2025-06-04 22:00:00.029430 :A05CB642:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=16288 pso_num=28 pso_serial#=3 2025-06-04 22:00:00.029565 :A05CB643:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=16288 osp_idx=26 osp_ver=176001 osp_pg=0 (spawn #252486) 2025-06-04 22:00:00.029566 :A05CB644:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-04 22:00:00.029567 :A05CB645:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=213 time=2050158672 2025-06-04 22:00:00.029567 :A05CB646:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-06-04 22:00:00.029567 :A05CB647:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-06-04 22:00:00.029568 :A05CB648:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-06-04 22:00:00.029568 :A05CB649:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-04 22:00:00.029568 :A05CB64A:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-04 22:00:00.030076 :A05CB64B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.030122 :A05CB652:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:00.030200 :A05CB666:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.034146 :A05CB675:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.035414 :A05CB67D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.035438 :A05CB680:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.035476 :A05CB68B:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:00.037296 :A05CB696:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.037323 :A05CB699:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.037360 :A05CB6A4:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:00.037824 :A05CB6AF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.040401 :A05CB6B7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.045682 :A05CB6BF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.051223 :A05CB6C7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.052646 :A05CB6CF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.055630 :A05CB6D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.057209 :A05CB6DF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.058114 :A05CB6E7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.060700 :A05CB6EF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.064126 :A05CB6F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.064476 :A05CB706:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.064519 :A05CB709:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:ktcc.c:879 2025-06-04 22:00:00.064532 :A05CB70A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:ktcc.c:879 2025-06-04 22:00:00.066466 :A05CB710:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.066507 :A05CB713:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:ktcc.c:879 2025-06-04 22:00:00.066518 :A05CB714:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:ktcc.c:879 2025-06-04 22:00:00.068572 :A05CB71A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.068615 :A05CB71D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:ktcc.c:879 2025-06-04 22:00:00.068625 :A05CB71E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:ktcc.c:879 2025-06-04 22:00:00.068788 :A05CB724:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.068802 :A05CB727:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-04 22:00:00.068839 :A05CB732:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:00.070383 :A05CB73D:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-06-04 22:00:01.072959 :A05CB7BE:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 06-04 22:00:01.067 2025-06-04 22:00:01.072961 :A05CB7BF:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=16188 pso_num=28 pso_serial#=4 2025-06-04 22:00:01.073179 :A05CB7C0:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=16188 osp_idx=26 osp_ver=176002 osp_pg=0 (spawn #252487) 2025-06-04 22:00:01.073180 :A05CB7C1:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-04 22:00:01.073181 :A05CB7C2:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=214 time=2050159719 2025-06-04 22:00:01.073181 :A05CB7C3:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-06-04 22:00:01.073182 :A05CB7C4:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-06-04 22:00:01.073182 :A05CB7C5:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-06-04 22:00:01.073183 :A05CB7C6:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-04 22:00:01.073183 :A05CB7C7:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-04 22:00:01.073860 :A05CB7D5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.079815 :A05CB807:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.079879 :A05CB80A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-06-04 22:00:01.085040 :A05CB82B:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-04 22:00:01.085627 :A05CB848:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 ddf3110000000000 2025-06-04 22:00:01.087360 :A05CB85E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.087429 :A05CB86B:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.087439 :A05CB872:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-06-04 22:00:01.087445 :A05CB873:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.087480 :A05CB87D:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.088186 :A05CB88B:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 227396245) 2025-06-04 22:00:01.088190 :A05CB88C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.088211 :A05CB89A:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.088220 :A05CB8A4:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65564 1) 2025-06-04 22:00:01.088223 :A05CB8A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.088250 :A05CB8B1:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.088253 :A05CB8BB:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65564) 2025-06-04 22:00:01.088256 :A05CB8BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.088315 :A05CB8DF:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.088977 :A05CB96E:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.089002 :A05CB97C:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-04 22:00:01.089905 :A05CB983:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 def3110000000000 2025-06-04 22:00:01.090278 :A05CB984:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 227396245) 2025-06-04 22:00:01.090284 :A05CB985:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.090310 :A05CB994:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.098580 :A05CB9EC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-06-04 22:00:01.099905 :A05CB9F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.099946 :A05CB9FF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-06-04 22:00:01.100050 :A05CBA12:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-04 22:00:01.192734 :A05CBABB:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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 28 (osid: 16188, J002)