Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250518140049\orcl_w000_13980_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:37403M/63366M, Ph+PgF:44614M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13980, image: ORACLE.EXE (W000) *** 2025-05-18 14:00:49.150 *** SESSION ID:(177.23617) 2025-05-18 14:00:49.150 *** 2025-05-18 14:00:49.150 Process diagnostic dump for ORACLE.EXE (W000), OS id=13980, pid: 22, proc_ser: 174, sid: 177, sess_ser: 23617 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=3.063884 sec, exc=3.063884 sec, total=3.063884 sec wait times: max=5.000000 sec, heur=53.151876 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.000025 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=5.014754 sec, exc=5.014754 sec, total=5.014754 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=5.014745 sec, exc=5.014745 sec, total=5.014745 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=5.010151 sec, exc=5.010151 sec, total=5.010151 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=7 seq_num=8 snap_id=1 wait times: snap=5.005022 sec, exc=5.005022 sec, total=5.005022 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=5.010521 sec, exc=5.010521 sec, total=5.010521 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=5.014745 sec, exc=5.014745 sec, total=5.014745 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=5.010148 sec, exc=5.010148 sec, total=5.010148 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=5.014739 sec, exc=5.014739 sec, total=5.014739 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=5.001742 sec, exc=5.001742 sec, total=5.001742 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=4.991181 sec, exc=4.991181 sec, total=4.991181 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.004111 sec of elapsed time Sampled Session History of session 177 serial 23617 --------------------------------------------------- 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 --------------------------------------------------- [54 samples, 13:59:56 - 14:00:49] idle wait at each sample [session created at: 13:59:56] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-18 14:00:49.150 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13980, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-18 11:19:34.506275 :98B66131:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 11:29:35.352491 :98B72C1B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 11:29:35.951054 :98B72C5E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 11:29:35.946 2025-05-18 11:29:35.951056 :98B72C5F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12820 pso_num=22 pso_serial#=161 2025-05-18 11:29:35.951192 :98B72C60:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12820 osp_idx=0 osp_ver=207221 osp_pg=0 (spawn #194381) 2025-05-18 11:29:35.951193 :98B72C61:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 11:29:35.951193 :98B72C62:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=126 time=543585829 2025-05-18 11:29:35.951194 :98B72C63:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 11:29:35.951194 :98B72C64:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 11:29:35.951194 :98B72C65:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 11:29:35.951195 :98B72C66:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 11:29:35.951195 :98B72C67:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 11:29:35.951696 :98B72C68:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 11:29:35.951743 :98B72C6F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 11:30:49.539954 :98B7452F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 11:39:37.388065 :98B7F67D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 11:49:38.266907 :98B8C0C0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 11:49:38.927582 :98B8C106:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 11:49:38.923 2025-05-18 11:49:38.927584 :98B8C107:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13836 pso_num=22 pso_serial#=162 2025-05-18 11:49:38.927718 :98B8C108:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13836 osp_idx=0 osp_ver=207222 osp_pg=0 (spawn #194425) 2025-05-18 11:49:38.927719 :98B8C109:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 11:49:38.927720 :98B8C10A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=127 time=544788797 2025-05-18 11:49:38.927720 :98B8C10B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 11:49:38.927720 :98B8C10C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 11:49:38.927721 :98B8C10D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 11:49:38.927721 :98B8C10E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 11:49:38.927721 :98B8C10F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 11:49:38.928212 :98B8C110:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 11:49:38.928259 :98B8C117:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 11:59:39.902879 :98B98AC2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 11:59:40.261339 :98B98AFA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 11:59:40.256 2025-05-18 11:59:40.261341 :98B98AFB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10904 pso_num=22 pso_serial#=163 2025-05-18 11:59:40.261480 :98B98AFC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10904 osp_idx=0 osp_ver=207223 osp_pg=0 (spawn #194448) 2025-05-18 11:59:40.261481 :98B98AFD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 11:59:40.261482 :98B98AFE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=128 time=545390125 2025-05-18 11:59:40.261482 :98B98AFF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 11:59:40.261482 :98B98B00:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 11:59:40.261483 :98B98B01:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 11:59:40.261483 :98B98B02:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 11:59:40.261484 :98B98B03:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 11:59:40.261984 :98B98B04:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 11:59:40.262038 :98B98B0E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 12:09:41.229591 :98BA6167:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 12:09:41.702997 :98BA61D5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 12:09:41.698 2025-05-18 12:09:41.702999 :98BA61D6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8444 pso_num=22 pso_serial#=164 2025-05-18 12:09:41.703127 :98BA61D7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8444 osp_idx=0 osp_ver=207224 osp_pg=0 (spawn #194474) 2025-05-18 12:09:41.703127 :98BA61D8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 12:09:41.703128 :98BA61D9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=129 time=545991579 2025-05-18 12:09:41.703128 :98BA61DA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 12:09:41.703129 :98BA61DB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 12:09:41.703129 :98BA61DC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 12:09:41.703129 :98BA61DD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 12:09:41.703130 :98BA61DE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 12:09:41.703679 :98BA61DF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 12:09:41.703724 :98BA61E7:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 12:19:42.573592 :98BB2BBC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 12:19:43.000135 :98BB2C1F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 12:19:42.995 2025-05-18 12:19:43.000137 :98BB2C20:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13936 pso_num=22 pso_serial#=165 2025-05-18 12:19:43.000277 :98BB2C21:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13936 osp_idx=0 osp_ver=207225 osp_pg=0 (spawn #194496) 2025-05-18 12:19:43.000277 :98BB2C22:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 12:19:43.000278 :98BB2C23:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=130 time=546592875 2025-05-18 12:19:43.000278 :98BB2C24:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 12:19:43.000279 :98BB2C25:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 12:19:43.000279 :98BB2C26:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 12:19:43.000279 :98BB2C27:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 12:19:43.000280 :98BB2C28:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 12:19:43.000776 :98BB2C29:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 12:19:43.000818 :98BB2C31:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 12:29:43.926780 :98BBF691:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 12:29:44.338795 :98BBF6FF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 12:29:44.334 2025-05-18 12:29:44.338797 :98BBF700:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11304 pso_num=22 pso_serial#=166 2025-05-18 12:29:44.338933 :98BBF701:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11304 osp_idx=0 osp_ver=207226 osp_pg=0 (spawn #194519) 2025-05-18 12:29:44.338934 :98BBF702:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 12:29:44.338935 :98BBF703:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=131 time=547194204 2025-05-18 12:29:44.338935 :98BBF704:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 12:29:44.338935 :98BBF705:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 12:29:44.338936 :98BBF706:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 12:29:44.338936 :98BBF707:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 12:29:44.338936 :98BBF708:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 12:29:44.339469 :98BBF709:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 12:29:44.339520 :98BBF712:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 12:39:45.336932 :98BCC109:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 12:39:45.576017 :98BCC155:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 12:39:45.571 2025-05-18 12:39:45.576019 :98BCC156:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12128 pso_num=22 pso_serial#=167 2025-05-18 12:39:45.576156 :98BCC157:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12128 osp_idx=0 osp_ver=207227 osp_pg=0 (spawn #194542) 2025-05-18 12:39:45.576157 :98BCC158:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 12:39:45.576158 :98BCC159:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=132 time=547795454 2025-05-18 12:39:45.576158 :98BCC15A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 12:39:45.576159 :98BCC15B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 12:39:45.576159 :98BCC15C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 12:39:45.576159 :98BCC15D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 12:39:45.576160 :98BCC15E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 12:39:45.576714 :98BCC15F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 12:39:45.576761 :98BCC166:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 12:49:46.516302 :98BD8B9D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 12:49:46.802335 :98BD8BD6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 12:49:46.797 2025-05-18 12:49:46.802337 :98BD8BD7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12724 pso_num=22 pso_serial#=168 2025-05-18 12:49:46.802479 :98BD8BD8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12724 osp_idx=0 osp_ver=207228 osp_pg=0 (spawn #194564) 2025-05-18 12:49:46.802479 :98BD8BD9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 12:49:46.802480 :98BD8BDA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=133 time=548396672 2025-05-18 12:49:46.802481 :98BD8BDB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 12:49:46.802481 :98BD8BDC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 12:49:46.802482 :98BD8BDD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 12:49:46.802482 :98BD8BDE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 12:49:46.802482 :98BD8BDF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 12:49:46.802980 :98BD8BE0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 12:49:46.803024 :98BD8BE7:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 12:59:47.642003 :98BE55ED:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 12:59:48.037376 :98BE5626:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 12:59:48.038 2025-05-18 12:59:48.037378 :98BE5627:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12508 pso_num=22 pso_serial#=169 2025-05-18 12:59:48.037513 :98BE5628:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12508 osp_idx=0 osp_ver=207229 osp_pg=0 (spawn #194587) 2025-05-18 12:59:48.037513 :98BE5629:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 12:59:48.037514 :98BE562A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=134 time=548997907 2025-05-18 12:59:48.037515 :98BE562B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 12:59:48.037515 :98BE562C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 12:59:48.037515 :98BE562D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 12:59:48.037516 :98BE562E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 12:59:48.037516 :98BE562F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 12:59:48.038005 :98BE5630:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 12:59:48.038049 :98BE5636:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 13:09:48.971673 :98BF2DC2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 13:09:49.367185 :98BF2E06:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 13:09:49.363 2025-05-18 13:09:49.367187 :98BF2E07:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6552 pso_num=22 pso_serial#=170 2025-05-18 13:09:49.367325 :98BF2E08:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6552 osp_idx=0 osp_ver=207230 osp_pg=0 (spawn #194614) 2025-05-18 13:09:49.367326 :98BF2E09:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 13:09:49.367326 :98BF2E0A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=135 time=549599235 2025-05-18 13:09:49.367327 :98BF2E0B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 13:09:49.367327 :98BF2E0C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 13:09:49.367327 :98BF2E0D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 13:09:49.367327 :98BF2E0E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 13:09:49.367328 :98BF2E0F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 13:09:49.367824 :98BF2E10:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 13:09:49.367867 :98BF2E18:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 13:19:50.427916 :98BFFAA4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 13:19:50.729389 :98BFFAE0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 13:19:50.724 2025-05-18 13:19:50.729391 :98BFFAE1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13736 pso_num=22 pso_serial#=171 2025-05-18 13:19:50.729529 :98BFFAE2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13736 osp_idx=0 osp_ver=207231 osp_pg=0 (spawn #194636) 2025-05-18 13:19:50.729531 :98BFFAE3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 13:19:50.729531 :98BFFAE4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=136 time=550200594 2025-05-18 13:19:50.729531 :98BFFAE5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 13:19:50.729532 :98BFFAE6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 13:19:50.729532 :98BFFAE7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 13:19:50.729533 :98BFFAE8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 13:19:50.729533 :98BFFAE9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 13:19:50.730028 :98BFFAEA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 13:19:50.730070 :98BFFAF2:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 13:29:51.738864 :98C0CA14:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 13:29:52.046182 :98C0CA5A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 13:29:52.041 2025-05-18 13:29:52.046185 :98C0CA5B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10624 pso_num=22 pso_serial#=172 2025-05-18 13:29:52.046334 :98C0CA5C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10624 osp_idx=0 osp_ver=207232 osp_pg=0 (spawn #194659) 2025-05-18 13:29:52.046334 :98C0CA5D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 13:29:52.046335 :98C0CA5E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=137 time=550801922 2025-05-18 13:29:52.046335 :98C0CA5F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 13:29:52.046336 :98C0CA60:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 13:29:52.046336 :98C0CA61:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 13:29:52.046336 :98C0CA62:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 13:29:52.046337 :98C0CA63:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 13:29:52.046928 :98C0CA64:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 13:29:52.046998 :98C0CA6E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 13:35:28.936124 :98C13E34:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 13:39:53.384600 :98C19796:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 13:49:54.276174 :98C26435:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 13:49:54.624523 :98C26479:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 13:49:54.620 2025-05-18 13:49:54.624526 :98C2647A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14164 pso_num=22 pso_serial#=173 2025-05-18 13:49:54.624657 :98C2647B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14164 osp_idx=0 osp_ver=207233 osp_pg=0 (spawn #194703) 2025-05-18 13:49:54.624658 :98C2647C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 13:49:54.624659 :98C2647D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=138 time=552004500 2025-05-18 13:49:54.624659 :98C2647E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 13:49:54.624659 :98C2647F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 13:49:54.624660 :98C26480:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 13:49:54.624660 :98C26481:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 13:49:54.624660 :98C26482:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 13:49:54.625137 :98C26483:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 13:49:54.625181 :98C2648A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-18 13:59:55.542039 :98C3302B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 13:59:56.000117 :98C33078:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 13:59:55.995 2025-05-18 13:59:56.000119 :98C33079:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13980 pso_num=22 pso_serial#=174 2025-05-18 13:59:56.000258 :98C3307A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13980 osp_idx=0 osp_ver=207234 osp_pg=0 (spawn #194726) 2025-05-18 13:59:56.000259 :98C3307B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 13:59:56.000259 :98C3307C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=139 time=552605875 2025-05-18 13:59:56.000260 :98C3307D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 13:59:56.000260 :98C3307E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 13:59:56.000261 :98C3307F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 13:59:56.000261 :98C33080:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 13:59:56.000262 :98C33081:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 13:59:56.000779 :98C33082:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 13:59:56.000831 :98C33089:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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 22 (osid: 13980, W000)