Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510140049\orcl_w000_12600_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:37502M/63366M, Ph+PgF:44875M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 12600, image: ORACLE.EXE (W000) *** 2025-05-10 14:00:49.961 *** SESSION ID:(209.33011) 2025-05-10 14:00:49.961 *** 2025-05-10 14:00:49.961 Process diagnostic dump for ORACLE.EXE (W000), OS id=12600, pid: 26, proc_ser: 75, sid: 209, sess_ser: 33011 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=82 seq_num=83 snap_id=1 wait times: snap=0.151070 sec, exc=0.151070 sec, total=0.151070 sec wait times: max=5.000000 sec, heur=40.190865 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.000024 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=81 seq_num=82 snap_id=1 wait times: snap=5.004745 sec, exc=5.004745 sec, total=5.004745 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 1: 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.004546 sec, exc=5.004546 sec, total=5.004546 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 2: 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.004618 sec, exc=5.004618 sec, total=5.004618 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: 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.004658 sec, exc=5.004658 sec, total=5.004658 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 4: 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.004609 sec, exc=5.004609 sec, total=5.004609 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 5: 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.015251 sec, exc=5.015251 sec, total=5.015251 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: 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.003353 sec, exc=5.003353 sec, total=5.003353 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=74 seq_num=75 snap_id=1 wait times: snap=4.997824 sec, exc=4.997824 sec, total=4.997824 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.001790 sec of elapsed time 8: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x1, filetype=0x2 wait_id=73 seq_num=74 snap_id=1 wait times: snap=0.000151 sec, exc=0.000151 sec, total=0.000151 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000219 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=72 seq_num=73 snap_id=1 wait times: snap=1.180270 sec, exc=1.180270 sec, total=1.180270 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time Sampled Session History of session 209 serial 33011 --------------------------------------------------- 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, 13:58:49 - 14:00:49] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 14:00:49.961 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 12600, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 11:33:53.961985 :9533076C:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 11:33:53.961986 :9533076D:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 11:33:53.961986 :9533076E:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 11:33:53.962480 :9533076F: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-10 11:33:53.962523 :95330777: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-10 11:43:54.845060 :9533CB8C:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 11:43:55.250264 :9533CC18:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 11:43:55.245 2025-05-10 11:43:55.250266 :9533CC19:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=7964 pso_num=26 pso_serial#=62 2025-05-10 11:43:55.250399 :9533CC1A:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=7964 osp_idx=24 osp_ver=244861 osp_pg=0 (spawn #167619) 2025-05-10 11:43:55.250400 :9533CC1B: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-10 11:43:55.250401 :9533CC1C:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=249 time=4148212421 2025-05-10 11:43:55.250401 :9533CC1D:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 11:43:55.250401 :9533CC1E:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 11:43:55.250402 :9533CC1F:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 11:43:55.250402 :9533CC20:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 11:43:55.250403 :9533CC21:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 11:43:55.250887 :9533CC22: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-10 11:43:55.250930 :9533CC2A: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-10 11:53:56.109580 :95349016:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 11:53:56.692473 :953490B1:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 11:53:56.687 2025-05-10 11:53:56.692475 :953490B2:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11468 pso_num=26 pso_serial#=63 2025-05-10 11:53:56.692618 :953490B3:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11468 osp_idx=24 osp_ver=244862 osp_pg=0 (spawn #167642) 2025-05-10 11:53:56.692619 :953490B4: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-10 11:53:56.692619 :953490B5:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=250 time=4148813859 2025-05-10 11:53:56.692619 :953490B6:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 11:53:56.692620 :953490B7:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 11:53:56.692620 :953490B8:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 11:53:56.692621 :953490B9:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 11:53:56.692621 :953490BA:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 11:53:56.693114 :953490BB: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-10 11:53:56.693160 :953490C2: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-10 12:00:04.998677 :9535085E: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-10 12:03:58.003497 :9535565F: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-10 12:13:58.874901 :953622F9:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 12:13:59.395059 :9536236F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 12:13:59.390 2025-05-10 12:13:59.395061 :95362370:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10396 pso_num=26 pso_serial#=64 2025-05-10 12:13:59.395206 :95362371:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10396 osp_idx=24 osp_ver=244863 osp_pg=0 (spawn #167691) 2025-05-10 12:13:59.395207 :95362372: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-10 12:13:59.395207 :95362373:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=251 time=4150016562 2025-05-10 12:13:59.395208 :95362374:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 12:13:59.395208 :95362375:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 12:13:59.395208 :95362376:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 12:13:59.395209 :95362377:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 12:13:59.395209 :95362378:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 12:13:59.395710 :95362379: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-10 12:13:59.395759 :95362382: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-10 12:14:14.417927 :95362829:db_trace:ksl2.c@2477:kslwtbctx(): [10005:26:209] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-05-10 12:14:14.417974 :95362840:db_trace:ksl2.c@2611:kslwtectx(): [10005:26:209] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-05-10 12:14:14.417975 :95362841:db_trace:ksl2.c@2619:kslwtectx(): [10005:26:209] KSL WAIT END wait times (usecs) - snap=46, exc=46, tot=46 2025-05-10 12:24:00.194775 :9536E88F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 12:24:00.500890 :9536E892:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 12:24:00.487 2025-05-10 12:24:00.500892 :9536E893:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13056 pso_num=26 pso_serial#=65 2025-05-10 12:24:00.501023 :9536E894:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=13056 (legacy spawn) 2025-05-10 12:24:00.507488 :9536E895:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 12:24:00.507666 :9536E89A:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-10 12:24:00.508480 :9536E89F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 12:24:00.711309 :9536E90B:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 12:24:00.706 2025-05-10 12:24:00.711311 :9536E90C:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9672 pso_num=26 pso_serial#=66 2025-05-10 12:24:00.711445 :9536E90D:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9672 osp_idx=24 osp_ver=244865 osp_pg=0 (spawn #167714) 2025-05-10 12:24:00.711446 :9536E90E: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-10 12:24:00.711446 :9536E90F:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=252 time=4150617875 2025-05-10 12:24:00.711446 :9536E910:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 12:24:00.711447 :9536E911:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 12:24:00.711447 :9536E912:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 12:24:00.711447 :9536E913:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 12:24:00.711448 :9536E914:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 12:24:00.711934 :9536E915: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-10 12:24:00.711979 :9536E91D: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-10 12:34:01.652308 :9537ADE6:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 12:34:02.110212 :9537AE4B:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 12:34:02.105 2025-05-10 12:34:02.110214 :9537AE4C:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10700 pso_num=26 pso_serial#=67 2025-05-10 12:34:02.110350 :9537AE4D:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10700 osp_idx=24 osp_ver=244866 osp_pg=0 (spawn #167736) 2025-05-10 12:34:02.110351 :9537AE4E: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-10 12:34:02.110352 :9537AE4F:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=253 time=4151219281 2025-05-10 12:34:02.110352 :9537AE50:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 12:34:02.110353 :9537AE51:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 12:34:02.110353 :9537AE52:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 12:34:02.110353 :9537AE53:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 12:34:02.110353 :9537AE54:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 12:34:02.110848 :9537AE55: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-10 12:34:02.110893 :9537AE5C: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-10 12:44:03.026085 :9538739B:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 12:44:03.593211 :95387409:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 12:44:03.588 2025-05-10 12:44:03.593213 :9538740A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13260 pso_num=26 pso_serial#=68 2025-05-10 12:44:03.593350 :9538740B:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13260 osp_idx=24 osp_ver=244867 osp_pg=0 (spawn #167759) 2025-05-10 12:44:03.593351 :9538740C: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-10 12:44:03.593351 :9538740D:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=254 time=4151820765 2025-05-10 12:44:03.593352 :9538740E:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 12:44:03.593352 :9538740F:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 12:44:03.593353 :95387410:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 12:44:03.593353 :95387411:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 12:44:03.593353 :95387412:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 12:44:03.593846 :95387413: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-10 12:44:03.593889 :9538741B: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-10 12:54:04.599391 :953938BE:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 12:54:05.082962 :9539391F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 12:54:05.078 2025-05-10 12:54:05.082964 :95393920:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2752 pso_num=26 pso_serial#=69 2025-05-10 12:54:05.083096 :95393921:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2752 osp_idx=24 osp_ver=244868 osp_pg=0 (spawn #167782) 2025-05-10 12:54:05.083097 :95393922: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-10 12:54:05.083097 :95393923:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=255 time=4152422250 2025-05-10 12:54:05.083098 :95393924:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 12:54:05.083098 :95393925:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 12:54:05.083098 :95393926:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 12:54:05.083099 :95393927:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 12:54:05.083099 :95393928:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 12:54:05.083584 :95393929: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-10 12:54:05.083630 :95393930: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-10 13:04:05.962770 :953A0006:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 13:04:06.467601 :953A0084:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 13:04:06.463 2025-05-10 13:04:06.467604 :953A0085:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11496 pso_num=26 pso_serial#=70 2025-05-10 13:04:06.467740 :953A0086:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11496 osp_idx=24 osp_ver=244869 osp_pg=0 (spawn #167809) 2025-05-10 13:04:06.467741 :953A0087: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-10 13:04:06.467741 :953A0088:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=0 time=4153023640 2025-05-10 13:04:06.467742 :953A0089:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 13:04:06.467742 :953A008A:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 13:04:06.467742 :953A008B:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 13:04:06.467743 :953A008C:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 13:04:06.467743 :953A008D:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 13:04:06.468243 :953A008E: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-10 13:04:06.468295 :953A0095: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-10 13:14:07.359436 :953ACA99:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 13:14:07.864111 :953ACAFB:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 13:14:07.859 2025-05-10 13:14:07.864113 :953ACAFC:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11752 pso_num=26 pso_serial#=71 2025-05-10 13:14:07.864246 :953ACAFD:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11752 osp_idx=24 osp_ver=244870 osp_pg=0 (spawn #167832) 2025-05-10 13:14:07.864247 :953ACAFE: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-10 13:14:07.864247 :953ACAFF:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=1 time=4153625031 2025-05-10 13:14:07.864247 :953ACB00:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 13:14:07.864248 :953ACB01:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 13:14:07.864248 :953ACB02:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 13:14:07.864248 :953ACB03:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 13:14:07.864249 :953ACB04:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 13:14:07.864734 :953ACB05: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-10 13:14:07.864780 :953ACB0F: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-10 13:24:08.767832 :953B9249:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 13:24:09.241308 :953B92BD:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 13:24:09.236 2025-05-10 13:24:09.241310 :953B92BE:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11560 pso_num=26 pso_serial#=72 2025-05-10 13:24:09.241448 :953B92BF:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11560 osp_idx=24 osp_ver=244871 osp_pg=0 (spawn #167855) 2025-05-10 13:24:09.241449 :953B92C0: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-10 13:24:09.241449 :953B92C1:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=2 time=4154226406 2025-05-10 13:24:09.241450 :953B92C2:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 13:24:09.241450 :953B92C3:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 13:24:09.241450 :953B92C4:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 13:24:09.241451 :953B92C5:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 13:24:09.241451 :953B92C6:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 13:24:09.241951 :953B92C7: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-10 13:24:09.241996 :953B92CE: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-10 13:34:10.244532 :953C565D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 13:34:10.499322 :953C56C3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 13:34:10.495 2025-05-10 13:34:10.499324 :953C56C4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9028 pso_num=26 pso_serial#=73 2025-05-10 13:34:10.499465 :953C56C5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9028 osp_idx=24 osp_ver=244872 osp_pg=0 (spawn #167877) 2025-05-10 13:34:10.499465 :953C56C6: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-10 13:34:10.499466 :953C56C7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=3 time=4154827671 2025-05-10 13:34:10.499466 :953C56C8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 13:34:10.499467 :953C56C9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 13:34:10.499467 :953C56CA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 13:34:10.499467 :953C56CB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 13:34:10.499468 :953C56CC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 13:34:10.499969 :953C56CD: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-10 13:34:10.500012 :953C56D5: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-10 13:44:11.448107 :953D1AE4:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 13:44:11.843333 :953D1B53:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 13:44:11.838 2025-05-10 13:44:11.843335 :953D1B54:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=8400 pso_num=26 pso_serial#=74 2025-05-10 13:44:11.843467 :953D1B55:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=8400 osp_idx=24 osp_ver=244873 osp_pg=0 (spawn #167900) 2025-05-10 13:44:11.843468 :953D1B56: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-10 13:44:11.843468 :953D1B57:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=4 time=4155429015 2025-05-10 13:44:11.843468 :953D1B58:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 13:44:11.843469 :953D1B59:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 13:44:11.843469 :953D1B5A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 13:44:11.843469 :953D1B5B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 13:44:11.843470 :953D1B5C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 13:44:11.843979 :953D1B5D: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-10 13:44:11.844024 :953D1B65: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-10 13:54:12.799208 :953DDF86:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 13:54:13.079516 :953DDFE3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 13:54:13.075 2025-05-10 13:54:13.079519 :953DDFE4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12600 pso_num=26 pso_serial#=75 2025-05-10 13:54:13.079654 :953DDFE5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12600 osp_idx=24 osp_ver=244874 osp_pg=0 (spawn #167923) 2025-05-10 13:54:13.079654 :953DDFE6: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-10 13:54:13.079655 :953DDFE7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=5 time=4156030250 2025-05-10 13:54:13.079655 :953DDFE8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 13:54:13.079655 :953DDFE9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 13:54:13.079655 :953DDFEA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 13:54:13.079656 :953DDFEB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 13:54:13.079656 :953DDFEC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 13:54:13.080169 :953DDFED: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-10 13:54:13.080214 :953DDFF5: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-10 14:00:09.778077 :953E54CC: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 12600, W000)