Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250514080149\orcl_w000_12592_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:37396M/63366M, Ph+PgF:44666M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 12592, image: ORACLE.EXE (W000) *** 2025-05-14 08:01:49.875 *** SESSION ID:(177.48981) 2025-05-14 08:01:49.875 *** 2025-05-14 08:01:49.875 Process diagnostic dump for ORACLE.EXE (W000), OS id=12592, pid: 22, proc_ser: 108, sid: 177, sess_ser: 48981 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=68 seq_num=69 snap_id=1 wait times: snap=2.102210 sec, exc=2.102210 sec, total=2.102210 sec wait times: max=5.000000 sec, heur=5 min 37 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=67 seq_num=68 snap_id=1 wait times: snap=5.007691 sec, exc=5.007691 sec, total=5.007691 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000044 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=66 seq_num=67 snap_id=1 wait times: snap=5.007729 sec, exc=5.007729 sec, total=5.007729 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=65 seq_num=66 snap_id=1 wait times: snap=5.014760 sec, exc=5.014760 sec, total=5.014760 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=64 seq_num=65 snap_id=1 wait times: snap=5.004629 sec, exc=5.004629 sec, total=5.004629 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=63 seq_num=64 snap_id=1 wait times: snap=5.014723 sec, exc=5.014723 sec, total=5.014723 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=62 seq_num=63 snap_id=1 wait times: snap=5.015240 sec, exc=5.015240 sec, total=5.015240 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=61 seq_num=62 snap_id=1 wait times: snap=5.013606 sec, exc=5.013606 sec, total=5.013606 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=60 seq_num=61 snap_id=1 wait times: snap=5.011773 sec, exc=5.011773 sec, total=5.011773 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=59 seq_num=60 snap_id=1 wait times: snap=5.009476 sec, exc=5.009476 sec, total=5.009476 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=58 seq_num=59 snap_id=1 wait times: snap=5.004614 sec, exc=5.004614 sec, total=5.004614 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 177 serial 48981 --------------------------------------------------- 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, 07:59:49 - 08:01:49] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-14 08:01:49.875 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 12592, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-14 05:25:52.818884 :96D36F70:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=245 time=176162688 2025-05-14 05:25:52.818884 :96D36F71:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 05:25:52.818885 :96D36F72:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 05:25:52.818885 :96D36F73:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 05:25:52.818885 :96D36F74:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 05:25:52.818886 :96D36F75:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 05:25:52.819385 :96D36F76: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-14 05:25:52.819431 :96D36F7E: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-14 05:35:53.699029 :96D43017:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 05:35:54.109962 :96D4305B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 05:35:54.105 2025-05-14 05:35:54.109963 :96D4305C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8612 pso_num=22 pso_serial#=95 2025-05-14 05:35:54.110102 :96D4305D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8612 osp_idx=0 osp_ver=190070 osp_pg=0 (spawn #180211) 2025-05-14 05:35:54.110103 :96D4305E: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-14 05:35:54.110103 :96D4305F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=246 time=176763985 2025-05-14 05:35:54.110104 :96D43060:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 05:35:54.110104 :96D43061:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 05:35:54.110104 :96D43062:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 05:35:54.110105 :96D43063:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 05:35:54.110105 :96D43064:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 05:35:54.110603 :96D43065: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-14 05:35:54.110649 :96D4306C: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-14 05:40:40.270723 :96D48C8C: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-14 05:45:55.352951 :96D4F253: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-14 05:55:56.238295 :96D5B422:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 05:55:56.251171 :96D5B43F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 05:55:56.238 2025-05-14 05:55:56.251172 :96D5B440:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2860 pso_num=22 pso_serial#=96 2025-05-14 05:55:56.251354 :96D5B441:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=2860 (legacy spawn) 2025-05-14 05:55:56.257868 :96D5B442: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-05-14 05:55:56.258044 :96D5B44B: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-05-14 05:55:56.258847 :96D5B44C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 05:55:56.617592 :96D5B490:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 05:55:56.613 2025-05-14 05:55:56.617594 :96D5B491:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13144 pso_num=22 pso_serial#=97 2025-05-14 05:55:56.617729 :96D5B492:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13144 osp_idx=0 osp_ver=190072 osp_pg=0 (spawn #180256) 2025-05-14 05:55:56.617730 :96D5B493: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-14 05:55:56.617730 :96D5B494:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=247 time=177966485 2025-05-14 05:55:56.617730 :96D5B495:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 05:55:56.617731 :96D5B496:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 05:55:56.617731 :96D5B497:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 05:55:56.617732 :96D5B498:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 05:55:56.617732 :96D5B499:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 05:55:56.618243 :96D5B49A: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-14 05:55:56.618292 :96D5B4A2: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-14 06:05:57.486757 :96D6824A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 06:05:57.819511 :96D6827F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 06:05:57.815 2025-05-14 06:05:57.819513 :96D68280:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12148 pso_num=22 pso_serial#=98 2025-05-14 06:05:57.819655 :96D68281:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12148 osp_idx=0 osp_ver=190073 osp_pg=0 (spawn #180281) 2025-05-14 06:05:57.819655 :96D68282: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-14 06:05:57.819656 :96D68283:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=248 time=178567688 2025-05-14 06:05:57.819656 :96D68284:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 06:05:57.819657 :96D68285:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 06:05:57.819657 :96D68286:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 06:05:57.819657 :96D68287:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 06:05:57.819658 :96D68288:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 06:05:57.820151 :96D68289: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-14 06:05:57.820199 :96D68290: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-14 06:15:58.700524 :96D743D2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 06:15:59.236528 :96D7441C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 06:15:59.231 2025-05-14 06:15:59.236530 :96D7441D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12604 pso_num=22 pso_serial#=99 2025-05-14 06:15:59.236665 :96D7441E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12604 osp_idx=0 osp_ver=190074 osp_pg=0 (spawn #180304) 2025-05-14 06:15:59.236666 :96D7441F: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-14 06:15:59.236666 :96D74420:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=249 time=179169110 2025-05-14 06:15:59.236667 :96D74421:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 06:15:59.236667 :96D74422:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 06:15:59.236667 :96D74423:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 06:15:59.236667 :96D74424:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 06:15:59.236668 :96D74425:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 06:15:59.237155 :96D74426: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-14 06:15:59.237199 :96D7442D: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-14 06:26:00.185434 :96D80498:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 06:26:00.487060 :96D804D2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 06:26:00.482 2025-05-14 06:26:00.487062 :96D804D3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2196 pso_num=22 pso_serial#=100 2025-05-14 06:26:00.487199 :96D804D4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2196 osp_idx=0 osp_ver=190075 osp_pg=0 (spawn #180327) 2025-05-14 06:26:00.487200 :96D804D5: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-14 06:26:00.487200 :96D804D6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=250 time=179770360 2025-05-14 06:26:00.487200 :96D804D7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 06:26:00.487201 :96D804D8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 06:26:00.487201 :96D804D9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 06:26:00.487201 :96D804DA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 06:26:00.487202 :96D804DB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 06:26:00.487703 :96D804DC: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-14 06:26:00.487749 :96D804E3: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-14 06:36:01.389301 :96D8C5F1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 06:36:01.815884 :96D8C636:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 06:36:01.811 2025-05-14 06:36:01.815886 :96D8C637:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10020 pso_num=22 pso_serial#=101 2025-05-14 06:36:01.816017 :96D8C638:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10020 osp_idx=0 osp_ver=190076 osp_pg=0 (spawn #180350) 2025-05-14 06:36:01.816017 :96D8C639: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-14 06:36:01.816018 :96D8C63A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=251 time=180371688 2025-05-14 06:36:01.816018 :96D8C63B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 06:36:01.816018 :96D8C63C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 06:36:01.816018 :96D8C63D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 06:36:01.816019 :96D8C63E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 06:36:01.816019 :96D8C63F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 06:36:01.816549 :96D8C640: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-14 06:36:01.816593 :96D8C648: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-14 06:46:02.779510 :96D98633:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 06:46:03.143705 :96D9866B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 06:46:03.139 2025-05-14 06:46:03.143706 :96D9866C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8276 pso_num=22 pso_serial#=102 2025-05-14 06:46:03.143853 :96D9866D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8276 osp_idx=0 osp_ver=190077 osp_pg=0 (spawn #180373) 2025-05-14 06:46:03.143854 :96D9866E: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-14 06:46:03.143854 :96D9866F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=252 time=180973016 2025-05-14 06:46:03.143854 :96D98670:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 06:46:03.143855 :96D98671:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 06:46:03.143855 :96D98672:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 06:46:03.143855 :96D98673:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 06:46:03.143856 :96D98674:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 06:46:03.144363 :96D98675: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-14 06:46:03.144408 :96D9867C: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-14 06:56:04.085240 :96DA47EF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 06:56:04.418064 :96DA4829:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 06:56:04.413 2025-05-14 06:56:04.418065 :96DA482A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13276 pso_num=22 pso_serial#=103 2025-05-14 06:56:04.418204 :96DA482B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13276 osp_idx=0 osp_ver=190078 osp_pg=0 (spawn #180396) 2025-05-14 06:56:04.418204 :96DA482C: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-14 06:56:04.418205 :96DA482D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=253 time=181574282 2025-05-14 06:56:04.418205 :96DA482E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 06:56:04.418206 :96DA482F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 06:56:04.418206 :96DA4830:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 06:56:04.418206 :96DA4831:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 06:56:04.418207 :96DA4832:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 06:56:04.418705 :96DA4833: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-14 06:56:04.418749 :96DA483A: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-14 07:06:05.309183 :96DB1054:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 07:06:05.673287 :96DB1096:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 07:06:05.668 2025-05-14 07:06:05.673288 :96DB1097:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10512 pso_num=22 pso_serial#=104 2025-05-14 07:06:05.673421 :96DB1098:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10512 osp_idx=0 osp_ver=190079 osp_pg=0 (spawn #180421) 2025-05-14 07:06:05.673422 :96DB1099: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-14 07:06:05.673422 :96DB109A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=254 time=182175547 2025-05-14 07:06:05.673423 :96DB109B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 07:06:05.673423 :96DB109C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 07:06:05.673423 :96DB109D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 07:06:05.673424 :96DB109E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 07:06:05.673424 :96DB109F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 07:06:05.673983 :96DB10A0: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-14 07:06:05.674026 :96DB10A8: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-14 07:16:06.611844 :96DBD3A3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 07:16:06.929045 :96DBD3E8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 07:16:06.924 2025-05-14 07:16:06.929047 :96DBD3E9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12144 pso_num=22 pso_serial#=105 2025-05-14 07:16:06.929184 :96DBD3EA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12144 osp_idx=0 osp_ver=190080 osp_pg=0 (spawn #180444) 2025-05-14 07:16:06.929184 :96DBD3EB: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-14 07:16:06.929184 :96DBD3EC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=255 time=182776797 2025-05-14 07:16:06.929185 :96DBD3ED:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 07:16:06.929187 :96DBD3EE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 07:16:06.929187 :96DBD3EF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 07:16:06.929187 :96DBD3F0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 07:16:06.929188 :96DBD3F1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 07:16:06.929689 :96DBD3F2: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-14 07:16:06.929735 :96DBD3FB: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-14 07:26:07.825587 :96DC9414:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 07:26:08.205296 :96DC9469:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 07:26:08.200 2025-05-14 07:26:08.205298 :96DC946A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9872 pso_num=22 pso_serial#=106 2025-05-14 07:26:08.205435 :96DC946B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9872 osp_idx=0 osp_ver=190081 osp_pg=0 (spawn #180467) 2025-05-14 07:26:08.205436 :96DC946C: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-14 07:26:08.205436 :96DC946D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=0 time=183378079 2025-05-14 07:26:08.205436 :96DC946E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 07:26:08.205437 :96DC946F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 07:26:08.205437 :96DC9470:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 07:26:08.205437 :96DC9471:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 07:26:08.205438 :96DC9472:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 07:26:08.205934 :96DC9473: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-14 07:26:08.205978 :96DC947A: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-14 07:36:09.133469 :96DD5594:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 07:36:09.497491 :96DD55DD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 07:36:09.493 2025-05-14 07:36:09.497494 :96DD55DE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2312 pso_num=22 pso_serial#=107 2025-05-14 07:36:09.497629 :96DD55DF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2312 osp_idx=0 osp_ver=190082 osp_pg=0 (spawn #180491) 2025-05-14 07:36:09.497629 :96DD55E0: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-14 07:36:09.497630 :96DD55E1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=1 time=183979360 2025-05-14 07:36:09.497630 :96DD55E2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 07:36:09.497631 :96DD55E3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 07:36:09.497631 :96DD55E4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 07:36:09.497631 :96DD55E5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 07:36:09.497632 :96DD55E6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 07:36:09.498127 :96DD55E7: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-14 07:36:09.498179 :96DD55EF: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-14 07:45:40.813687 :96DE0DA5: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-14 07:46:10.800323 :96DE170B: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-14 07:56:11.648134 :96DED82C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-14 07:56:12.246248 :96DED874:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-14 07:56:12.241 2025-05-14 07:56:12.246250 :96DED875:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12592 pso_num=22 pso_serial#=108 2025-05-14 07:56:12.246382 :96DED876:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12592 osp_idx=0 osp_ver=190083 osp_pg=0 (spawn #180534) 2025-05-14 07:56:12.246383 :96DED877: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-14 07:56:12.246383 :96DED878:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=2 time=185182110 2025-05-14 07:56:12.246383 :96DED879:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 07:56:12.246384 :96DED87A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 07:56:12.246384 :96DED87B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 07:56:12.246384 :96DED87C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 07:56:12.246385 :96DED87D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 07:56:12.246911 :96DED87E: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-14 07:56:12.246956 :96DED886: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: 12592, W000)