Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250522220955\orcl_w000_11740_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:37351M/63366M, Ph+PgF:44419M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 11740, image: ORACLE.EXE (W000) *** 2025-05-22 22:09:55.592 *** SESSION ID:(201.49709) 2025-05-22 22:09:55.592 *** 2025-05-22 22:09:55.592 Process diagnostic dump for ORACLE.EXE (W000), OS id=11740, pid: 25, proc_ser: 44, sid: 201, sess_ser: 49709 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=70 seq_num=71 snap_id=1 wait times: snap=4.079890 sec, exc=4.079890 sec, total=4.079890 sec wait times: max=5.000000 sec, heur=5 min 49 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=69 seq_num=70 snap_id=1 wait times: snap=5.004636 sec, exc=5.004636 sec, total=5.004636 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=68 seq_num=69 snap_id=1 wait times: snap=5.014743 sec, exc=5.014743 sec, total=5.014743 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 2: 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.004630 sec, exc=5.004630 sec, total=5.004630 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 3: 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.008336 sec, exc=5.008336 sec, total=5.008336 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 4: 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.000368 sec, exc=5.000368 sec, total=5.000368 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: 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.013459 sec, exc=5.013459 sec, total=5.013459 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 6: 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.014740 sec, exc=5.014740 sec, total=5.014740 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 7: 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.014748 sec, exc=5.014748 sec, total=5.014748 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 8: 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.010144 sec, exc=5.010144 sec, total=5.010144 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=60 seq_num=61 snap_id=1 wait times: snap=5.014732 sec, exc=5.014732 sec, total=5.014732 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 201 serial 49709 --------------------------------------------------- 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:07:55 - 22:09:55] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-22 22:09:55.592 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 11740, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-22 19:53:47.616400 :9AA0A2D6:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=11132 (legacy spawn) 2025-05-22 19:53:47.622807 :9AA0A2D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-22 19:53:47.622981 :9AA0A2DC:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 19:53:47.623804 :9AA0A2E1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 19:53:47.632483 :9AA0A2E4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 19:53:47.624 2025-05-22 19:53:47.632485 :9AA0A2E5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13764 pso_num=25 pso_serial#=30 2025-05-22 19:53:47.632633 :9AA0A2E6:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13764 (legacy spawn) 2025-05-22 19:53:47.639121 :9AA0A2E7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-22 19:53:47.639282 :9AA0A2F0:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 19:53:47.640143 :9AA0A2F1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 19:53:47.676599 :9AA0A352:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 19:53:47.671 2025-05-22 19:53:47.676601 :9AA0A353:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4228 pso_num=25 pso_serial#=31 2025-05-22 19:53:47.676758 :9AA0A354:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4228 osp_idx=23 osp_ver=110445 osp_pg=0 (spawn #208880) 2025-05-22 19:53:47.676759 :9AA0A355:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 19:53:47.676759 :9AA0A356:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=104 time=919402579 2025-05-22 19:53:47.676760 :9AA0A357:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 19:53:47.676760 :9AA0A358:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 19:53:47.676760 :9AA0A359:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 19:53:47.676760 :9AA0A35A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 19:53:47.676761 :9AA0A35B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 19:53:47.677330 :9AA0A35C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 19:53:47.677394 :9AA0A362:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 20:03:48.692809 :9AA166CE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 20:03:49.025650 :9AA1671C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 20:03:49.021 2025-05-22 20:03:49.025652 :9AA1671D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14064 pso_num=25 pso_serial#=32 2025-05-22 20:03:49.025794 :9AA1671E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14064 osp_idx=23 osp_ver=110446 osp_pg=0 (spawn #208905) 2025-05-22 20:03:49.025794 :9AA1671F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 20:03:49.025795 :9AA16720:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=105 time=920003922 2025-05-22 20:03:49.025795 :9AA16721:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 20:03:49.025796 :9AA16722:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 20:03:49.025796 :9AA16723:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 20:03:49.025796 :9AA16724:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 20:03:49.025797 :9AA16725:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 20:03:49.026299 :9AA16726:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 20:03:49.026348 :9AA1672F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 20:13:49.989896 :9AA22D56:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 20:13:50.447862 :9AA22DB4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 20:13:50.443 2025-05-22 20:13:50.447864 :9AA22DB5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7276 pso_num=25 pso_serial#=33 2025-05-22 20:13:50.448006 :9AA22DB6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7276 osp_idx=23 osp_ver=110447 osp_pg=0 (spawn #208928) 2025-05-22 20:13:50.448007 :9AA22DB7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 20:13:50.448008 :9AA22DB8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=106 time=920605344 2025-05-22 20:13:50.448008 :9AA22DB9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 20:13:50.448008 :9AA22DBA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 20:13:50.448009 :9AA22DBB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 20:13:50.448009 :9AA22DBC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 20:13:50.448009 :9AA22DBD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 20:13:50.448507 :9AA22DBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 20:13:50.448557 :9AA22DC7:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 20:23:51.402834 :9AA2F086:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 20:23:51.891961 :9AA2F0F4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 20:23:51.887 2025-05-22 20:23:51.891963 :9AA2F0F5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12672 pso_num=25 pso_serial#=34 2025-05-22 20:23:51.892106 :9AA2F0F6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12672 osp_idx=23 osp_ver=110448 osp_pg=0 (spawn #208951) 2025-05-22 20:23:51.892106 :9AA2F0F7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 20:23:51.892107 :9AA2F0F8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=107 time=921206797 2025-05-22 20:23:51.892107 :9AA2F0F9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 20:23:51.892108 :9AA2F0FA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 20:23:51.892108 :9AA2F0FB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 20:23:51.892108 :9AA2F0FC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 20:23:51.892109 :9AA2F0FD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 20:23:51.892614 :9AA2F0FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 20:23:51.892659 :9AA2F106:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 20:33:52.880394 :9AA3B22D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 20:33:53.385245 :9AA3B2A8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 20:33:53.380 2025-05-22 20:33:53.385247 :9AA3B2A9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13864 pso_num=25 pso_serial#=35 2025-05-22 20:33:53.385393 :9AA3B2AA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13864 osp_idx=23 osp_ver=110449 osp_pg=0 (spawn #208973) 2025-05-22 20:33:53.385394 :9AA3B2AB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 20:33:53.385394 :9AA3B2AC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=108 time=921808282 2025-05-22 20:33:53.385395 :9AA3B2AD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 20:33:53.385396 :9AA3B2AE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 20:33:53.385396 :9AA3B2AF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 20:33:53.385396 :9AA3B2B0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 20:33:53.385397 :9AA3B2B1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 20:33:53.385892 :9AA3B2B2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 20:33:53.385937 :9AA3B2B9:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 20:43:54.380022 :9AA4739D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 20:43:54.947420 :9AA47422:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 20:43:54.942 2025-05-22 20:43:54.947423 :9AA47423:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8164 pso_num=25 pso_serial#=36 2025-05-22 20:43:54.947562 :9AA47424:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8164 osp_idx=23 osp_ver=110450 osp_pg=0 (spawn #208996) 2025-05-22 20:43:54.947564 :9AA47425:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 20:43:54.947564 :9AA47426:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=109 time=922409844 2025-05-22 20:43:54.947565 :9AA47427:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 20:43:54.947565 :9AA47428:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 20:43:54.947565 :9AA47429:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 20:43:54.947566 :9AA4742A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 20:43:54.947566 :9AA4742B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 20:43:54.948074 :9AA4742C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 20:43:54.948124 :9AA47433:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 20:53:55.864247 :9AA53491:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 20:53:56.446992 :9AA5351E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 20:53:56.442 2025-05-22 20:53:56.446994 :9AA5351F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14244 pso_num=25 pso_serial#=37 2025-05-22 20:53:56.447125 :9AA53520:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14244 osp_idx=23 osp_ver=110451 osp_pg=0 (spawn #209019) 2025-05-22 20:53:56.447125 :9AA53521:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 20:53:56.447126 :9AA53522:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=110 time=923011344 2025-05-22 20:53:56.447126 :9AA53523:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 20:53:56.447126 :9AA53524:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 20:53:56.447127 :9AA53525:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 20:53:56.447127 :9AA53526:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 20:53:56.447128 :9AA53527:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 20:53:56.447693 :9AA53528:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 20:53:56.447744 :9AA53530:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:03:57.351998 :9AA5F895:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 21:03:57.541007 :9AA5F8C0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 21:03:57.539 2025-05-22 21:03:57.541008 :9AA5F8C1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12360 pso_num=25 pso_serial#=38 2025-05-22 21:03:57.541145 :9AA5F8C2:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=12360 (legacy spawn) 2025-05-22 21:03:57.547620 :9AA5F8C3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-22 21:03:57.547784 :9AA5F8C9:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:03:57.548572 :9AA5F8CD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 21:03:57.809716 :9AA5F946:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 21:03:57.805 2025-05-22 21:03:57.809717 :9AA5F947:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12720 pso_num=25 pso_serial#=39 2025-05-22 21:03:57.809852 :9AA5F948:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12720 osp_idx=23 osp_ver=110453 osp_pg=0 (spawn #209044) 2025-05-22 21:03:57.809853 :9AA5F949:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:03:57.809853 :9AA5F94A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=111 time=923612704 2025-05-22 21:03:57.809854 :9AA5F94B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:03:57.809854 :9AA5F94C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:03:57.809855 :9AA5F94D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:03:57.809855 :9AA5F94E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:03:57.809855 :9AA5F94F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:03:57.810347 :9AA5F950:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 21:03:57.810393 :9AA5F956:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:13:58.679465 :9AA6C02B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 21:13:59.319271 :9AA6C0AB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 21:13:59.315 2025-05-22 21:13:59.319274 :9AA6C0AC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10956 pso_num=25 pso_serial#=40 2025-05-22 21:13:59.319415 :9AA6C0AD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10956 osp_idx=23 osp_ver=110454 osp_pg=0 (spawn #209067) 2025-05-22 21:13:59.319416 :9AA6C0AE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:13:59.319417 :9AA6C0AF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=112 time=924214219 2025-05-22 21:13:59.319417 :9AA6C0B0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:13:59.319418 :9AA6C0B1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:13:59.319418 :9AA6C0B2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:13:59.319418 :9AA6C0B3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:13:59.319419 :9AA6C0B4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:13:59.319918 :9AA6C0B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 21:13:59.319964 :9AA6C0BD:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:20:17.060665 :9AA73C4F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:24:00.681041 :9AA784C3:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:34:01.527269 :9AA84547:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 21:34:02.000587 :9AA845A5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 21:34:01.996 2025-05-22 21:34:02.000589 :9AA845A6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14280 pso_num=25 pso_serial#=41 2025-05-22 21:34:02.000741 :9AA845A7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14280 osp_idx=23 osp_ver=110455 osp_pg=0 (spawn #209111) 2025-05-22 21:34:02.000742 :9AA845A8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:34:02.000742 :9AA845A9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=113 time=925416907 2025-05-22 21:34:02.000742 :9AA845AA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:34:02.000743 :9AA845AB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:34:02.000743 :9AA845AC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:34:02.000743 :9AA845AD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:34:02.000744 :9AA845AE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:34:02.001252 :9AA845AF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 21:34:02.001297 :9AA845B8:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:44:02.924075 :9AA9071F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 21:44:03.382026 :9AA90791:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 21:44:03.377 2025-05-22 21:44:03.382028 :9AA90792:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13724 pso_num=25 pso_serial#=42 2025-05-22 21:44:03.382165 :9AA90793:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13724 osp_idx=23 osp_ver=110456 osp_pg=0 (spawn #209134) 2025-05-22 21:44:03.382165 :9AA90794:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:44:03.382166 :9AA90795:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=114 time=926018282 2025-05-22 21:44:03.382166 :9AA90796:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:44:03.382166 :9AA90797:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:44:03.382167 :9AA90798:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:44:03.382167 :9AA90799:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:44:03.382167 :9AA9079A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:44:03.382665 :9AA9079B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 21:44:03.382712 :9AA907A3:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 21:54:04.340731 :9AA9CA1A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 21:54:04.673562 :9AA9CA6E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 21:54:04.669 2025-05-22 21:54:04.673564 :9AA9CA6F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14056 pso_num=25 pso_serial#=43 2025-05-22 21:54:04.673710 :9AA9CA70:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14056 osp_idx=23 osp_ver=110457 osp_pg=0 (spawn #209157) 2025-05-22 21:54:04.673711 :9AA9CA71:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 21:54:04.673711 :9AA9CA72:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=115 time=926619579 2025-05-22 21:54:04.673712 :9AA9CA73:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 21:54:04.673712 :9AA9CA74:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 21:54:04.673712 :9AA9CA75:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 21:54:04.673713 :9AA9CA76:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 21:54:04.673713 :9AA9CA77:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 21:54:04.674221 :9AA9CA78:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 21:54:04.674264 :9AA9CA80:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-22 22:04:05.661722 :9AAA97D3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-22 22:04:05.932084 :9AAA9845:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-22 22:04:05.927 2025-05-22 22:04:05.932087 :9AAA9846:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11740 pso_num=25 pso_serial#=44 2025-05-22 22:04:05.932224 :9AAA9847:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11740 osp_idx=23 osp_ver=110458 osp_pg=0 (spawn #209188) 2025-05-22 22:04:05.932224 :9AAA9848:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-22 22:04:05.932225 :9AAA9849:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=116 time=927220829 2025-05-22 22:04:05.932225 :9AAA984A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-22 22:04:05.932226 :9AAA984B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-22 22:04:05.932226 :9AAA984C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-22 22:04:05.932226 :9AAA984D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-22 22:04:05.932226 :9AAA984E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-22 22:04:05.932712 :9AAA984F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-22 22:04:05.932766 :9AAA9857:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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 25 (osid: 11740, W000)