Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250511180436\orcl_w000_13196_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:37473M/63366M, Ph+PgF:44819M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 13196, image: ORACLE.EXE (W000) *** 2025-05-11 18:04:36.380 *** SESSION ID:(209.37541) 2025-05-11 18:04:36.380 *** 2025-05-11 18:04:36.380 Process diagnostic dump for ORACLE.EXE (W000), OS id=13196, pid: 26, proc_ser: 8, sid: 209, sess_ser: 37541 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=81 seq_num=82 snap_id=1 wait times: snap=1.368632 sec, exc=1.368632 sec, total=1.368632 sec wait times: max=5.000000 sec, heur=6 min 41 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.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=80 seq_num=81 snap_id=1 wait times: snap=5.012273 sec, exc=5.012273 sec, total=5.012273 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=79 seq_num=80 snap_id=1 wait times: snap=5.012050 sec, exc=5.012050 sec, total=5.012050 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=78 seq_num=79 snap_id=1 wait times: snap=5.012653 sec, exc=5.012653 sec, total=5.012653 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.004625 sec, exc=5.004625 sec, total=5.004625 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=76 seq_num=77 snap_id=1 wait times: snap=5.014724 sec, exc=5.014724 sec, total=5.014724 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=75 seq_num=76 snap_id=1 wait times: snap=5.010141 sec, exc=5.010141 sec, total=5.010141 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=74 seq_num=75 snap_id=1 wait times: snap=5.008320 sec, exc=5.008320 sec, total=5.008320 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=73 seq_num=74 snap_id=1 wait times: snap=5.012305 sec, exc=5.012305 sec, total=5.012305 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=72 seq_num=73 snap_id=1 wait times: snap=5.008773 sec, exc=5.008773 sec, total=5.008773 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=71 seq_num=72 snap_id=1 wait times: snap=5.004640 sec, exc=5.004640 sec, total=5.004640 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time Sampled Session History of session 209 serial 37541 --------------------------------------------------- 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 --------------------------------------------------- [121 samples, 18:02:36 - 18:04:36] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-11 18:04:36.380 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 13196, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-11 15:27:34.730606 :95B4B4BF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 15:27:34.730606 :95B4B4C0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 15:27:34.731096 :95B4B4C1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 15:27:34.731165 :95B4B4CB:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 15:37:35.669311 :95B578A1:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 15:37:35.955214 :95B578FE:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 15:37:35.950 2025-05-11 15:37:35.955216 :95B578FF:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10912 pso_num=26 pso_serial#=250 2025-05-11 15:37:35.955352 :95B57900:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10912 osp_idx=24 osp_ver=247089 osp_pg=0 (spawn #171571) 2025-05-11 15:37:35.955352 :95B57901:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 15:37:35.955353 :95B57902:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=8 time=4248633125 2025-05-11 15:37:35.955353 :95B57903:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 15:37:35.955353 :95B57904:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 15:37:35.955354 :95B57905:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 15:37:35.955354 :95B57906:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 15:37:35.955354 :95B57907:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 15:37:35.955841 :95B57908:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 15:37:35.955884 :95B57910:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 15:47:36.869469 :95B63D67:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 15:47:37.203433 :95B63DB5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 15:47:37.199 2025-05-11 15:47:37.203436 :95B63DB6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12536 pso_num=26 pso_serial#=251 2025-05-11 15:47:37.203620 :95B63DB7:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12536 osp_idx=24 osp_ver=247090 osp_pg=0 (spawn #171594) 2025-05-11 15:47:37.203621 :95B63DB8:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 15:47:37.203622 :95B63DB9:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=9 time=4249234375 2025-05-11 15:47:37.203622 :95B63DBA:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 15:47:37.203622 :95B63DBB:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 15:47:37.203623 :95B63DBC:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 15:47:37.203623 :95B63DBD:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 15:47:37.203623 :95B63DBE:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 15:47:37.204139 :95B63DBF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 15:47:37.204198 :95B63DC5:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 15:57:38.121968 :95B700D8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 15:57:38.523758 :95B70140:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 15:57:38.524 2025-05-11 15:57:38.523761 :95B70141:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=4856 pso_num=26 pso_serial#=252 2025-05-11 15:57:38.523905 :95B70142:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=4856 osp_idx=24 osp_ver=247091 osp_pg=0 (spawn #171617) 2025-05-11 15:57:38.523906 :95B70143:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 15:57:38.523907 :95B70144:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=10 time=4249835687 2025-05-11 15:57:38.523907 :95B70145:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 15:57:38.523908 :95B70146:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 15:57:38.523908 :95B70147:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 15:57:38.523908 :95B70148:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 15:57:38.523909 :95B70149:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 15:57:38.524422 :95B7014A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 15:57:38.524468 :95B70152:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 16:07:39.470949 :95B7CF78:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 16:07:39.756900 :95B7CFCB:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 16:07:39.752 2025-05-11 16:07:39.756902 :95B7CFCC:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12580 pso_num=26 pso_serial#=253 2025-05-11 16:07:39.757045 :95B7CFCD:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12580 osp_idx=24 osp_ver=247092 osp_pg=0 (spawn #171645) 2025-05-11 16:07:39.757045 :95B7CFCE:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 16:07:39.757046 :95B7CFCF:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=11 time=4250436921 2025-05-11 16:07:39.757046 :95B7CFD0:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 16:07:39.757047 :95B7CFD1:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 16:07:39.757047 :95B7CFD2:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 16:07:39.757047 :95B7CFD3:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 16:07:39.757048 :95B7CFD4:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 16:07:39.757552 :95B7CFD5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 16:07:39.757608 :95B7CFDB:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 16:17:40.681446 :95B895AA:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 16:17:40.998789 :95B89619:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 16:17:40.994 2025-05-11 16:17:40.998791 :95B8961A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9288 pso_num=26 pso_serial#=254 2025-05-11 16:17:40.998926 :95B8961B:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9288 osp_idx=24 osp_ver=247093 osp_pg=0 (spawn #171668) 2025-05-11 16:17:40.998926 :95B8961C:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 16:17:40.998926 :95B8961D:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=12 time=4251038171 2025-05-11 16:17:40.998927 :95B8961E:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 16:17:40.998927 :95B8961F:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 16:17:40.998928 :95B89620:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 16:17:40.998928 :95B89621:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 16:17:40.998928 :95B89622:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 16:17:40.999422 :95B89623:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 16:17:40.999467 :95B8962C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 16:27:41.920579 :95B958E3:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 16:27:42.268984 :95B9596D:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 16:27:42.264 2025-05-11 16:27:42.268985 :95B9596E:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12516 pso_num=26 pso_serial#=255 2025-05-11 16:27:42.269119 :95B9596F:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12516 osp_idx=24 osp_ver=247094 osp_pg=0 (spawn #171691) 2025-05-11 16:27:42.269120 :95B95970:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 16:27:42.269120 :95B95971:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=13 time=4251639437 2025-05-11 16:27:42.269120 :95B95972:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 16:27:42.269121 :95B95973:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 16:27:42.269121 :95B95974:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 16:27:42.269121 :95B95975:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 16:27:42.269122 :95B95976:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 16:27:42.269668 :95B95977:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 16:27:42.269714 :95B95981:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 16:30:33.875812 :95B991DB:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-11 16:37:43.498373 :95BA1D82:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-11 16:47:44.393671 :95BAE01A:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 16:47:44.819971 :95BAE06F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 16:47:44.815 2025-05-11 16:47:44.819973 :95BAE070:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=8164 pso_num=26 pso_serial#=1 2025-05-11 16:47:44.820113 :95BAE071:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=8164 osp_idx=24 osp_ver=247095 osp_pg=0 (spawn #171735) 2025-05-11 16:47:44.820114 :95BAE072:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 16:47:44.820114 :95BAE073:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=14 time=4252841984 2025-05-11 16:47:44.820115 :95BAE074:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 16:47:44.820115 :95BAE075:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 16:47:44.820116 :95BAE076:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 16:47:44.820116 :95BAE077:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 16:47:44.820116 :95BAE078:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 16:47:44.820617 :95BAE079:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 16:47:44.820660 :95BAE081:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 16:57:45.702852 :95BBA3F0:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 16:57:46.061363 :95BBA434:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 16:57:46.057 2025-05-11 16:57:46.061366 :95BBA435:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10024 pso_num=26 pso_serial#=2 2025-05-11 16:57:46.061507 :95BBA436:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10024 osp_idx=24 osp_ver=247096 osp_pg=0 (spawn #171758) 2025-05-11 16:57:46.061507 :95BBA437:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 16:57:46.061508 :95BBA438:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=15 time=4253443234 2025-05-11 16:57:46.061508 :95BBA439:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 16:57:46.061509 :95BBA43A:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 16:57:46.061509 :95BBA43B:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 16:57:46.061509 :95BBA43C:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 16:57:46.061510 :95BBA43D:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 16:57:46.062024 :95BBA43E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 16:57:46.062069 :95BBA446:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 17:07:47.053515 :95BC7011:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 17:07:47.448944 :95BC7054:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 17:07:47.444 2025-05-11 17:07:47.448947 :95BC7055:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12628 pso_num=26 pso_serial#=3 2025-05-11 17:07:47.449090 :95BC7056:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12628 osp_idx=24 osp_ver=247097 osp_pg=0 (spawn #171785) 2025-05-11 17:07:47.449091 :95BC7057:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 17:07:47.449091 :95BC7058:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=16 time=4254044609 2025-05-11 17:07:47.449092 :95BC7059:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 17:07:47.449092 :95BC705A:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 17:07:47.449093 :95BC705B:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 17:07:47.449093 :95BC705C:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 17:07:47.449093 :95BC705D:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 17:07:47.449624 :95BC705E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 17:07:47.449675 :95BC7065:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 17:17:48.401524 :95BD366D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 17:17:48.749932 :95BD36B5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 17:17:48.745 2025-05-11 17:17:48.749936 :95BD36B6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9980 pso_num=26 pso_serial#=4 2025-05-11 17:17:48.750078 :95BD36B7:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9980 osp_idx=24 osp_ver=247098 osp_pg=0 (spawn #171808) 2025-05-11 17:17:48.750079 :95BD36B8:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 17:17:48.750079 :95BD36B9:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=17 time=4254645921 2025-05-11 17:17:48.750080 :95BD36BA:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 17:17:48.750080 :95BD36BB:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 17:17:48.750080 :95BD36BC:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 17:17:48.750080 :95BD36BD:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 17:17:48.750080 :95BD36BE:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 17:17:48.750578 :95BD36BF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 17:17:48.750622 :95BD36C6:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 17:27:49.611820 :95BDF9B0:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 17:27:50.132053 :95BDF9F3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 17:27:50.128 2025-05-11 17:27:50.132055 :95BDF9F4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12708 pso_num=26 pso_serial#=5 2025-05-11 17:27:50.132187 :95BDF9F5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12708 osp_idx=24 osp_ver=247099 osp_pg=0 (spawn #171831) 2025-05-11 17:27:50.132187 :95BDF9F6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 17:27:50.132188 :95BDF9F7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=18 time=4255247296 2025-05-11 17:27:50.132188 :95BDF9F8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 17:27:50.132188 :95BDF9F9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 17:27:50.132189 :95BDF9FA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 17:27:50.132189 :95BDF9FB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 17:27:50.132189 :95BDF9FC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 17:27:50.132736 :95BDF9FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 17:27:50.132793 :95BDFA04:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 17:37:50.987075 :95BEBD8B:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 17:37:51.523114 :95BEBDDF:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 17:37:51.518 2025-05-11 17:37:51.523116 :95BEBDE0:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12356 pso_num=26 pso_serial#=6 2025-05-11 17:37:51.523256 :95BEBDE1:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12356 osp_idx=24 osp_ver=247100 osp_pg=0 (spawn #171853) 2025-05-11 17:37:51.523256 :95BEBDE2:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 17:37:51.523257 :95BEBDE3:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=19 time=4255848687 2025-05-11 17:37:51.523257 :95BEBDE4:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 17:37:51.523258 :95BEBDE5:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 17:37:51.523258 :95BEBDE6:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 17:37:51.523259 :95BEBDE7:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 17:37:51.523259 :95BEBDE8:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 17:37:51.523774 :95BEBDE9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 17:37:51.523820 :95BEBDF0:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 17:47:52.415703 :95BF800F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 17:47:52.982943 :95BF8063:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 17:47:52.978 2025-05-11 17:47:52.982946 :95BF8064:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11240 pso_num=26 pso_serial#=7 2025-05-11 17:47:52.983087 :95BF8065:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11240 osp_idx=24 osp_ver=247101 osp_pg=0 (spawn #171876) 2025-05-11 17:47:52.983087 :95BF8066:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 17:47:52.983088 :95BF8067:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=20 time=4256450156 2025-05-11 17:47:52.983088 :95BF8068:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 17:47:52.983088 :95BF8069:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 17:47:52.983089 :95BF806A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 17:47:52.983089 :95BF806B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 17:47:52.983089 :95BF806C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 17:47:52.983591 :95BF806D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 17:47:52.983639 :95BF8075:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 17:57:53.817184 :95C04392:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-11 17:57:54.416776 :95C043D5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-11 17:57:54.412 2025-05-11 17:57:54.416778 :95C043D6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13196 pso_num=26 pso_serial#=8 2025-05-11 17:57:54.416914 :95C043D7:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13196 osp_idx=24 osp_ver=247102 osp_pg=0 (spawn #171900) 2025-05-11 17:57:54.416915 :95C043D8:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 17:57:54.416916 :95C043D9:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=21 time=4257051578 2025-05-11 17:57:54.416916 :95C043DA:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 17:57:54.416917 :95C043DB:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 17:57:54.416918 :95C043DC:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 17:57:54.416919 :95C043DD:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 17:57:54.416919 :95C043DE:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 17:57:54.417410 :95C043DF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 17:57:54.417455 :95C043E6:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 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 26 (osid: 13196, W000)