Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250809220701\orcl_w000_21200_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:35648M/63366M, Ph+PgF:41115M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 21200, image: ORACLE.EXE (W000) *** 2025-08-09 22:07:01.104 *** SESSION ID:(177.1877) 2025-08-09 22:07:01.104 *** 2025-08-09 22:07:01.104 Process diagnostic dump for ORACLE.EXE (W000), OS id=21200, pid: 22, proc_ser: 47, sid: 177, sess_ser: 1877 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=182 seq_num=183 snap_id=1 wait times: snap=3.877507 sec, exc=3.877507 sec, total=3.877507 sec wait times: max=5.000000 sec, heur=4 min 54 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.000030 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=181 seq_num=182 snap_id=1 wait times: snap=5.003216 sec, exc=5.003216 sec, total=5.003216 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=180 seq_num=181 snap_id=1 wait times: snap=5.000421 sec, exc=5.000421 sec, total=5.000421 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=179 seq_num=180 snap_id=1 wait times: snap=5.014025 sec, exc=5.014025 sec, total=5.014025 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=178 seq_num=179 snap_id=1 wait times: snap=5.009208 sec, exc=5.009208 sec, total=5.009208 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=177 seq_num=178 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.000032 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=176 seq_num=177 snap_id=1 wait times: snap=5.015258 sec, exc=5.015258 sec, total=5.015258 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=175 seq_num=176 snap_id=1 wait times: snap=5.003205 sec, exc=5.003205 sec, total=5.003205 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=174 seq_num=175 snap_id=1 wait times: snap=5.000523 sec, exc=5.000523 sec, total=5.000523 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=173 seq_num=174 snap_id=1 wait times: snap=5.003012 sec, exc=5.003012 sec, total=5.003012 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=172 seq_num=173 snap_id=1 wait times: snap=5.000956 sec, exc=5.000956 sec, total=5.000956 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time Sampled Session History of session 177 serial 1877 --------------------------------------------------- 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, 22:05:01 - 22:07:01] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-09 22:07:01.104 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 21200, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-09 19:41:49.513319 :BD8E1895:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14108 pso_num=22 pso_serial#=33 2025-08-09 19:41:49.513462 :BD8E1896:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14108 osp_idx=0 osp_ver=497355 osp_pg=0 (spawn #472171) 2025-08-09 19:41:49.513463 :BD8E1897:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 19:41:49.513463 :BD8E1898:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=41 time=3449178814 2025-08-09 19:41:49.513464 :BD8E1899:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 19:41:49.513464 :BD8E189A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 19:41:49.513465 :BD8E189B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 19:41:49.513465 :BD8E189C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 19:41:49.513465 :BD8E189D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 19:41:49.513979 :BD8E189E: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-08-09 19:41:49.514023 :BD8E18A6: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-08-09 19:51:50.362390 :BD8EDB62:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 19:51:50.595419 :BD8EDB65:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 19:51:50.580 2025-08-09 19:51:50.595421 :BD8EDB66:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20664 pso_num=22 pso_serial#=34 2025-08-09 19:51:50.595581 :BD8EDB67:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20664 (legacy spawn) 2025-08-09 19:51:50.602461 :BD8EDB68:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-09 19:51:50.602666 :BD8EDB6E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-09 19:51:50.603580 :BD8EDB72:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 19:51:50.619967 :BD8EDB75:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 19:51:50.612 2025-08-09 19:51:50.619969 :BD8EDB76:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16248 pso_num=22 pso_serial#=35 2025-08-09 19:51:50.620115 :BD8EDB77:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=16248 (legacy spawn) 2025-08-09 19:51:50.626739 :BD8EDB78:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-09 19:51:50.626912 :BD8EDB81:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-09 19:51:50.627844 :BD8EDB82:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 19:51:50.695216 :BD8EDBBE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 19:51:50.690 2025-08-09 19:51:50.695218 :BD8EDBBF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21224 pso_num=22 pso_serial#=36 2025-08-09 19:51:50.695362 :BD8EDBC0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21224 osp_idx=0 osp_ver=497358 osp_pg=0 (spawn #472194) 2025-08-09 19:51:50.695362 :BD8EDBC1:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 19:51:50.695363 :BD8EDBC2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=42 time=3449780001 2025-08-09 19:51:50.695363 :BD8EDBC3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 19:51:50.695364 :BD8EDBC4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 19:51:50.695364 :BD8EDBC5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 19:51:50.695364 :BD8EDBC6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 19:51:50.695365 :BD8EDBC7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 19:51:50.695846 :BD8EDBC8: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-08-09 19:51:50.695890 :BD8EDBD0: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-08-09 19:55:09.940620 :BD8F1C1B: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-08-09 20:01:51.908379 :BD8F9E49: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-08-09 20:11:52.784297 :BD9069A9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 20:11:53.148386 :BD9069E0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 20:11:53.143 2025-08-09 20:11:53.148389 :BD9069E1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19756 pso_num=22 pso_serial#=37 2025-08-09 20:11:53.148526 :BD9069E2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19756 osp_idx=0 osp_ver=497359 osp_pg=0 (spawn #472242) 2025-08-09 20:11:53.148527 :BD9069E3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 20:11:53.148528 :BD9069E4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=43 time=3450982454 2025-08-09 20:11:53.148528 :BD9069E5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 20:11:53.148528 :BD9069E6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 20:11:53.148529 :BD9069E7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 20:11:53.148529 :BD9069E8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 20:11:53.148529 :BD9069E9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 20:11:53.149036 :BD9069EA: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-08-09 20:11:53.149084 :BD9069F4: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-08-09 20:21:54.006963 :BD912B04:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 20:21:54.334455 :BD912B4C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 20:21:54.329 2025-08-09 20:21:54.334457 :BD912B4D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21032 pso_num=22 pso_serial#=38 2025-08-09 20:21:54.334601 :BD912B4E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21032 osp_idx=0 osp_ver=497360 osp_pg=0 (spawn #472265) 2025-08-09 20:21:54.334602 :BD912B4F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 20:21:54.334602 :BD912B50:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=44 time=3451583642 2025-08-09 20:21:54.334603 :BD912B51:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 20:21:54.334603 :BD912B52:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 20:21:54.334604 :BD912B53:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 20:21:54.334604 :BD912B54:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 20:21:54.334604 :BD912B55:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 20:21:54.335112 :BD912B56: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-08-09 20:21:54.335159 :BD912B5D: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-08-09 20:31:55.152570 :BD91ED53:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 20:31:55.594859 :BD91ED89:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 20:31:55.590 2025-08-09 20:31:55.594861 :BD91ED8A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19496 pso_num=22 pso_serial#=39 2025-08-09 20:31:55.595008 :BD91ED8B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19496 osp_idx=0 osp_ver=497361 osp_pg=0 (spawn #472287) 2025-08-09 20:31:55.595008 :BD91ED8C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 20:31:55.595009 :BD91ED8D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=45 time=3452184908 2025-08-09 20:31:55.595009 :BD91ED8E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 20:31:55.595010 :BD91ED8F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 20:31:55.595010 :BD91ED90:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 20:31:55.595010 :BD91ED91:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 20:31:55.595011 :BD91ED92:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 20:31:55.595500 :BD91ED93: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-08-09 20:31:55.595546 :BD91ED9A: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-08-09 20:41:56.297014 :BD92AEFA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 20:41:56.801769 :BD92AF4B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 20:41:56.796 2025-08-09 20:41:56.801771 :BD92AF4C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20312 pso_num=22 pso_serial#=40 2025-08-09 20:41:56.801907 :BD92AF4D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20312 osp_idx=0 osp_ver=497362 osp_pg=0 (spawn #472310) 2025-08-09 20:41:56.801908 :BD92AF4E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 20:41:56.801908 :BD92AF4F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=46 time=3452786111 2025-08-09 20:41:56.801908 :BD92AF50:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 20:41:56.801909 :BD92AF51:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 20:41:56.801909 :BD92AF52:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 20:41:56.801909 :BD92AF53:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 20:41:56.801909 :BD92AF54:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 20:41:56.802388 :BD92AF55: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-08-09 20:41:56.802434 :BD92AF5F: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-08-09 20:51:57.696040 :BD93717B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 20:51:58.085950 :BD9371B1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 20:51:58.080 2025-08-09 20:51:58.085952 :BD9371B2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19792 pso_num=22 pso_serial#=41 2025-08-09 20:51:58.086093 :BD9371B3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19792 osp_idx=0 osp_ver=497363 osp_pg=0 (spawn #472333) 2025-08-09 20:51:58.086095 :BD9371B4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 20:51:58.086096 :BD9371B5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=47 time=3453387392 2025-08-09 20:51:58.086096 :BD9371B6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 20:51:58.086097 :BD9371B7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 20:51:58.086097 :BD9371B8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 20:51:58.086098 :BD9371B9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 20:51:58.086098 :BD9371BA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 20:51:58.086595 :BD9371BB: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-08-09 20:51:58.086641 :BD9371C3: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-08-09 21:01:58.955128 :BD943504:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 21:01:59.397392 :BD94353E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 21:01:59.392 2025-08-09 21:01:59.397395 :BD94353F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20596 pso_num=22 pso_serial#=42 2025-08-09 21:01:59.397540 :BD943540:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20596 osp_idx=0 osp_ver=497364 osp_pg=0 (spawn #472357) 2025-08-09 21:01:59.397541 :BD943541:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 21:01:59.397541 :BD943542:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=48 time=3453988704 2025-08-09 21:01:59.397542 :BD943543:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 21:01:59.397542 :BD943544:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 21:01:59.397542 :BD943545:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 21:01:59.397543 :BD943546:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 21:01:59.397543 :BD943547:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 21:01:59.398047 :BD943548: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-08-09 21:01:59.398096 :BD94354F: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-08-09 21:12:00.265086 :BD950059:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 21:12:00.816807 :BD95009E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 21:12:00.811 2025-08-09 21:12:00.816809 :BD95009F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19728 pso_num=22 pso_serial#=43 2025-08-09 21:12:00.816953 :BD9500A0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19728 osp_idx=0 osp_ver=497365 osp_pg=0 (spawn #472381) 2025-08-09 21:12:00.816953 :BD9500A1:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 21:12:00.816954 :BD9500A2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=49 time=3454590126 2025-08-09 21:12:00.816954 :BD9500A3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 21:12:00.816955 :BD9500A4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 21:12:00.816955 :BD9500A5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 21:12:00.816956 :BD9500A6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 21:12:00.816956 :BD9500A7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 21:12:00.817461 :BD9500A8: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-08-09 21:12:00.817506 :BD9500AF: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-08-09 21:22:01.656642 :BD95C2A6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 21:22:01.958180 :BD95C2DB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 21:22:01.953 2025-08-09 21:22:01.958182 :BD95C2DC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19060 pso_num=22 pso_serial#=44 2025-08-09 21:22:01.958326 :BD95C2DD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19060 osp_idx=0 osp_ver=497366 osp_pg=0 (spawn #472404) 2025-08-09 21:22:01.958327 :BD95C2DE:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 21:22:01.958327 :BD95C2DF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=50 time=3455191267 2025-08-09 21:22:01.958328 :BD95C2E0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 21:22:01.958328 :BD95C2E1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 21:22:01.958328 :BD95C2E2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 21:22:01.958329 :BD95C2E3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 21:22:01.958329 :BD95C2E4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 21:22:01.958834 :BD95C2E5: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-08-09 21:22:01.958879 :BD95C2ED: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-08-09 21:32:02.795183 :BD96843D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 21:32:03.128341 :BD968484:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 21:32:03.123 2025-08-09 21:32:03.128343 :BD968485:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20476 pso_num=22 pso_serial#=45 2025-08-09 21:32:03.128481 :BD968486:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20476 osp_idx=0 osp_ver=497367 osp_pg=0 (spawn #472426) 2025-08-09 21:32:03.128482 :BD968487:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 21:32:03.128482 :BD968488:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=51 time=3455792439 2025-08-09 21:32:03.128482 :BD968489:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 21:32:03.128483 :BD96848A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 21:32:03.128483 :BD96848B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 21:32:03.128484 :BD96848C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 21:32:03.128484 :BD96848D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 21:32:03.128976 :BD96848E: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-08-09 21:32:03.129022 :BD968495: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-08-09 21:42:04.002451 :BD974749:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 21:42:04.429181 :BD97477C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 21:42:04.424 2025-08-09 21:42:04.429183 :BD97477D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20556 pso_num=22 pso_serial#=46 2025-08-09 21:42:04.429328 :BD97477E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20556 osp_idx=0 osp_ver=497368 osp_pg=0 (spawn #472449) 2025-08-09 21:42:04.429329 :BD97477F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 21:42:04.429329 :BD974780:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=52 time=3456393736 2025-08-09 21:42:04.429329 :BD974781:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 21:42:04.429330 :BD974782:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 21:42:04.429330 :BD974783:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 21:42:04.429330 :BD974784:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 21:42:04.429331 :BD974785:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 21:42:04.429835 :BD974786: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-08-09 21:42:04.429885 :BD97478D: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-08-09 21:52:05.245493 :BD980B41:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-09 21:52:05.609749 :BD980B79:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-09 21:52:05.605 2025-08-09 21:52:05.609751 :BD980B7A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21200 pso_num=22 pso_serial#=47 2025-08-09 21:52:05.609892 :BD980B7B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21200 osp_idx=0 osp_ver=497369 osp_pg=0 (spawn #472472) 2025-08-09 21:52:05.609893 :BD980B7C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-09 21:52:05.609894 :BD980B7D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=53 time=3456994923 2025-08-09 21:52:05.609894 :BD980B7E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-09 21:52:05.609895 :BD980B7F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-09 21:52:05.609895 :BD980B80:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-09 21:52:05.609895 :BD980B81:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-09 21:52:05.609896 :BD980B82:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-09 21:52:05.610400 :BD980B83: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-08-09 21:52:05.610447 :BD980B8A: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-08-09 21:55:24.534892 :BD984C93: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-08-09 22:02:06.816360 :BD98D1E3: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-08-09 22:02:06.816409 :BD98D1E9:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-08-09 22:02:06.816441 :BD98D1EE:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-08-09 22:02:06.816442 :BD98D1EF:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=32, exc=32, tot=32 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 21200, W000)