Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250503060008\orcl_j004_8880_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:37580M/63366M, Ph+PgF:45086M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 30 Windows thread id: 8880, image: ORACLE.EXE (J004) *** 2025-05-03 06:00:08.957 *** SESSION ID:(241.1293) 2025-05-03 06:00:08.957 *** 2025-05-03 06:00:08.957 Process diagnostic dump for ORACLE.EXE (J004), OS id=8880, pid: 30, proc_ser: 125, sid: 241, sess_ser: 1293 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 8880 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J004) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.138860 sec, exc=0.138860 sec, total=0.138860 sec wait times: max=0.500000 sec, heur=5.145233 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=9 seq_num=10 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.000013 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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.000010 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499987 sec, exc=0.499987 sec, total=0.499987 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 3: 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.000009 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.510155 sec, exc=0.510155 sec, total=0.510155 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 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.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 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 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 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.000013 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.500007 sec, exc=0.500007 sec, total=0.500007 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.496145 sec, exc=0.496145 sec, total=0.496145 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 241 serial 1293 --------------------------------------------------- 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 --------------------------------------------------- [6 samples, 06:00:03 - 06:00:08] idle wait at each sample [session created at: 06:00:03] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-03 06:00:08.957 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 30 (osid: 8880, J004) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-02 22:00:02.536397 :91D83C38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:02.543635 :91D83C40:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:02.988451*:91D83CF2:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000031686918 estart=1746194401 eid=16777295 ctx=0x00000007831EA738 cwh=0x00000000316B0248 cpu=31250 buffg=45 interb=1040384 r=1 rb=1040384 w=0 wb=0 2025-05-02 22:00:02.988451*:91D83CF3:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000031686918 curCtx=0x000000003918EDB8 pubTabIdxCnt=0 2025-05-02 22:00:02.988451*:91D83CF4:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000031686918 2025-05-02 22:00:02.988451*:91D83CF5:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000031686918 2025-05-02 22:00:02.988451*:91D83CF6:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB7C288 estart=1746194400 eid=16777255 ctx=0x000000079F654AA8 cwh=0x000000002DB70158 cpu=1625000 buffg=144982 interb=32104448 r=1440 rb=27516928 w=24 wb=4587520 2025-05-02 22:00:02.988451*:91D83CF7:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB7C288 curCtx=0x0000000031688510 pubTabIdxCnt=0 2025-05-02 22:00:02.988451*:91D83CF8:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB7C288 2025-05-02 22:00:02.988451*:91D83CF9:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB7C288 2025-05-02 22:00:03.082669*:91D83D87:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000031686918 curCtx=0x000000003918EDB8 xsc->flg4=65792 flags=1 2025-05-02 22:00:03.082669*:91D83D88:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000031686918 2025-05-02 22:00:03.630735 :91D83E54:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.633014 :91D83E5C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.633326 :91D83E64:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.640913 :91D83E6C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.648408 :91D83E74:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.656877 :91D83E7C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.657213 :91D83E84:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.657213*:91D83E87:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB7C288 curCtx=0x0000000031688510 xsc->flg4=65792 flags=2 2025-05-02 22:00:03.657213*:91D83E88:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB7C288 2025-05-02 22:00:03.657469 :91D83E8E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:jslv.c:9203 2025-05-02 22:00:03.659076 :91D83E8F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.662217 :91D83E97:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.662307 :91D83E9A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-02 22:00:03.662397 :91D83EA7:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] 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-02 22:00:33.807950 :91D84B4A:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-02 22:19:03.049572 :91D9D79E:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-02 22:19:03.048 2025-05-02 22:19:03.049573 :91D9D79F:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=12108 pso_num=30 pso_serial#=117 2025-05-02 22:19:03.050709 :91D9D7A0:db_trace:kso.c@4093:ksonfy(): [10420:30:0] kso: new process: pid=12108 osp_idx=28 osp_ver=626 osp_pg=0 (spawn #141982) 2025-05-02 22:19:03.050710 :91D9D7A1:db_trace:kso.c@4099:ksonfy(): [10420:30:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 22:19:03.050710 :91D9D7A2:db_trace:kso.c@4103:ksonfy(): [10420:30:0] kso: new process: pso_index=30 reservation=29 time=3495132500 2025-05-02 22:19:03.050711 :91D9D7A3:db_trace:kso.c@4109:ksonfy(): [10420:30:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 22:19:03.050711 :91D9D7A4:db_trace:kso.c@4111:ksonfy(): [10420:30:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 22:19:03.050711 :91D9D7A5:db_trace:kso.c@4113:ksonfy(): [10420:30:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 22:19:03.050712 :91D9D7A6:db_trace:kso.c@4115:ksonfy(): [10420:30:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 22:19:03.050712 :91D9D7A7:db_trace:kso.c@4117:ksonfy(): [10420:30:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 22:19:03.051798 :91D9D7A8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 22:19:03.051848 :91D9D7AE:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] 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-02 22:19:03.052271 :91D9D7AF:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-02 22:19:04.265191 :91D9D868:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-02 22:19:04.264 2025-05-02 22:19:04.265192 :91D9D869:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=10396 pso_num=30 pso_serial#=118 2025-05-02 22:19:04.265337 :91D9D86A:db_trace:kso.c@4093:ksonfy(): [10420:30:0] kso: new process: pid=10396 osp_idx=28 osp_ver=627 osp_pg=0 (spawn #141984) 2025-05-02 22:19:04.265337 :91D9D86B:db_trace:kso.c@4099:ksonfy(): [10420:30:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 22:19:04.265338 :91D9D86C:db_trace:kso.c@4103:ksonfy(): [10420:30:0] kso: new process: pso_index=30 reservation=30 time=3495133734 2025-05-02 22:19:04.265339 :91D9D86D:db_trace:kso.c@4109:ksonfy(): [10420:30:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 22:19:04.265339 :91D9D86E:db_trace:kso.c@4111:ksonfy(): [10420:30:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 22:19:04.265339 :91D9D86F:db_trace:kso.c@4113:ksonfy(): [10420:30:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 22:19:04.265340 :91D9D870:db_trace:kso.c@4115:ksonfy(): [10420:30:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 22:19:04.265341 :91D9D871:db_trace:kso.c@4117:ksonfy(): [10420:30:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 22:19:04.265909 :91D9D872:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 22:19:04.265950 :91D9D878:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] 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-02 22:19:04.266357 :91D9D879:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-02 22:19:05.696357 :91D9DDD0:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-02 22:19:05.702 2025-05-02 22:19:05.696359 :91D9DDD1:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=9764 pso_num=30 pso_serial#=119 2025-05-02 22:19:05.696501 :91D9DDD2:db_trace:kso.c@4093:ksonfy(): [10420:30:0] kso: new process: pid=9764 osp_idx=28 osp_ver=628 osp_pg=0 (spawn #141986) 2025-05-02 22:19:05.696502 :91D9DDD3:db_trace:kso.c@4099:ksonfy(): [10420:30:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 22:19:05.696502 :91D9DDD4:db_trace:kso.c@4103:ksonfy(): [10420:30:0] kso: new process: pso_index=30 reservation=31 time=3495135171 2025-05-02 22:19:05.696503 :91D9DDD5:db_trace:kso.c@4109:ksonfy(): [10420:30:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 22:19:05.696503 :91D9DDD6:db_trace:kso.c@4111:ksonfy(): [10420:30:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 22:19:05.696504 :91D9DDD7:db_trace:kso.c@4113:ksonfy(): [10420:30:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 22:19:05.696504 :91D9DDD8:db_trace:kso.c@4115:ksonfy(): [10420:30:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 22:19:05.696505 :91D9DDD9:db_trace:kso.c@4117:ksonfy(): [10420:30:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 22:19:05.697049 :91D9DDDA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 22:19:05.697089 :91D9DDE1:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] 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-02 22:19:05.703497 :91D9DDEE:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-02 23:59:07.003438 :91E20739:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-02 23:59:06.992 2025-05-02 23:59:07.003440 :91E2073A:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=10288 pso_num=30 pso_serial#=120 2025-05-02 23:59:07.003572 :91E2073B:db_trace:kso.c@4093:ksonfy(): [10420:30:0] kso: new process: pid=10288 osp_idx=28 osp_ver=629 osp_pg=0 (spawn #142217) 2025-05-02 23:59:07.003573 :91E2073C:db_trace:kso.c@4099:ksonfy(): [10420:30:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 23:59:07.003573 :91E2073D:db_trace:kso.c@4103:ksonfy(): [10420:30:0] kso: new process: pso_index=30 reservation=32 time=3501136484 2025-05-02 23:59:07.003574 :91E2073E:db_trace:kso.c@4109:ksonfy(): [10420:30:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 23:59:07.003574 :91E2073F:db_trace:kso.c@4111:ksonfy(): [10420:30:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 23:59:07.003575 :91E20740:db_trace:kso.c@4113:ksonfy(): [10420:30:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 23:59:07.003575 :91E20741:db_trace:kso.c@4115:ksonfy(): [10420:30:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 23:59:07.003576 :91E20742:db_trace:kso.c@4117:ksonfy(): [10420:30:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 23:59:07.004076 :91E20743:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 23:59:37.060404 :91E2124B:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-02 23:59:50.932626 :91E21715:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-02 23:59:50.922 2025-05-02 23:59:50.932629 :91E21716:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=8072 pso_num=30 pso_serial#=121 2025-05-02 23:59:50.932758 :91E21717:db_trace:kso.c@4070:ksonfy(): [10420:30:0] kso: new process: pid=8072 (legacy spawn) 2025-05-02 23:59:50.946622 :91E21718:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 23:59:54.167970 :91E21829:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 23:59:54.167997 :91E2182C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 23:59:54.168142 :91E2182F:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] 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-02 23:59:54.169339 :91E21840:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-02 23:59:54.396480 :91E2185F:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-02 23:59:54.384 2025-05-02 23:59:54.396482 :91E21860:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=10552 pso_num=30 pso_serial#=122 2025-05-02 23:59:54.396619 :91E21861:db_trace:kso.c@4070:ksonfy(): [10420:30:0] kso: new process: pid=10552 (legacy spawn) 2025-05-02 23:59:54.403536 :91E21862:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 23:59:54.403745 :91E2186B:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] 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-02 23:59:54.404628 :91E2186C:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-02 23:59:54.422896 :91E2186F:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-02 23:59:54.415 2025-05-02 23:59:54.422898 :91E21870:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=7588 pso_num=30 pso_serial#=123 2025-05-02 23:59:54.423045 :91E21871:db_trace:kso.c@4070:ksonfy(): [10420:30:0] kso: new process: pid=7588 (legacy spawn) 2025-05-02 23:59:54.437697 :91E2187D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 00:00:27.636433 :91E227DC:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-03 01:00:25.118192 :91E6F19D:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-03 01:00:25.107 2025-05-03 01:00:25.118194 :91E6F19E:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=11180 pso_num=30 pso_serial#=124 2025-05-03 01:00:25.118325 :91E6F19F:db_trace:kso.c@4093:ksonfy(): [10420:30:0] kso: new process: pid=11180 osp_idx=28 osp_ver=633 osp_pg=0 (spawn #142363) 2025-05-03 01:00:25.118326 :91E6F1A0:db_trace:kso.c@4099:ksonfy(): [10420:30:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 01:00:25.118327 :91E6F1A1:db_trace:kso.c@4103:ksonfy(): [10420:30:0] kso: new process: pso_index=30 reservation=33 time=3504814593 2025-05-03 01:00:25.118327 :91E6F1A2:db_trace:kso.c@4109:ksonfy(): [10420:30:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 01:00:25.118328 :91E6F1A3:db_trace:kso.c@4111:ksonfy(): [10420:30:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 01:00:25.118328 :91E6F1A4:db_trace:kso.c@4113:ksonfy(): [10420:30:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 01:00:25.118329 :91E6F1A5:db_trace:kso.c@4115:ksonfy(): [10420:30:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 01:00:25.118329 :91E6F1A6:db_trace:kso.c@4117:ksonfy(): [10420:30:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 01:00:25.118835 :91E6F1A7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.118882 :91E6F1AD:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] 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-03 01:00:25.126551 :91E6F1C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.127630 :91E6F1CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.128181 :91E6F1D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.128643 :91E6F1DE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.129079 :91E6F1E6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.131554 :91E6F1EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.132634 :91E6F1F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.182365 :91E6F1FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.183316 :91E6F206:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.183549 :91E6F20E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.183782 :91E6F216:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 01:00:25.185491 :91E6F21E:db_trace:kst.c@698:kstpsodel(): [10280:30:0] kst: process state object about to be deleted 2025-05-03 06:00:02.053724 :91FED873:db_trace:kst.c@673:kstipg(): [10280:30:0] kst: process state object created on 05-03 06:00:02.051 2025-05-03 06:00:02.053724 :91FED874:db_trace:kst.c@679:kstipg(): [10280:30:0] kst: process info: ospid=8880 pso_num=30 pso_serial#=125 2025-05-03 06:00:02.053884 :91FED878:db_trace:kso.c@4093:ksonfy(): [10420:30:0] kso: new process: pid=8880 osp_idx=28 osp_ver=634 osp_pg=0 (spawn #143068) 2025-05-03 06:00:02.053885 :91FED879:db_trace:kso.c@4099:ksonfy(): [10420:30:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 06:00:02.053886 :91FED87A:db_trace:kso.c@4103:ksonfy(): [10420:30:0] kso: new process: pso_index=30 reservation=34 time=3522791515 2025-05-03 06:00:02.053886 :91FED87B:db_trace:kso.c@4109:ksonfy(): [10420:30:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 06:00:02.053886 :91FED87C:db_trace:kso.c@4111:ksonfy(): [10420:30:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 06:00:02.053887 :91FED87D:db_trace:kso.c@4113:ksonfy(): [10420:30:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 06:00:02.053887 :91FED87E:db_trace:kso.c@4115:ksonfy(): [10420:30:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 06:00:02.053888 :91FED87F:db_trace:kso.c@4117:ksonfy(): [10420:30:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 06:00:02.054588 :91FED885:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-03 06:00:02.059306 :91FED9DE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=24 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-03 06:00:02.059919 :91FED9E8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:02.059949 :91FED9EB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:jslv.c:9203 2025-05-03 06:00:02.065378 :91FEDA05:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:02.231855 :91FEDB5A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:02.391302 :91FEDB62:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:02.530526 :91FEDB82:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.663745 :91FEDE35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.664830 :91FEDE3D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.668758 :91FEDE45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.671746 :91FEDE4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.673239 :91FEDE55:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.689769 :91FEDE5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.690448 :91FEDE65:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.690998 :91FEDE6D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.691518 :91FEDE75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.694165 :91FEDE7D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.695059 :91FEDE85:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.695832 :91FEDE86:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.696577 :91FEDE87:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.697027 :91FEDE88:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.697033 :91FEDE89:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.697604 :91FEDE8A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.698103 :91FEDE8B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.698403 :91FEDE8C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.699449 :91FEDE8D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.741698 :91FEDE8E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.741744 :91FEDE91:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.742562 :91FEDE97:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.743353 :91FEDE9F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.743761 :91FEDEA0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.764015 :91FEDEA8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.764067 :91FEDEAB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.764897 :91FEDEB1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.765696 :91FEDEB9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.766123 :91FEDEC4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.784498 :91FEDECC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.784553 :91FEDECF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.785391 :91FEDED5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.796700 :91FEDF14:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpus:psdpgi.c:2235 2025-05-03 06:00:03.797213 :91FEDF15:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.817168 :91FEDF1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.817226 :91FEDF20:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:psdpgi.c:2235 2025-05-03 06:00:03.818080 :91FEDF26:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.818509 :91FEDF2E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.818854 :91FEDF36:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.819027 :91FEDF3E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.819164 :91FEDF46:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.819295 :91FEDF4E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:30:241] atxpop:jslv.c:9203 2025-05-03 06:00:03.823101 :91FEDF4F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.823174 :91FEDF52:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:30:241] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-03 06:00:03.823245 :91FEDF5F:db_trace:ksl2.c@12699:ksliwat(): [10005:30:241] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 30 (osid: 8880, J004)