Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250521220826\orcl_j001_12404_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:37359M/63366M, Ph+PgF:44465M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 12404, image: ORACLE.EXE (J001) *** 2025-05-21 22:08:26.583 *** SESSION ID:(201.48631) 2025-05-21 22:08:26.583 *** 2025-05-21 22:08:26.583 Process diagnostic dump for ORACLE.EXE (J001), OS id=12404, pid: 25, proc_ser: 37, sid: 201, sess_ser: 48631 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12404 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=56 seq_num=57 snap_id=1 wait times: snap=0.473549 sec, exc=0.473549 sec, total=0.473549 sec wait times: max=0.500000 sec, heur=28.569411 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000011 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=55 seq_num=56 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=54 seq_num=55 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.000011 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=53 seq_num=54 snap_id=1 wait times: snap=0.512340 sec, exc=0.512340 sec, total=0.512340 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=52 seq_num=53 snap_id=1 wait times: snap=0.499995 sec, exc=0.499995 sec, total=0.499995 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=51 seq_num=52 snap_id=1 wait times: snap=0.503185 sec, exc=0.503185 sec, total=0.503185 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=50 seq_num=51 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=49 seq_num=50 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.000011 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=48 seq_num=49 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 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=47 seq_num=48 snap_id=1 wait times: snap=0.500213 sec, exc=0.500213 sec, total=0.500213 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=46 seq_num=47 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time Sampled Session History of session 201 serial 48631 --------------------------------------------------- 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 --------------------------------------------------- [29 samples, 22:07:58 - 22:08:26] idle wait at each sample [session created at: 22:07:58] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-21 22:08:26.583 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 12404, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-21 22:00:03.158566*:9A3BB71B:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003F05A188 curCtx=0x000000003EF53C90 pubTabIdxCnt=0 2025-05-21 22:00:03.158566*:9A3BB71C:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003F05A188 2025-05-21 22:00:03.158566*:9A3BB71D:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003F05A188 2025-05-21 22:00:03.158566*:9A3BB71E:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DDC288 estart=1747836001 eid=16777274 ctx=0x000000079F654AA8 cwh=0x0000000024DD0158 cpu=0 buffg=78703 interb=18694144 r=864 rb=16400384 w=12 wb=2293760 2025-05-21 22:00:03.158566*:9A3BB71F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DDC288 curCtx=0x000000003EF52DB8 pubTabIdxCnt=0 2025-05-21 22:00:03.158566*:9A3BB720:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DDC288 2025-05-21 22:00:03.158566*:9A3BB721:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DDC288 2025-05-21 22:00:03.158566*:9A3BB722:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003F05A188 curCtx=0x000000003EF53C90 xsc->flg4=65792 flags=0 2025-05-21 22:00:03.158566*:9A3BB723:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003F05A188 2025-05-21 22:00:03.165884 :9A3BB724:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.180747 :9A3BB72C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.195261 :9A3BB734:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.209853 :9A3BB73C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.218839 :9A3BB744:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.228754 :9A3BB74C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.238375 :9A3BB754:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.248080 :9A3BB75C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.260896 :9A3BB764:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.275909 :9A3BB76C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.283215 :9A3BB774:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.290464 :9A3BB77C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.297733 :9A3BB784:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.305270 :9A3BB78C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.312608 :9A3BB794:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.320143 :9A3BB79C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.328047 :9A3BB7A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.335557 :9A3BB7AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:03.342979 :9A3BB7B4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.431879 :9A3BBBA6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.436881 :9A3BBBAE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.437127 :9A3BBBB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.444773 :9A3BBBBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.452110 :9A3BBBC6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.460667 :9A3BBBCE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.461003 :9A3BBBD6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.461003*:9A3BBBDA:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DDC288 curCtx=0x000000003EF52DB8 xsc->flg4=65792 flags=2 2025-05-21 22:00:04.461003*:9A3BBBDF:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DDC288 2025-05-21 22:00:04.461269 :9A3BBBE0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-21 22:00:04.465809 :9A3BBBE1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.465889 :9A3BBBE4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-21 22:00:04.465983 :9A3BBBF1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-21 22:00:34.541105 :9A3BC7C1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:00:41.781642 :9A3BCA80:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:00:41.779 2025-05-21 22:00:41.781644 :9A3BCA81:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12916 pso_num=25 pso_serial#=28 2025-05-21 22:00:41.781778 :9A3BCA82:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12916 osp_idx=23 osp_ver=109932 osp_pg=0 (spawn #205846) 2025-05-21 22:00:41.781778 :9A3BCA83:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:00:41.781779 :9A3BCA84:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=152 time=840651641 2025-05-21 22:00:41.781779 :9A3BCA85:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:00:41.781779 :9A3BCA86:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:00:41.781780 :9A3BCA87:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:00:41.781780 :9A3BCA88:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:00:41.781781 :9A3BCA89:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:00:41.782275 :9A3BCA8A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.782329 :9A3BCA90:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-21 22:00:41.789845 :9A3BCA9E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.790905 :9A3BCAA6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.791439 :9A3BCAAE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.791894 :9A3BCAB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.792330 :9A3BCABE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.794811 :9A3BCAC6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.795914 :9A3BCACE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.851969 :9A3BCAD6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.852850 :9A3BCADE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.853084 :9A3BCAE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.853301 :9A3BCAEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-21 22:00:41.855065 :9A3BCAF6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:00:57.324079 :9A3BCFFD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:00:57.313 2025-05-21 22:00:57.324081 :9A3BCFFE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10376 pso_num=25 pso_serial#=29 2025-05-21 22:00:57.324216 :9A3BCFFF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10376 osp_idx=23 osp_ver=109933 osp_pg=0 (spawn #205849) 2025-05-21 22:00:57.324217 :9A3BD000:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:00:57.324217 :9A3BD001:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=153 time=840667188 2025-05-21 22:00:57.324218 :9A3BD002:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:00:57.324218 :9A3BD003:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:00:57.324219 :9A3BD004:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:00:57.324219 :9A3BD005:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:00:57.324219 :9A3BD006:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:00:57.324732 :9A3BD00F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:01:27.433473 :9A3BDA41:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:01:40.563507 :9A3BDEC3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:01:40.551 2025-05-21 22:01:40.563509 :9A3BDEC4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12448 pso_num=25 pso_serial#=30 2025-05-21 22:01:40.563679 :9A3BDEC5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12448 osp_idx=23 osp_ver=109934 osp_pg=0 (spawn #205851) 2025-05-21 22:01:40.563679 :9A3BDEC6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:01:40.563680 :9A3BDEC7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=154 time=840710422 2025-05-21 22:01:40.563680 :9A3BDEC8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:01:40.563680 :9A3BDEC9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:01:40.563681 :9A3BDECA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:01:40.563681 :9A3BDECB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:01:40.563681 :9A3BDECC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:01:40.564191 :9A3BDECD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:01:40.564230 :9A3BDED3:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-21 22:01:40.568300 :9A3BDEF3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-21 22:01:40.568344 :9A3BDEF4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-21 22:01:40.568612 :9A3BDEF5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-21 22:01:40.568632 :9A3BDEF6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-21 22:01:40.568855 :9A3BDEF7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-21 22:01:40.568870 :9A3BDEF8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-21 22:01:40.569079 :9A3BDEF9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-21 22:01:40.569092 :9A3BDEFA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-21 22:01:40.569302 :9A3BDEFB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-21 22:01:40.569318 :9A3BDEFC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-21 22:01:40.569523 :9A3BDEFD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-21 22:01:40.569536 :9A3BDEFE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-21 22:01:40.571827 :9A3BDF21:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:01:57.418291 :9A3BE4A9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:01:57.407 2025-05-21 22:01:57.418293 :9A3BE4AA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12192 pso_num=25 pso_serial#=31 2025-05-21 22:01:57.418433 :9A3BE4AB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12192 osp_idx=23 osp_ver=109935 osp_pg=0 (spawn #205854) 2025-05-21 22:01:57.418434 :9A3BE4AC:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:01:57.418434 :9A3BE4AD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=155 time=840727282 2025-05-21 22:01:57.418434 :9A3BE4AE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:01:57.418435 :9A3BE4AF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:01:57.418435 :9A3BE4B0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:01:57.418436 :9A3BE4B1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:01:57.418436 :9A3BE4B2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:01:57.418938 :9A3BE4B3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:02:27.510470 :9A3BEE41:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:02:57.520967 :9A3BF7F6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:02:57.509 2025-05-21 22:02:57.520969 :9A3BF7F7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14016 pso_num=25 pso_serial#=32 2025-05-21 22:02:57.521097 :9A3BF7F8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14016 osp_idx=23 osp_ver=109936 osp_pg=0 (spawn #205856) 2025-05-21 22:02:57.521098 :9A3BF7F9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:02:57.521098 :9A3BF7FA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=156 time=840787391 2025-05-21 22:02:57.521099 :9A3BF7FB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:02:57.521099 :9A3BF7FC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:02:57.521100 :9A3BF7FD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:02:57.521100 :9A3BF7FE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:02:57.521101 :9A3BF7FF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:02:57.521571 :9A3BF800:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:03:27.617148 :9A3C01BB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:03:57.649506 :9A3C0AF8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:03:57.638 2025-05-21 22:03:57.649507 :9A3C0AF9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11340 pso_num=25 pso_serial#=33 2025-05-21 22:03:57.649640 :9A3C0AFA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11340 osp_idx=23 osp_ver=109937 osp_pg=0 (spawn #205858) 2025-05-21 22:03:57.649640 :9A3C0AFB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:03:57.649641 :9A3C0AFC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=157 time=840847516 2025-05-21 22:03:57.649641 :9A3C0AFD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:03:57.649642 :9A3C0AFE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:03:57.649642 :9A3C0AFF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:03:57.649642 :9A3C0B00:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:03:57.649642 :9A3C0B01:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:03:57.650208 :9A3C0B02:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:04:27.738951 :9A3C14AA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:04:57.745334 :9A3C1E8B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:04:57.734 2025-05-21 22:04:57.745336 :9A3C1E8C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=1880 pso_num=25 pso_serial#=34 2025-05-21 22:04:57.745463 :9A3C1E8D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=1880 osp_idx=23 osp_ver=109938 osp_pg=0 (spawn #205860) 2025-05-21 22:04:57.745463 :9A3C1E8E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:04:57.745464 :9A3C1E8F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=158 time=840907610 2025-05-21 22:04:57.745464 :9A3C1E90:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:04:57.745465 :9A3C1E91:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:04:57.745465 :9A3C1E92:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:04:57.745465 :9A3C1E93:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:04:57.745466 :9A3C1E94:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:04:57.745955 :9A3C1E95:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:05:27.851698 :9A3C2C06:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:05:52.826714 :9A3C393A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:05:52.815 2025-05-21 22:05:52.826716 :9A3C393B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4856 pso_num=25 pso_serial#=35 2025-05-21 22:05:52.826852 :9A3C393C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4856 osp_idx=23 osp_ver=109939 osp_pg=0 (spawn #205862) 2025-05-21 22:05:52.826853 :9A3C393D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:05:52.826853 :9A3C393E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=159 time=840962688 2025-05-21 22:05:52.826853 :9A3C393F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:05:52.826854 :9A3C3940:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:05:52.826854 :9A3C3941:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:05:52.826854 :9A3C3942:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:05:52.826855 :9A3C3943:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:05:52.827336 :9A3C3944:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:05:57.822392 :9A3C3B09:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-21 22:06:27.905315 :9A3C45FA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:06:57.913634 :9A3C4FCB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:06:57.902 2025-05-21 22:06:57.913636 :9A3C4FCC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14296 pso_num=25 pso_serial#=36 2025-05-21 22:06:57.913770 :9A3C4FCD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14296 osp_idx=23 osp_ver=109940 osp_pg=0 (spawn #205864) 2025-05-21 22:06:57.913771 :9A3C4FCE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:06:57.913772 :9A3C4FCF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=160 time=841027782 2025-05-21 22:06:57.913772 :9A3C4FD0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:06:57.913773 :9A3C4FD1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:06:57.913773 :9A3C4FD2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:06:57.913773 :9A3C4FD3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:06:57.913774 :9A3C4FD4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:06:57.914253 :9A3C4FD5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-21 22:07:27.978233 :9A3C5A75:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-21 22:07:58.018172 :9A3C6469:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-21 22:07:58.006 2025-05-21 22:07:58.018175 :9A3C646A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12404 pso_num=25 pso_serial#=37 2025-05-21 22:07:58.018302 :9A3C646B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12404 osp_idx=23 osp_ver=109941 osp_pg=0 (spawn #205866) 2025-05-21 22:07:58.018303 :9A3C646C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-21 22:07:58.018304 :9A3C646D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=161 time=841087875 2025-05-21 22:07:58.018304 :9A3C646E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 22:07:58.018304 :9A3C646F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 22:07:58.018305 :9A3C6470:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 22:07:58.018305 :9A3C6471:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 22:07:58.018306 :9A3C6472:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 22:07:58.018783 :9A3C6473:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 12404, J001)