Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250425221409\orcl_j001_2960_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:37623M/63366M, Ph+PgF:45334M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 2960, image: ORACLE.EXE (J001) *** 2025-04-25 22:14:09.998 *** SESSION ID:(201.14227) 2025-04-25 22:14:09.998 *** 2025-04-25 22:14:09.998 Process diagnostic dump for ORACLE.EXE (J001), OS id=2960, pid: 25, proc_ser: 250, sid: 201, sess_ser: 14227 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 2960 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=41 seq_num=42 snap_id=1 wait times: snap=0.426234 sec, exc=0.426234 sec, total=0.426234 sec wait times: max=0.500000 sec, heur=20.993923 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.000010 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.501076 sec, exc=0.501076 sec, total=0.501076 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=39 seq_num=40 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.500176 sec, exc=0.500176 sec, total=0.500176 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=37 seq_num=38 snap_id=1 wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=36 seq_num=37 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=35 seq_num=36 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.000007 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.500122 sec, exc=0.500122 sec, total=0.500122 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=33 seq_num=34 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.000010 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.507780 sec, exc=0.507780 sec, total=0.507780 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=31 seq_num=32 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.000008 sec of elapsed time Sampled Session History of session 201 serial 14227 --------------------------------------------------- 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 --------------------------------------------------- [21 samples, 22:13:49 - 22:14:09] idle wait at each sample [session created at: 22:13:49] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-25 22:14:09.998 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 2960, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-25 22:00:04.014352*:8EBBEACF:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DDC718 estart=1745589603 eid=16779261 ctx=0x000000077FD6A000 cwh=0x0000000024DD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-04-25 22:00:04.014352*:8EBBEAD0:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 pubTabIdxCnt=0 2025-04-25 22:00:04.014352*:8EBBEAD1:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DDC718 2025-04-25 22:00:04.014352*:8EBBEAD2:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DDC718 2025-04-25 22:00:04.014352*:8EBBEAD3:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 xsc->flg4=65792 flags=2 2025-04-25 22:00:04.014352*:8EBBEAD4:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DDC718 2025-04-25 22:00:04.016446 :8EBBEAD5: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-04-25 22:00:04.016484 :8EBBEAD8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-04-25 22:00:04.024289 :8EBBEADE: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-04-25 22:00:04.024944 :8EBBEAE6: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-04-25 22:00:04.025707 :8EBBEAEE: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-04-25 22:00:04.025891 :8EBBEAF6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-04-25 22:00:04.028553 :8EBBEAF7: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-04-25 22:00:04.028616 :8EBBEAFA: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-04-25 22:00:04.028699 :8EBBEB07: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-04-25 22:00:34.129797 :8EBBF824:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:00:47.779730 :8EBBFD1A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:00:47.768 2025-04-25 22:00:47.779732 :8EBBFD1B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9268 pso_num=25 pso_serial#=236 2025-04-25 22:00:47.779862 :8EBBFD1C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9268 osp_idx=23 osp_ver=64750 osp_pg=0 (spawn #118203) 2025-04-25 22:00:47.779863 :8EBBFD1D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:00:47.779863 :8EBBFD1E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=208 time=2889249562 2025-04-25 22:00:47.779864 :8EBBFD1F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:00:47.779864 :8EBBFD20:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:00:47.779864 :8EBBFD21:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:00:47.779865 :8EBBFD22:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:00:47.779865 :8EBBFD23:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:00:47.780359 :8EBBFD2C: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-04-25 22:01:17.855405 :8EBC08CA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:01:47.862973 :8EBC129C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:01:47.851 2025-04-25 22:01:47.862975 :8EBC129D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=996 pso_num=25 pso_serial#=237 2025-04-25 22:01:47.863092 :8EBC129E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=996 osp_idx=23 osp_ver=64751 osp_pg=0 (spawn #118207) 2025-04-25 22:01:47.863093 :8EBC129F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:01:47.863093 :8EBC12A0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=209 time=2889309656 2025-04-25 22:01:47.863094 :8EBC12A1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:01:47.863094 :8EBC12A2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:01:47.863094 :8EBC12A3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:01:47.863095 :8EBC12A4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:01:47.863095 :8EBC12A5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:01:47.863574 :8EBC12A6: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-04-25 22:02:17.940261 :8EBC1C75:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:02:47.936065 :8EBC2676:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:02:47.925 2025-04-25 22:02:47.936068 :8EBC2677:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9552 pso_num=25 pso_serial#=238 2025-04-25 22:02:47.936194 :8EBC2678:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9552 osp_idx=23 osp_ver=64752 osp_pg=0 (spawn #118209) 2025-04-25 22:02:47.936194 :8EBC2679:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:02:47.936195 :8EBC267A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=210 time=2889369718 2025-04-25 22:02:47.936195 :8EBC267B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:02:47.936196 :8EBC267C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:02:47.936196 :8EBC267D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:02:47.936196 :8EBC267E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:02:47.936197 :8EBC267F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:02:47.936654 :8EBC2680: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-04-25 22:03:18.033051 :8EBC305F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:03:48.031266 :8EBC3A39:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:03:48.020 2025-04-25 22:03:48.031268 :8EBC3A3A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11012 pso_num=25 pso_serial#=239 2025-04-25 22:03:48.031408 :8EBC3A3B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11012 osp_idx=23 osp_ver=64753 osp_pg=0 (spawn #118211) 2025-04-25 22:03:48.031409 :8EBC3A3C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:03:48.031410 :8EBC3A3D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=211 time=2889429828 2025-04-25 22:03:48.031410 :8EBC3A3E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:03:48.031410 :8EBC3A3F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:03:48.031411 :8EBC3A40:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:03:48.031411 :8EBC3A41:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:03:48.031411 :8EBC3A42:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:03:48.031902 :8EBC3A43: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-04-25 22:04:18.118484 :8EBC448F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:04:48.137009 :8EBC4E77:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:04:48.125 2025-04-25 22:04:48.137012 :8EBC4E78:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8868 pso_num=25 pso_serial#=240 2025-04-25 22:04:48.137150 :8EBC4E79:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8868 osp_idx=23 osp_ver=64754 osp_pg=0 (spawn #118216) 2025-04-25 22:04:48.137151 :8EBC4E7A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:04:48.137151 :8EBC4E7B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=212 time=2889489921 2025-04-25 22:04:48.137152 :8EBC4E7C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:04:48.137152 :8EBC4E7D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:04:48.137153 :8EBC4E7E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:04:48.137153 :8EBC4E7F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:04:48.137153 :8EBC4E80:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:04:48.137633 :8EBC4E81: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-04-25 22:05:18.188162 :8EBC5BBC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:05:48.217440 :8EBC6B46:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:05:48.206 2025-04-25 22:05:48.217443 :8EBC6B47:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9956 pso_num=25 pso_serial#=241 2025-04-25 22:05:48.217582 :8EBC6B48:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9956 osp_idx=23 osp_ver=64755 osp_pg=0 (spawn #118218) 2025-04-25 22:05:48.217583 :8EBC6B49:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:05:48.217583 :8EBC6B4A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=213 time=2889550000 2025-04-25 22:05:48.217584 :8EBC6B4B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:05:48.217584 :8EBC6B4C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:05:48.217585 :8EBC6B4D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:05:48.217585 :8EBC6B4E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:05:48.217585 :8EBC6B4F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:05:48.218072 :8EBC6B50: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-04-25 22:06:18.307630 :8EBC76D3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:06:48.333787 :8EBC80B7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:06:48.322 2025-04-25 22:06:48.333789 :8EBC80B8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10632 pso_num=25 pso_serial#=242 2025-04-25 22:06:48.333918 :8EBC80B9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10632 osp_idx=23 osp_ver=64756 osp_pg=0 (spawn #118220) 2025-04-25 22:06:48.333919 :8EBC80BA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:06:48.333919 :8EBC80BB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=214 time=2889610125 2025-04-25 22:06:48.333919 :8EBC80BC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:06:48.333920 :8EBC80BD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:06:48.333920 :8EBC80BE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:06:48.333920 :8EBC80BF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:06:48.333921 :8EBC80C0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:06:48.334388 :8EBC80C1: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-04-25 22:07:18.410123 :8EBC8A84:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:07:43.436144 :8EBC9296:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:07:43.425 2025-04-25 22:07:43.436146 :8EBC9297:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10656 pso_num=25 pso_serial#=243 2025-04-25 22:07:43.436279 :8EBC9298:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10656 osp_idx=23 osp_ver=64757 osp_pg=0 (spawn #118222) 2025-04-25 22:07:43.436280 :8EBC9299:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:07:43.436280 :8EBC929A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=215 time=2889665218 2025-04-25 22:07:43.436281 :8EBC929B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:07:43.436281 :8EBC929C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:07:43.436281 :8EBC929D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:07:43.436282 :8EBC929E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:07:43.436282 :8EBC929F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:07:43.436757 :8EBC92A0: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-04-25 22:07:48.438874 :8EBC9483: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-04-25 22:08:18.523441 :8EBC9E36:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:08:48.520937 :8EBCA84B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:08:48.510 2025-04-25 22:08:48.520939 :8EBCA84C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9484 pso_num=25 pso_serial#=244 2025-04-25 22:08:48.521075 :8EBCA84D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9484 osp_idx=23 osp_ver=64758 osp_pg=0 (spawn #118225) 2025-04-25 22:08:48.521076 :8EBCA84E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:08:48.521076 :8EBCA84F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=216 time=2889730312 2025-04-25 22:08:48.521077 :8EBCA850:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:08:48.521078 :8EBCA851:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:08:48.521078 :8EBCA852:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:08:48.521079 :8EBCA853:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:08:48.521079 :8EBCA854:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:08:48.521558 :8EBCA855: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-04-25 22:09:18.564938 :8EBCB241:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:09:48.595943 :8EBCBBFD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:09:48.584 2025-04-25 22:09:48.595945 :8EBCBBFE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11148 pso_num=25 pso_serial#=245 2025-04-25 22:09:48.596080 :8EBCBBFF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11148 osp_idx=23 osp_ver=64759 osp_pg=0 (spawn #118227) 2025-04-25 22:09:48.596081 :8EBCBC00:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:09:48.596081 :8EBCBC01:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=217 time=2889790390 2025-04-25 22:09:48.596082 :8EBCBC02:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:09:48.596082 :8EBCBC03:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:09:48.596083 :8EBCBC04:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:09:48.596083 :8EBCBC05:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:09:48.596083 :8EBCBC06:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:09:48.596571 :8EBCBC07: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-04-25 22:10:18.671393 :8EBCC5EC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:10:48.733549 :8EBCCFE1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:10:48.722 2025-04-25 22:10:48.733552 :8EBCCFE2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=608 pso_num=25 pso_serial#=246 2025-04-25 22:10:48.733686 :8EBCCFE3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=608 osp_idx=23 osp_ver=64760 osp_pg=0 (spawn #118229) 2025-04-25 22:10:48.733687 :8EBCCFE4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:10:48.733687 :8EBCCFE5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=218 time=2889850515 2025-04-25 22:10:48.733688 :8EBCCFE6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:10:48.733688 :8EBCCFE7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:10:48.733688 :8EBCCFE8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:10:48.733688 :8EBCCFE9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:10:48.733689 :8EBCCFEA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:10:48.734187 :8EBCCFEB: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-04-25 22:11:18.829960 :8EBCDAB8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:11:48.838839 :8EBCE495:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:11:48.827 2025-04-25 22:11:48.838841 :8EBCE496:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10264 pso_num=25 pso_serial#=247 2025-04-25 22:11:48.838973 :8EBCE497:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10264 osp_idx=23 osp_ver=64761 osp_pg=0 (spawn #118231) 2025-04-25 22:11:48.838973 :8EBCE498:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:11:48.838974 :8EBCE499:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=219 time=2889910625 2025-04-25 22:11:48.838975 :8EBCE49A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:11:48.838975 :8EBCE49B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:11:48.838976 :8EBCE49C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:11:48.838976 :8EBCE49D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:11:48.838976 :8EBCE49E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:11:48.839537 :8EBCE49F: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-04-25 22:12:18.964177 :8EBCEE80:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:12:18.972746 :8EBCEE83:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:12:18.964 2025-04-25 22:12:18.972748 :8EBCEE84:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9960 pso_num=25 pso_serial#=248 2025-04-25 22:12:18.972883 :8EBCEE85:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=9960 (legacy spawn) 2025-04-25 22:12:18.979375 :8EBCEE86: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-04-25 22:12:18.979576 :8EBCEE8B: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-04-25 22:12:18.980277 :8EBCEE93:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:12:48.952751 :8EBCF841:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:12:48.942 2025-04-25 22:12:48.952753 :8EBCF842:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10472 pso_num=25 pso_serial#=249 2025-04-25 22:12:48.952880 :8EBCF843:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10472 osp_idx=23 osp_ver=64763 osp_pg=0 (spawn #118233) 2025-04-25 22:12:48.952881 :8EBCF844:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:12:48.952881 :8EBCF845:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=220 time=2889970750 2025-04-25 22:12:48.952881 :8EBCF846:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:12:48.952882 :8EBCF847:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:12:48.952882 :8EBCF848:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:12:48.952882 :8EBCF849:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:12:48.952883 :8EBCF84A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:12:48.953348 :8EBCF84B: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-04-25 22:13:19.018783 :8EBD0215:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-25 22:13:49.007452 :8EBD0BCF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-25 22:13:48.996 2025-04-25 22:13:49.007454 :8EBD0BD0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=2960 pso_num=25 pso_serial#=250 2025-04-25 22:13:49.007579 :8EBD0BD1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=2960 osp_idx=23 osp_ver=64764 osp_pg=0 (spawn #118235) 2025-04-25 22:13:49.007580 :8EBD0BD2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:13:49.007581 :8EBD0BD3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=221 time=2890030796 2025-04-25 22:13:49.007581 :8EBD0BD4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:13:49.007582 :8EBD0BD5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:13:49.007582 :8EBD0BD6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:13:49.007583 :8EBD0BD7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:13:49.007583 :8EBD0BD8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:13:49.008078 :8EBD0BD9: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: 2960, J001)