Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250905222022\orcl_m002_20488_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:35036M/63366M, Ph+PgF:39876M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 20488, image: ORACLE.EXE (M002) *** 2025-09-05 22:20:22.318 *** SESSION ID:(201.34309) 2025-09-05 22:20:22.318 *** 2025-09-05 22:20:22.318 Process diagnostic dump for ORACLE.EXE (M002), OS id=20488, pid: 25, proc_ser: 182, sid: 201, sess_ser: 34309 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'enq: TC - contention' name|mode=0x54430006, checkpoint ID=0x10019, 0=0x0 wait_id=1129 seq_num=1130 snap_id=1 wait times: snap=0.010059 sec, exc=0.010059 sec, total=0.010059 sec wait times: max=infinite, heur=0.010059 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a0 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000008 sec since current wait 0: waited for 'rdbms ipc reply' from_process=0xf, timeout=0x147ae14, =0x0 wait_id=1128 seq_num=1129 snap_id=1 wait times: snap=0.000027 sec, exc=0.000027 sec, total=0.000027 sec wait times: max=2.000000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 1: waited for 'rdbms ipc reply' from_process=0xf, timeout=0x147ae14, =0x0 wait_id=1127 seq_num=1128 snap_id=1 wait times: snap=0.000024 sec, exc=0.000024 sec, total=0.000024 sec wait times: max=2.000000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 2: waited for 'rdbms ipc reply' from_process=0xf, timeout=0x147ae14, =0x0 wait_id=1126 seq_num=1127 snap_id=1 wait times: snap=0.000019 sec, exc=0.000019 sec, total=0.000019 sec wait times: max=2.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 3: waited for 'control file sequential read' file#=0x0, block#=0x17, blocks=0x1 wait_id=1125 seq_num=1126 snap_id=1 wait times: snap=0.000055 sec, exc=0.000055 sec, total=0.000055 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000009 sec of elapsed time 4: waited for 'control file sequential read' file#=0x0, block#=0x11, blocks=0x1 wait_id=1124 seq_num=1125 snap_id=1 wait times: snap=0.000047 sec, exc=0.000047 sec, total=0.000047 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 5: waited for 'control file sequential read' file#=0x0, block#=0xf, blocks=0x1 wait_id=1123 seq_num=1124 snap_id=1 wait times: snap=0.000046 sec, exc=0.000046 sec, total=0.000046 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 6: waited for 'control file sequential read' file#=0x1, block#=0x1, blocks=0x1 wait_id=1122 seq_num=1123 snap_id=1 wait times: snap=0.000051 sec, exc=0.000051 sec, total=0.000051 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 7: waited for 'control file sequential read' file#=0x0, block#=0x1, blocks=0x1 wait_id=1121 seq_num=1122 snap_id=1 wait times: snap=0.000072 sec, exc=0.000072 sec, total=0.000072 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000412 sec of elapsed time 8: waited for 'rdbms ipc reply' from_process=0xf, timeout=0x147ae14, =0x0 wait_id=1120 seq_num=1121 snap_id=1 wait times: snap=0.000028 sec, exc=0.000028 sec, total=0.000028 sec wait times: max=2.000000 sec wait counts: calls=1 os=1 occurred after 0.000015 sec of elapsed time 9: waited for 'reliable message' channel context=0x7dc56ad40, channel handle=0x7ac4d61b0, broadcast message=0x7ac501de0 wait_id=1119 seq_num=1120 snap_id=1 wait times: snap=0.000089 sec, exc=0.000089 sec, total=0.000089 sec wait times: max=1.000000 sec wait counts: calls=1 os=1 occurred after 0.000060 sec of elapsed time Sampled Session History of session 201 serial 34309 --------------------------------------------------- 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 --------------------------------------------------- [1 sample, 22:20:22] idle wait at each sample [session created at: 22:20:22] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-05 22:20:22.318 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 20488, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-05 22:06:15.979015 :C97EA5EA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:06:15.979498 :C97EA5EB: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-09-05 22:06:30.989962 :C97EAABA: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-09-05 22:07:01.105805 :C97EB4C7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:07:31.094881 :C97EBEBE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:07:31.083 2025-09-05 22:07:31.094883 :C97EBEBF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=24104 pso_num=25 pso_serial#=167 2025-09-05 22:07:31.095013 :C97EBEC0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=24104 osp_idx=23 osp_ver=282210 osp_pg=0 (spawn #562505) 2025-09-05 22:07:31.095014 :C97EBEC1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:07:31.095014 :C97EBEC2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=25 time=1495702393 2025-09-05 22:07:31.095015 :C97EBEC3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:07:31.095015 :C97EBEC4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:07:31.095015 :C97EBEC5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:07:31.095016 :C97EBEC6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:07:31.095016 :C97EBEC7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:07:31.095485 :C97EBEC8: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-09-05 22:08:01.176902 :C97EC8AC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:08:31.172720 :C97ED25E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:08:31.161 2025-09-05 22:08:31.172722 :C97ED25F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8240 pso_num=25 pso_serial#=168 2025-09-05 22:08:31.172850 :C97ED260:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8240 osp_idx=23 osp_ver=282211 osp_pg=0 (spawn #562507) 2025-09-05 22:08:31.172851 :C97ED261:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:08:31.172851 :C97ED262:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=26 time=1495762471 2025-09-05 22:08:31.172851 :C97ED263:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:08:31.172852 :C97ED264:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:08:31.172852 :C97ED265:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:08:31.172852 :C97ED266:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:08:31.172853 :C97ED267:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:08:31.173340 :C97ED268: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-09-05 22:09:01.252155 :C97EDC4D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:09:31.268980 :C97EE667:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:09:31.258 2025-09-05 22:09:31.268982 :C97EE668:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16664 pso_num=25 pso_serial#=169 2025-09-05 22:09:31.269114 :C97EE669:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16664 osp_idx=23 osp_ver=282212 osp_pg=0 (spawn #562509) 2025-09-05 22:09:31.269114 :C97EE66A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:09:31.269115 :C97EE66B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=27 time=1495822565 2025-09-05 22:09:31.269115 :C97EE66C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:09:31.269116 :C97EE66D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:09:31.269116 :C97EE66E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:09:31.269116 :C97EE66F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:09:31.269117 :C97EE670:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:09:31.269594 :C97EE671: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-09-05 22:10:01.355939 :C97EF04F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:10:31.348968 :C97EFA66:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:10:31.338 2025-09-05 22:10:31.348970 :C97EFA67:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23996 pso_num=25 pso_serial#=170 2025-09-05 22:10:31.349099 :C97EFA68:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23996 osp_idx=23 osp_ver=282213 osp_pg=0 (spawn #562511) 2025-09-05 22:10:31.349100 :C97EFA69:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:10:31.349100 :C97EFA6A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=28 time=1495882643 2025-09-05 22:10:31.349100 :C97EFA6B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:10:31.349101 :C97EFA6C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:10:31.349101 :C97EFA6D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:10:31.349101 :C97EFA6E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:10:31.349101 :C97EFA6F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:10:31.349602 :C97EFA70: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-09-05 22:11:01.435547 :C97F0565:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:11:31.451258 :C97F0F24:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:11:31.440 2025-09-05 22:11:31.451260 :C97F0F25:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21936 pso_num=25 pso_serial#=171 2025-09-05 22:11:31.451383 :C97F0F26:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21936 osp_idx=23 osp_ver=282214 osp_pg=0 (spawn #562513) 2025-09-05 22:11:31.451383 :C97F0F27:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:11:31.451384 :C97F0F28:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=29 time=1495942752 2025-09-05 22:11:31.451384 :C97F0F29:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:11:31.451384 :C97F0F2A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:11:31.451385 :C97F0F2B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:11:31.451385 :C97F0F2C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:11:31.451385 :C97F0F2D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:11:31.451837 :C97F0F2E: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-09-05 22:12:01.539286 :C97F192C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:12:31.508188 :C97F22EA:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:12:31.496 2025-09-05 22:12:31.508190 :C97F22EB:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23656 pso_num=25 pso_serial#=172 2025-09-05 22:12:31.508360 :C97F22EC:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23656 osp_idx=23 osp_ver=282215 osp_pg=0 (spawn #562516) 2025-09-05 22:12:31.508360 :C97F22ED:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:12:31.508360 :C97F22EE:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=30 time=1496002799 2025-09-05 22:12:31.508361 :C97F22EF:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:12:31.508362 :C97F22F0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:12:31.508362 :C97F22F1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:12:31.508362 :C97F22F2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:12:31.508363 :C97F22F3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:12:31.508897 :C97F22F4: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-09-05 22:13:01.572177 :C97F2CBD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:13:31.589505 :C97F36A7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:13:31.577 2025-09-05 22:13:31.589507 :C97F36A8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20704 pso_num=25 pso_serial#=173 2025-09-05 22:13:31.589623 :C97F36A9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20704 osp_idx=23 osp_ver=282216 osp_pg=0 (spawn #562518) 2025-09-05 22:13:31.589624 :C97F36AA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:13:31.589624 :C97F36AB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=31 time=1496062893 2025-09-05 22:13:31.589625 :C97F36AC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:13:31.589625 :C97F36AD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:13:31.589626 :C97F36AE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:13:31.589626 :C97F36AF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:13:31.589627 :C97F36B0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:13:31.590135 :C97F36B1: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-09-05 22:14:01.681574 :C97F40FC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:14:31.663170 :C97F4ACB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:14:31.652 2025-09-05 22:14:31.663172 :C97F4ACC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22668 pso_num=25 pso_serial#=174 2025-09-05 22:14:31.663300 :C97F4ACD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22668 osp_idx=23 osp_ver=282217 osp_pg=0 (spawn #562521) 2025-09-05 22:14:31.663301 :C97F4ACE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:14:31.663301 :C97F4ACF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=32 time=1496122955 2025-09-05 22:14:31.663302 :C97F4AD0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:14:31.663302 :C97F4AD1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:14:31.663302 :C97F4AD2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:14:31.663303 :C97F4AD3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:14:31.663303 :C97F4AD4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:14:31.663831 :C97F4AD5: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-09-05 22:15:01.753425 :C97F54DD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:15:31.762959 :C97F5ECB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:15:31.750 2025-09-05 22:15:31.762961 :C97F5ECC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22116 pso_num=25 pso_serial#=175 2025-09-05 22:15:31.763079 :C97F5ECD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22116 osp_idx=23 osp_ver=282218 osp_pg=0 (spawn #562523) 2025-09-05 22:15:31.763080 :C97F5ECE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:15:31.763081 :C97F5ECF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=33 time=1496183065 2025-09-05 22:15:31.763081 :C97F5ED0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:15:31.763082 :C97F5ED1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:15:31.763083 :C97F5ED2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:15:31.763083 :C97F5ED3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:15:31.763083 :C97F5ED4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:15:31.763667 :C97F5ED5: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-09-05 22:16:01.845471 :C97F6CDC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:16:16.842328 :C97F71C4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:16:16.831 2025-09-05 22:16:16.842330 :C97F71C5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22808 pso_num=25 pso_serial#=176 2025-09-05 22:16:16.842460 :C97F71C6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22808 osp_idx=23 osp_ver=282219 osp_pg=0 (spawn #562525) 2025-09-05 22:16:16.842460 :C97F71C7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:16:16.842461 :C97F71C8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=34 time=1496228143 2025-09-05 22:16:16.842461 :C97F71C9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:16:16.842462 :C97F71CA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:16:16.842462 :C97F71CB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:16:16.842462 :C97F71CC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:16:16.842462 :C97F71CD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:16:16.842951 :C97F71CE: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-09-05 22:16:31.835059 :C97F76DB: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-09-05 22:17:01.921031 :C97F80D6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:17:31.935607 :C97F8A95:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:17:31.924 2025-09-05 22:17:31.935609 :C97F8A96:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19996 pso_num=25 pso_serial#=177 2025-09-05 22:17:31.935732 :C97F8A97:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19996 osp_idx=23 osp_ver=282220 osp_pg=0 (spawn #562528) 2025-09-05 22:17:31.935733 :C97F8A98:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:17:31.935733 :C97F8A99:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=35 time=1496303237 2025-09-05 22:17:31.935734 :C97F8A9A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:17:31.935734 :C97F8A9B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:17:31.935734 :C97F8A9C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:17:31.935734 :C97F8A9D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:17:31.935735 :C97F8A9E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:17:31.936208 :C97F8A9F: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-09-05 22:18:02.036970 :C97F94A0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:18:32.033676 :C97F9E80:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:18:32.022 2025-09-05 22:18:32.033678 :C97F9E81:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23988 pso_num=25 pso_serial#=178 2025-09-05 22:18:32.033812 :C97F9E82:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23988 osp_idx=23 osp_ver=282221 osp_pg=0 (spawn #562530) 2025-09-05 22:18:32.033812 :C97F9E83:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:18:32.033812 :C97F9E84:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=36 time=1496363330 2025-09-05 22:18:32.033813 :C97F9E85:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:18:32.033813 :C97F9E86:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:18:32.033813 :C97F9E87:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:18:32.033814 :C97F9E88:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:18:32.033814 :C97F9E89:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:18:32.034301 :C97F9E8A: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-09-05 22:19:02.119828 :C97FA895:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:19:32.118891 :C97FB279:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:19:32.107 2025-09-05 22:19:32.118894 :C97FB27A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16164 pso_num=25 pso_serial#=179 2025-09-05 22:19:32.119018 :C97FB27B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16164 osp_idx=23 osp_ver=282222 osp_pg=0 (spawn #562532) 2025-09-05 22:19:32.119019 :C97FB27C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:19:32.119019 :C97FB27D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=37 time=1496423424 2025-09-05 22:19:32.119020 :C97FB27E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:19:32.119020 :C97FB27F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:19:32.119021 :C97FB280:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:19:32.119022 :C97FB281:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:19:32.119022 :C97FB282:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:19:32.119488 :C97FB283: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-09-05 22:20:02.155366 :C97FBC52:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:20:18.903842 :C97FF85E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:20:18.895 2025-09-05 22:20:18.903844 :C97FF85F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14024 pso_num=25 pso_serial#=180 2025-09-05 22:20:18.903989 :C97FF860:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=14024 (legacy spawn) 2025-09-05 22:20:18.910524 :C97FF861: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-09-05 22:20:18.911096 :C97FF869: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-09-05 22:20:18.911998 :C97FF86B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:20:20.871990 :C97FFB9B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:20:20.865 2025-09-05 22:20:20.871992 :C97FFB9C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19576 pso_num=25 pso_serial#=181 2025-09-05 22:20:20.872274 :C97FFB9D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19576 osp_idx=23 osp_ver=282224 osp_pg=0 (spawn #562534) 2025-09-05 22:20:20.872275 :C97FFB9E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:20:20.872276 :C97FFB9F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=38 time=1496472158 2025-09-05 22:20:20.872276 :C97FFBA0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:20:20.872276 :C97FFBA1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:20:20.872277 :C97FFBA2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:20:20.872277 :C97FFBA3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:20:20.872277 :C97FFBA4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:20:20.873074 :C97FFBA5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-05 22:20:20.873119 :C97FFBAB:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-05 22:20:20.984093 :C97FFBE9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-09-05 22:20:22.200951 :C97FFC6F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 09-05 22:20:22.193 2025-09-05 22:20:22.200954 :C97FFC70:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20488 pso_num=25 pso_serial#=182 2025-09-05 22:20:22.201085 :C97FFC71:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20488 osp_idx=23 osp_ver=282225 osp_pg=0 (spawn #562536) 2025-09-05 22:20:22.201085 :C97FFC72:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 22:20:22.201086 :C97FFC73:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=39 time=1496473502 2025-09-05 22:20:22.201086 :C97FFC74:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 22:20:22.201087 :C97FFC75:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 22:20:22.201087 :C97FFC76:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 22:20:22.201087 :C97FFC77:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 22:20:22.201088 :C97FFC78:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 22:20:22.201580 :C97FFC79:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-05 22:20:22.201623 :C97FFC7F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 20488, M002)