Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250429221649\orcl_j001_11556_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:37668M/63366M, Ph+PgF:45276M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 11556, image: ORACLE.EXE (J001) *** 2025-04-29 22:16:49.911 *** SESSION ID:(209.44587) 2025-04-29 22:16:49.911 *** 2025-04-29 22:16:49.911 Process diagnostic dump for ORACLE.EXE (J001), OS id=11556, pid: 26, proc_ser: 53, sid: 209, sess_ser: 44587 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 11556 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.414675 sec, exc=0.414675 sec, total=0.414675 sec wait times: max=0.500000 sec, heur=28.435755 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=55 seq_num=56 snap_id=1 wait times: snap=0.499982 sec, exc=0.499982 sec, total=0.499982 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 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.501649 sec, exc=0.501649 sec, total=0.501649 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=53 seq_num=54 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 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=52 seq_num=53 snap_id=1 wait times: snap=0.499992 sec, exc=0.499992 sec, total=0.499992 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=51 seq_num=52 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.000007 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.500002 sec, exc=0.500002 sec, total=0.500002 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=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.000009 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.505108 sec, exc=0.505108 sec, total=0.505108 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.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 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=46 seq_num=47 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.000014 sec of elapsed time Sampled Session History of session 209 serial 44587 --------------------------------------------------- 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:16:21 - 22:16:49] idle wait at each sample [session created at: 22:16:21] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-29 22:16:49.911 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 11556, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-29 22:01:25.082832 :90876F40:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:01:25.082832 :90876F41:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:01:25.082832 :90876F42:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:01:25.083304 :90876F43:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:01:55.188594 :908779A0:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:02:25.171855 :9087836B:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:02:25.160 2025-04-29 22:02:25.171857 :9087836C:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10696 pso_num=26 pso_serial#=38 2025-04-29 22:02:25.171992 :9087836D:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10696 osp_idx=24 osp_ver=185167 osp_pg=0 (spawn #131788) 2025-04-29 22:02:25.171993 :9087836E:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:02:25.171994 :9087836F:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=70 time=3234934640 2025-04-29 22:02:25.171994 :90878370:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:02:25.171995 :90878371:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:02:25.171995 :90878372:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:02:25.171995 :90878373:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:02:25.171995 :90878374:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:02:25.172479 :90878375:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:02:55.237408 :90878D4F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:03:25.268272 :90879717:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:03:25.257 2025-04-29 22:03:25.268274 :90879718:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=7736 pso_num=26 pso_serial#=39 2025-04-29 22:03:25.268408 :90879719:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=7736 osp_idx=24 osp_ver=185168 osp_pg=0 (spawn #131790) 2025-04-29 22:03:25.268409 :9087971A:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:03:25.268409 :9087971B:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=71 time=3234994750 2025-04-29 22:03:25.268410 :9087971C:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:03:25.268410 :9087971D:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:03:25.268410 :9087971E:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:03:25.268411 :9087971F:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:03:25.268411 :90879720:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:03:25.268896 :90879721:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:03:55.358047 :9087A13E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:04:25.361656 :9087AA8E:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:04:25.350 2025-04-29 22:04:25.361658 :9087AA8F:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10208 pso_num=26 pso_serial#=40 2025-04-29 22:04:25.361800 :9087AA90:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10208 osp_idx=24 osp_ver=185169 osp_pg=0 (spawn #131792) 2025-04-29 22:04:25.361801 :9087AA91:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:04:25.361801 :9087AA92:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=72 time=3235054843 2025-04-29 22:04:25.361803 :9087AA93:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:04:25.361803 :9087AA94:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:04:25.361804 :9087AA95:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:04:25.361804 :9087AA96:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:04:25.361804 :9087AA97:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:04:25.362297 :9087AA98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:04:55.412171 :9087B494:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:05:25.432660 :9087C1BA:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:05:25.421 2025-04-29 22:05:25.432663 :9087C1BB:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12116 pso_num=26 pso_serial#=41 2025-04-29 22:05:25.432803 :9087C1BC:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12116 osp_idx=24 osp_ver=185170 osp_pg=0 (spawn #131794) 2025-04-29 22:05:25.432804 :9087C1BD:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:05:25.432805 :9087C1BE:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=73 time=3235114906 2025-04-29 22:05:25.432805 :9087C1BF:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:05:25.432806 :9087C1C0:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:05:25.432806 :9087C1C1:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:05:25.432806 :9087C1C2:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:05:25.432806 :9087C1C3:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:05:25.433280 :9087C1C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:05:55.495014 :9087D2C3:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:06:20.507283 :9087DB3E:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:06:20.496 2025-04-29 22:06:20.507285 :9087DB3F:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=608 pso_num=26 pso_serial#=42 2025-04-29 22:06:20.507416 :9087DB40:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=608 osp_idx=24 osp_ver=185171 osp_pg=0 (spawn #131796) 2025-04-29 22:06:20.507416 :9087DB41:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:06:20.507417 :9087DB42:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=74 time=3235169984 2025-04-29 22:06:20.507417 :9087DB43:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:06:20.507418 :9087DB44:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:06:20.507418 :9087DB45:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:06:20.507418 :9087DB46:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:06:20.507418 :9087DB47:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:06:20.507914 :9087DB48:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:06:25.498803 :9087DCEB:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-29 22:06:55.598376 :9087E792:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:07:25.616851 :9087F12B:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:07:25.605 2025-04-29 22:07:25.616853 :9087F12C:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12048 pso_num=26 pso_serial#=43 2025-04-29 22:07:25.616988 :9087F12D:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12048 osp_idx=24 osp_ver=185172 osp_pg=0 (spawn #131799) 2025-04-29 22:07:25.616989 :9087F12E:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:07:25.616990 :9087F12F:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=75 time=3235235093 2025-04-29 22:07:25.616990 :9087F130:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:07:25.616990 :9087F131:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:07:25.616990 :9087F132:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:07:25.616991 :9087F133:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:07:25.616991 :9087F134:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:07:25.617458 :9087F135:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:07:55.721648 :9087FB08:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:08:25.722211 :908804DF:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:08:25.711 2025-04-29 22:08:25.722213 :908804E0:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10076 pso_num=26 pso_serial#=44 2025-04-29 22:08:25.722349 :908804E1:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10076 osp_idx=24 osp_ver=185173 osp_pg=0 (spawn #131801) 2025-04-29 22:08:25.722349 :908804E2:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:08:25.722350 :908804E3:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=76 time=3235295203 2025-04-29 22:08:25.722350 :908804E4:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:08:25.722351 :908804E5:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:08:25.722351 :908804E6:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:08:25.722352 :908804E7:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:08:25.722352 :908804E8:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:08:25.722838 :908804E9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:08:55.777274 :90880FB3:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:09:25.829017 :90881997:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:09:25.817 2025-04-29 22:09:25.829019 :90881998:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2196 pso_num=26 pso_serial#=45 2025-04-29 22:09:25.829153 :90881999:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2196 osp_idx=24 osp_ver=185174 osp_pg=0 (spawn #131803) 2025-04-29 22:09:25.829154 :9088199A:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:09:25.829155 :9088199B:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=77 time=3235355296 2025-04-29 22:09:25.829155 :9088199C:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:09:25.829156 :9088199D:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:09:25.829156 :9088199E:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:09:25.829157 :9088199F:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:09:25.829157 :908819A0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:09:25.829627 :908819A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:09:55.914657 :90882350:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:09:55.925617 :90882360:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:09:55.915 2025-04-29 22:09:55.925619 :90882361:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=7552 pso_num=26 pso_serial#=46 2025-04-29 22:09:55.925755 :90882362:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=7552 (legacy spawn) 2025-04-29 22:09:55.932814 :90882366:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-29 22:09:55.933092 :9088236C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-29 22:09:55.933942 :90882370:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:10:25.917675 :90882D26:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:10:25.907 2025-04-29 22:10:25.917677 :90882D27:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11952 pso_num=26 pso_serial#=47 2025-04-29 22:10:25.917806 :90882D28:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11952 osp_idx=24 osp_ver=185176 osp_pg=0 (spawn #131805) 2025-04-29 22:10:25.917807 :90882D29:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:10:25.917807 :90882D2A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=78 time=3235415390 2025-04-29 22:10:25.917808 :90882D2B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:10:25.917808 :90882D2C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:10:25.917809 :90882D2D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:10:25.917809 :90882D2E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:10:25.917809 :90882D2F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:10:25.918335 :90882D30:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:10:56.012899 :90883734:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:11:26.037494 :90884136:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:11:26.026 2025-04-29 22:11:26.037496 :90884137:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10380 pso_num=26 pso_serial#=48 2025-04-29 22:11:26.037636 :90884138:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10380 osp_idx=24 osp_ver=185177 osp_pg=0 (spawn #131808) 2025-04-29 22:11:26.037636 :90884139:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:11:26.037637 :9088413A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=79 time=3235475515 2025-04-29 22:11:26.037637 :9088413B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:11:26.037637 :9088413C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:11:26.037638 :9088413D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:11:26.037638 :9088413E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:11:26.037638 :9088413F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:11:26.038113 :90884140:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:11:56.066481 :90884FA4:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:12:26.112875 :9088596B:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:12:26.102 2025-04-29 22:12:26.112877 :9088596C:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11652 pso_num=26 pso_serial#=49 2025-04-29 22:12:26.113009 :9088596D:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11652 osp_idx=24 osp_ver=185178 osp_pg=0 (spawn #131810) 2025-04-29 22:12:26.113010 :9088596E:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:12:26.113010 :9088596F:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=80 time=3235535593 2025-04-29 22:12:26.113011 :90885970:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:12:26.113011 :90885971:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:12:26.113011 :90885972:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:12:26.113012 :90885973:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:12:26.113012 :90885974:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:12:26.113501 :90885975:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:12:56.190027 :9088631D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:13:26.172981 :90886CEA:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:13:26.162 2025-04-29 22:13:26.172983 :90886CEB:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=6076 pso_num=26 pso_serial#=50 2025-04-29 22:13:26.173118 :90886CEC:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=6076 osp_idx=24 osp_ver=185179 osp_pg=0 (spawn #131812) 2025-04-29 22:13:26.173118 :90886CED:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:13:26.173119 :90886CEE:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=81 time=3235595640 2025-04-29 22:13:26.173119 :90886CEF:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:13:26.173119 :90886CF0:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:13:26.173120 :90886CF1:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:13:26.173120 :90886CF2:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:13:26.173121 :90886CF3:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:13:26.173635 :90886CF4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:13:56.248155 :90887738:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:14:26.281565 :90888108:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:14:26.270 2025-04-29 22:14:26.281567 :90888109:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10608 pso_num=26 pso_serial#=51 2025-04-29 22:14:26.281769 :9088810A:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10608 osp_idx=24 osp_ver=185180 osp_pg=0 (spawn #131814) 2025-04-29 22:14:26.281769 :9088810B:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:14:26.281770 :9088810C:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=82 time=3235655750 2025-04-29 22:14:26.281770 :9088810D:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:14:26.281771 :9088810E:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:14:26.281771 :9088810F:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:14:26.281772 :90888110:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:14:26.281772 :90888111:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:14:26.282283 :90888112:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:14:56.389775 :90888B07:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:15:26.397870 :908894C7:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:15:26.387 2025-04-29 22:15:26.397872 :908894C8:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=8232 pso_num=26 pso_serial#=52 2025-04-29 22:15:26.398055 :908894C9:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=8232 osp_idx=24 osp_ver=185181 osp_pg=0 (spawn #131816) 2025-04-29 22:15:26.398056 :908894CA:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:15:26.398056 :908894CB:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=83 time=3235715875 2025-04-29 22:15:26.398057 :908894CC:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:15:26.398057 :908894CD:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:15:26.398058 :908894CE:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:15:26.398058 :908894CF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:15:26.398059 :908894D0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:15:26.398575 :908894D1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:15:56.484274 :90889E93:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-04-29 22:16:21.483449 :9088A6CC:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 04-29 22:16:21.472 2025-04-29 22:16:21.483451 :9088A6CD:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11556 pso_num=26 pso_serial#=53 2025-04-29 22:16:21.483588 :9088A6CE:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11556 osp_idx=24 osp_ver=185182 osp_pg=0 (spawn #131818) 2025-04-29 22:16:21.483588 :9088A6CF:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:16:21.483589 :9088A6D0:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=84 time=3235770953 2025-04-29 22:16:21.483589 :9088A6D1:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:16:21.483590 :9088A6D2:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:16:21.483590 :9088A6D3:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:16:21.483590 :9088A6D4:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:16:21.483591 :9088A6D5:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:16:21.484065 :9088A6D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-29 22:16:26.488610 :9088A874:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 11556, J001)