Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510220153\orcl_j002_7548_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:37492M/63366M, Ph+PgF:44864M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 7548, image: ORACLE.EXE (J002) *** 2025-05-10 22:01:53.791 *** SESSION ID:(225.7025) 2025-05-10 22:01:53.791 *** 2025-05-10 22:01:53.791 Process diagnostic dump for ORACLE.EXE (J002), OS id=7548, pid: 28, proc_ser: 207, sid: 225, sess_ser: 7025 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 7548 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.191243 sec, exc=0.191243 sec, total=0.191243 sec wait times: max=0.500000 sec, heur=6.197730 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.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 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.000011 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.499991 sec, exc=0.499991 sec, total=0.499991 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.500000 sec, exc=0.500000 sec, total=0.500000 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.500135 sec, exc=0.500135 sec, total=0.500135 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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.000008 sec of elapsed time 5: 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.000008 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499989 sec, exc=0.499989 sec, total=0.499989 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000015 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.512434 sec, exc=0.512434 sec, total=0.512434 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500004 sec, exc=0.500004 sec, total=0.500004 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.500126 sec, exc=0.500126 sec, total=0.500126 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time Sampled Session History of session 225 serial 7025 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 22:01:47 - 22:01:53] idle wait at each sample [session created at: 22:01:47] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 22:01:53.791 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 7548, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 21:59:10.339946 :95637C57:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=11624 pso_num=28 pso_serial#=187 2025-05-10 21:59:10.340080 :95637C58:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=11624 (legacy spawn) 2025-05-10 21:59:10.346507 :95637C59: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-05-10 21:59:10.346705 :95637C62: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-05-10 21:59:10.347487 :95637C63:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 21:59:10.356123 :95637C66:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 21:59:10.343 2025-05-10 21:59:10.356125 :95637C67:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13016 pso_num=28 pso_serial#=188 2025-05-10 21:59:10.356263 :95637C68:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=13016 (legacy spawn) 2025-05-10 21:59:10.362730 :95637C69: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-05-10 21:59:10.362900 :95637C72: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-05-10 21:59:10.363690 :95637C73:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 21:59:46.822180 :9563881D:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 21:59:46.809 2025-05-10 21:59:46.822182 :9563881E:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13048 pso_num=28 pso_serial#=189 2025-05-10 21:59:46.822359 :9563881F:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=13048 (legacy spawn) 2025-05-10 21:59:46.828762 :95638820: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-05-10 21:59:46.828936 :95638825: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-05-10 21:59:46.829761 :9563882A:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 21:59:46.838258 :9563882D:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 21:59:46.825 2025-05-10 21:59:46.838260 :9563882E:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=11172 pso_num=28 pso_serial#=190 2025-05-10 21:59:46.838397 :9563882F:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=11172 (legacy spawn) 2025-05-10 21:59:46.844811 :95638830: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-05-10 21:59:46.844985 :95638839: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-05-10 21:59:46.845782 :9563883A:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 21:59:54.738268 :95638B75:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 21:59:54.730 2025-05-10 21:59:54.738271 :95638B76:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=8620 pso_num=28 pso_serial#=191 2025-05-10 21:59:54.738401 :95638B77:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=8620 (legacy spawn) 2025-05-10 21:59:54.744848 :95638B78: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-05-10 21:59:54.745016 :95638B81: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-05-10 21:59:54.745849 :95638B82:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:02.952212 :95638DE6:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:02.943 2025-05-10 22:00:02.952214 :95638DE7:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=12936 pso_num=28 pso_serial#=192 2025-05-10 22:00:02.952350 :95638DE8:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=12936 (legacy spawn) 2025-05-10 22:00:02.958829 :95638DE9: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-05-10 22:00:02.959001 :95638DEE: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-05-10 22:00:02.959799 :95638DF3:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:19.929938 :9563932E:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:19.926 2025-05-10 22:00:19.929941 :9563932F:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=7212 pso_num=28 pso_serial#=193 2025-05-10 22:00:19.930082 :95639330:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=7212 (legacy spawn) 2025-05-10 22:00:19.936549 :95639331: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-05-10 22:00:19.936727 :95639336: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-05-10 22:00:19.937540 :9563933B:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:19.946040 :9563933E:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:19.942 2025-05-10 22:00:19.946042 :9563933F:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=4696 pso_num=28 pso_serial#=194 2025-05-10 22:00:19.946186 :95639340:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=4696 (legacy spawn) 2025-05-10 22:00:19.952661 :95639341: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-05-10 22:00:19.952823 :9563934A: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-05-10 22:00:19.953641 :9563934B:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:23.121218 :95639433:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:23.108 2025-05-10 22:00:23.121220 :95639434:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=12356 pso_num=28 pso_serial#=195 2025-05-10 22:00:23.121358 :95639435:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=12356 (legacy spawn) 2025-05-10 22:00:23.127766 :95639436: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-05-10 22:00:23.127935 :9563943B: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-05-10 22:00:23.128715 :95639440:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:23.146925 :95639443:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:23.140 2025-05-10 22:00:23.146926 :95639444:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=2936 pso_num=28 pso_serial#=196 2025-05-10 22:00:23.147061 :95639445:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=2936 (legacy spawn) 2025-05-10 22:00:23.153581 :95639446: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-05-10 22:00:23.153754 :9563944B: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-05-10 22:00:23.154570 :95639450:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:25.855133 :9563953E:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:25.847 2025-05-10 22:00:25.855135 :9563953F:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=12688 pso_num=28 pso_serial#=197 2025-05-10 22:00:25.855269 :95639540:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=12688 (legacy spawn) 2025-05-10 22:00:25.861701 :95639541: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-05-10 22:00:25.861877 :95639546: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-05-10 22:00:25.862726 :9563954B:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:47.245415 :95639D32:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:47.239 2025-05-10 22:00:47.245418 :95639D33:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13148 pso_num=28 pso_serial#=198 2025-05-10 22:00:47.245551 :95639D34:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=13148 osp_idx=26 osp_ver=101687 osp_pg=0 (spawn #169069) 2025-05-10 22:00:47.245552 :95639D35:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 22:00:47.245552 :95639D36:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=36 time=4185224406 2025-05-10 22:00:47.245553 :95639D37:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 22:00:47.245553 :95639D38:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 22:00:47.245554 :95639D39:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 22:00:47.245554 :95639D3A:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 22:00:47.245555 :95639D3B:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 22:00:47.246043 :95639D3C: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-05-10 22:00:47.246092 :95639D42: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-05-10 22:00:47.250568 :95639D55: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-05-10 22:00:47.276875 :95639D5D:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 4286481055 8486241) 2025-05-10 22:00:47.276883 :95639D5E: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-05-10 22:00:47.276926 :95639D66: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-05-10 22:00:47.276976 :95639D76: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-05-10 22:00:47.291406 :95639D7E: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-05-10 22:00:47.316453 :95639D86: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-05-10 22:00:47.320213 :95639D8E: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-05-10 22:00:47.323886 :95639D96: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-05-10 22:00:47.326974 :95639D9E: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-05-10 22:00:47.326988 :95639D9F:db_trace:ktur.c@3079:ktuabt(): [10444:28:225] ABORT TRANSACTION - xid: 0x000a.006.00168630 2025-05-10 22:00:47.327442 :95639DA7:db_trace:ktu.c@4871:ktuaex1r(): [10442:28:225] Extension usn 10, ext 1, nex 3 2025-05-10 22:00:47.327448 :95639DA8:db_trace:ktusm.c@2117:ktusmasp(): [10445:28:225] des1:tsn:1 rdba:0x00817bd3 where: ktspbwh1: ktspfsrch 2025-05-10 22:00:47.328729 :95639DA9: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-05-10 22:00:47.329871 :95639DB1: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-05-10 22:00:48.583452 :95639E65: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-05-10 22:00:48.610159 :95639E6D: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-05-10 22:00:48.610478 :95639E75: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-05-10 22:00:48.610752 :95639E7D: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-05-10 22:00:48.610767 :95639E80:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 22:00:48.610831 :95639E8C: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-05-10 22:00:48.614493 :95639E9A:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:56.329022 :9563A12D:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:56.314 2025-05-10 22:00:56.329024 :9563A12E:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=8172 pso_num=28 pso_serial#=199 2025-05-10 22:00:56.329164 :9563A12F:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=8172 (legacy spawn) 2025-05-10 22:00:56.335629 :9563A130: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-05-10 22:00:56.335802 :9563A135: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-05-10 22:00:56.336582 :9563A13A:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:56.345162 :9563A13D:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:56.345 2025-05-10 22:00:56.345164 :9563A13E:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=11808 pso_num=28 pso_serial#=200 2025-05-10 22:00:56.345296 :9563A13F:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=11808 (legacy spawn) 2025-05-10 22:00:56.351783 :9563A140: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-05-10 22:00:56.351939 :9563A149: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-05-10 22:00:56.352745 :9563A14A:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:56.947251 :9563A1B6:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:56.939 2025-05-10 22:00:56.947252 :9563A1B7:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=9804 pso_num=28 pso_serial#=201 2025-05-10 22:00:56.947395 :9563A1B8:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=9804 (legacy spawn) 2025-05-10 22:00:56.974482 :9563A1B9: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-05-10 22:00:56.974657 :9563A1C2: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-05-10 22:00:56.975468 :9563A1C3:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:59.524755 :9563A249:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:59.511 2025-05-10 22:00:59.524757 :9563A24A:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=12544 pso_num=28 pso_serial#=202 2025-05-10 22:00:59.524894 :9563A24B:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=12544 (legacy spawn) 2025-05-10 22:00:59.531343 :9563A24C: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-05-10 22:00:59.531517 :9563A251: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-05-10 22:00:59.532306 :9563A256:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:00:59.540924 :9563A259:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:00:59.527 2025-05-10 22:00:59.540926 :9563A25A:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=12684 pso_num=28 pso_serial#=203 2025-05-10 22:00:59.541063 :9563A25B:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=12684 (legacy spawn) 2025-05-10 22:00:59.547479 :9563A25C: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-05-10 22:00:59.547642 :9563A265: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-05-10 22:00:59.548447 :9563A266:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:01:11.165446 :9563A5E3:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:01:11.152 2025-05-10 22:01:11.165448 :9563A5E4:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=9808 pso_num=28 pso_serial#=204 2025-05-10 22:01:11.165592 :9563A5E5:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=9808 (legacy spawn) 2025-05-10 22:01:11.172009 :9563A5E6: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-05-10 22:01:11.172195 :9563A5EB: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-05-10 22:01:11.173006 :9563A5F0:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:01:45.354725 :9563B0EA:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:01:45.346 2025-05-10 22:01:45.354726 :9563B0EB:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=12676 pso_num=28 pso_serial#=205 2025-05-10 22:01:45.354864 :9563B0EC:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=12676 (legacy spawn) 2025-05-10 22:01:45.361361 :9563B0ED: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-05-10 22:01:45.361522 :9563B0F3: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-05-10 22:01:45.362344 :9563B0F7:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:01:47.392600 :9563B17B:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:01:47.387 2025-05-10 22:01:47.392602 :9563B17C:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=6600 pso_num=28 pso_serial#=206 2025-05-10 22:01:47.392735 :9563B17D:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=6600 osp_idx=26 osp_ver=101695 osp_pg=0 (spawn #169073) 2025-05-10 22:01:47.392735 :9563B17E:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 22:01:47.392736 :9563B17F:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=37 time=4185284562 2025-05-10 22:01:47.392736 :9563B180:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 22:01:47.392736 :9563B181:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 22:01:47.392736 :9563B182:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 22:01:47.392737 :9563B183:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 22:01:47.392737 :9563B184:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 22:01:47.393296 :9563B185: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-05-10 22:01:47.393338 :9563B18B: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-05-10 22:01:47.397420 :9563B1A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-10 22:01:47.397463 :9563B1A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-10 22:01:47.397731 :9563B1A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-10 22:01:47.397750 :9563B1A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-10 22:01:47.397983 :9563B1A6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-10 22:01:47.397998 :9563B1A7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-10 22:01:47.398209 :9563B1A8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-10 22:01:47.398223 :9563B1A9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-10 22:01:47.398436 :9563B1AA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-10 22:01:47.398449 :9563B1AB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-10 22:01:47.398657 :9563B1AC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-10 22:01:47.398673 :9563B1AD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-10 22:01:47.401095 :9563B1D2:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-10 22:01:47.595704 :9563B614:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-10 22:01:47.591 2025-05-10 22:01:47.595705 :9563B615:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=7548 pso_num=28 pso_serial#=207 2025-05-10 22:01:47.595840 :9563B618:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=7548 osp_idx=26 osp_ver=101696 osp_pg=0 (spawn #169076) 2025-05-10 22:01:47.595841 :9563B619:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 22:01:47.595842 :9563B61A:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=38 time=4185284765 2025-05-10 22:01:47.595842 :9563B61B:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 22:01:47.595843 :9563B61C:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 22:01:47.595843 :9563B61D:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 22:01:47.595844 :9563B61E:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 22:01:47.595844 :9563B61F:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 22:01:47.596342 :9563B629: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 28 (osid: 7548, J002)