Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250723222122\orcl_m002_15420_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:36091M/63366M, Ph+PgF:41919M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 15420, image: ORACLE.EXE (M002) *** 2025-07-23 22:21:22.208 *** SESSION ID:(201.7937) 2025-07-23 22:21:22.208 *** 2025-07-23 22:21:22.208 Process diagnostic dump for ORACLE.EXE (M002), OS id=15420, pid: 25, proc_ser: 117, sid: 201, sess_ser: 7937 ------------------------------------------------------------------------------- current sql: Current Wait Stack: Not in wait; last wait ended 0.000126 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000150 sec since last wait 0: waited for 'db file sequential read' file#=0x2, block#=0x7ffa, blocks=0x1 wait_id=1664 seq_num=1665 snap_id=1 wait times: snap=0.003119 sec, exc=0.003119 sec, total=0.003119 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000254 sec of elapsed time 1: waited for 'db file sequential read' file#=0x2, block#=0x7fda, blocks=0x1 wait_id=1663 seq_num=1664 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000151 sec of elapsed time 2: waited for 'db file sequential read' file#=0x2, block#=0x7fea, blocks=0x1 wait_id=1662 seq_num=1663 snap_id=1 wait times: snap=0.000058 sec, exc=0.000058 sec, total=0.000058 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000168 sec of elapsed time 3: waited for 'db file sequential read' file#=0x2, block#=0x8022, blocks=0x1 wait_id=1661 seq_num=1662 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000256 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x8042, blocks=0x1 wait_id=1660 seq_num=1661 snap_id=1 wait times: snap=0.000047 sec, exc=0.000047 sec, total=0.000047 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000140 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x8032, blocks=0x1 wait_id=1659 seq_num=1660 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000138 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x7f02, blocks=0x1 wait_id=1658 seq_num=1659 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000157 sec of elapsed time 7: waited for 'db file sequential read' file#=0x2, block#=0x7902, blocks=0x1 wait_id=1657 seq_num=1658 snap_id=1 wait times: snap=0.000051 sec, exc=0.000051 sec, total=0.000051 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000159 sec of elapsed time 8: waited for 'db file sequential read' file#=0x2, block#=0x8912, blocks=0x1 wait_id=1656 seq_num=1657 snap_id=1 wait times: snap=0.000053 sec, exc=0.000053 sec, total=0.000053 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000156 sec of elapsed time 9: waited for 'db file sequential read' file#=0x2, block#=0x7fa2, blocks=0x1 wait_id=1655 seq_num=1656 snap_id=1 wait times: snap=0.000065 sec, exc=0.000065 sec, total=0.000065 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000546 sec of elapsed time Sampled Session History of session 201 serial 7937 --------------------------------------------------- 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 --------------------------------------------------- [1 sample, 22:21:21] waited for 'db file sequential read', seq_num: 1407 p1: 'file#'=0x2 p2: 'block#'=0x23f2 p3: 'blocks'=0x1 time_waited: >= 0 sec (still in wait) [1 sample, 22:21:20] idle wait at each sample [session created at: 22:21:21] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'db file sequential read' [1 sample, 22:21:21 ] time_waited: >= 0 sec (still in wait) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-23 22:21:22.208 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 15420, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-23 22:08:32.557134 :B6106556:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:08:32.557619 :B6106557:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:09:02.648276 :B6106F77:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:09:32.663906 :B610799A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:09:32.652 2025-07-23 22:09:32.663908 :B610799B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18668 pso_num=25 pso_serial#=101 2025-07-23 22:09:32.664047 :B610799C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18668 osp_idx=23 osp_ver=211098 osp_pg=0 (spawn #415844) 2025-07-23 22:09:32.664047 :B610799D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:09:32.664047 :B610799E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=16 time=1989348548 2025-07-23 22:09:32.664048 :B610799F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:09:32.664048 :B61079A0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:09:32.664049 :B61079A1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:09:32.664049 :B61079A2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:09:32.664049 :B61079A3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:09:32.664527 :B61079A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:10:02.718917 :B61083E4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:10:32.732570 :B6108DF6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:10:32.721 2025-07-23 22:10:32.732572 :B6108DF7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19068 pso_num=25 pso_serial#=102 2025-07-23 22:10:32.732696 :B6108DF8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19068 osp_idx=23 osp_ver=211099 osp_pg=0 (spawn #415846) 2025-07-23 22:10:32.732697 :B6108DF9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:10:32.732697 :B6108DFA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=17 time=1989408626 2025-07-23 22:10:32.732697 :B6108DFB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:10:32.732698 :B6108DFC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:10:32.732698 :B6108DFD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:10:32.732698 :B6108DFE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:10:32.732699 :B6108DFF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:10:32.733163 :B6108E00:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:11:02.811653 :B6109829:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:11:32.842917 :B610A248:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:11:32.832 2025-07-23 22:11:32.842919 :B610A249:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16504 pso_num=25 pso_serial#=103 2025-07-23 22:11:32.843061 :B610A24A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16504 osp_idx=23 osp_ver=211100 osp_pg=0 (spawn #415848) 2025-07-23 22:11:32.843062 :B610A24B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:11:32.843062 :B610A24C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=18 time=1989468736 2025-07-23 22:11:32.843063 :B610A24D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:11:32.843063 :B610A24E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:11:32.843063 :B610A24F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:11:32.843064 :B610A250:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:11:32.843064 :B610A251:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:11:32.843551 :B610A252:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:12:02.883882 :B610AC7B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:12:32.906365 :B610B6A0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:12:32.895 2025-07-23 22:12:32.906367 :B610B6A1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4192 pso_num=25 pso_serial#=104 2025-07-23 22:12:32.906507 :B610B6A2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4192 osp_idx=23 osp_ver=211101 osp_pg=0 (spawn #415850) 2025-07-23 22:12:32.906508 :B610B6A3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:12:32.906508 :B610B6A4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=19 time=1989528798 2025-07-23 22:12:32.906509 :B610B6A5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:12:32.906509 :B610B6A6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:12:32.906509 :B610B6A7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:12:32.906509 :B610B6A8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:12:32.906509 :B610B6A9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:12:32.906991 :B610B6AA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:13:02.996328 :B610C0F5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:13:32.992619 :B610CB4C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:13:32.981 2025-07-23 22:13:32.992621 :B610CB4D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18004 pso_num=25 pso_serial#=105 2025-07-23 22:13:32.992741 :B610CB4E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18004 osp_idx=23 osp_ver=211102 osp_pg=0 (spawn #415853) 2025-07-23 22:13:32.992742 :B610CB4F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:13:32.992743 :B610CB50:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=20 time=1989588876 2025-07-23 22:13:32.992743 :B610CB51:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:13:32.992743 :B610CB52:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:13:32.992744 :B610CB53:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:13:32.992744 :B610CB54:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:13:32.992744 :B610CB55:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:13:32.993225 :B610CB56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:13:58.004015 :B610D37D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-23 22:14:28.078673 :B610E1A0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:14:33.052445 :B610E37A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:14:33.041 2025-07-23 22:14:33.052447 :B610E37B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15576 pso_num=25 pso_serial#=106 2025-07-23 22:14:33.052581 :B610E37C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15576 osp_idx=23 osp_ver=211103 osp_pg=0 (spawn #415855) 2025-07-23 22:14:33.052582 :B610E37D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:14:33.052583 :B610E37E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=21 time=1989648939 2025-07-23 22:14:33.052583 :B610E37F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:14:33.052584 :B610E380:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:14:33.052584 :B610E381:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:14:33.052585 :B610E382:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:14:33.052585 :B610E383:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:14:33.053122 :B610E384:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:15:03.136563 :B610EE96:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:15:33.133573 :B610F8A7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:15:33.122 2025-07-23 22:15:33.133575 :B610F8A8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18504 pso_num=25 pso_serial#=107 2025-07-23 22:15:33.133703 :B610F8A9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18504 osp_idx=23 osp_ver=211104 osp_pg=0 (spawn #415857) 2025-07-23 22:15:33.133703 :B610F8AA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:15:33.133704 :B610F8AB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=22 time=1989709017 2025-07-23 22:15:33.133704 :B610F8AC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:15:33.133705 :B610F8AD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:15:33.133705 :B610F8AE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:15:33.133705 :B610F8AF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:15:33.133706 :B610F8B0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:15:33.134187 :B610F8B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:16:03.164405 :B61102BE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:16:33.209409 :B6110D4D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:16:33.198 2025-07-23 22:16:33.209411 :B6110D4E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10604 pso_num=25 pso_serial#=108 2025-07-23 22:16:33.209538 :B6110D4F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10604 osp_idx=23 osp_ver=211105 osp_pg=0 (spawn #415861) 2025-07-23 22:16:33.209539 :B6110D50:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:16:33.209539 :B6110D51:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=23 time=1989769095 2025-07-23 22:16:33.209540 :B6110D52:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:16:33.209540 :B6110D53:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:16:33.209540 :B6110D54:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:16:33.209541 :B6110D55:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:16:33.209541 :B6110D56:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:16:33.210015 :B6110D57:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:17:03.319698 :B6111763:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:17:33.308856 :B6112185:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:17:33.297 2025-07-23 22:17:33.308858 :B6112186:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18200 pso_num=25 pso_serial#=109 2025-07-23 22:17:33.308977 :B6112187:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18200 osp_idx=23 osp_ver=211106 osp_pg=0 (spawn #415863) 2025-07-23 22:17:33.308978 :B6112188:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:17:33.308978 :B6112189:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=24 time=1989829189 2025-07-23 22:17:33.308979 :B611218A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:17:33.308979 :B611218B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:17:33.308979 :B611218C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:17:33.308980 :B611218D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:17:33.308980 :B611218E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:17:33.309463 :B611218F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:18:03.396798 :B6112C25:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:18:33.457040 :B6113637:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:18:33.453 2025-07-23 22:18:33.457042 :B6113638:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4800 pso_num=25 pso_serial#=110 2025-07-23 22:18:33.457173 :B6113639:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4800 osp_idx=23 osp_ver=211107 osp_pg=0 (spawn #415865) 2025-07-23 22:18:33.457173 :B611363A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:18:33.457174 :B611363B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=25 time=1989889329 2025-07-23 22:18:33.457174 :B611363C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:18:33.457175 :B611363D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:18:33.457175 :B611363E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:18:33.457175 :B611363F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:18:33.457176 :B6113640:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:18:33.457655 :B6113641:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:19:03.547434 :B6114046:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:19:33.554260 :B6114A83:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:19:33.543 2025-07-23 22:19:33.554262 :B6114A84:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18812 pso_num=25 pso_serial#=111 2025-07-23 22:19:33.554401 :B6114A85:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18812 osp_idx=23 osp_ver=211108 osp_pg=0 (spawn #415867) 2025-07-23 22:19:33.554402 :B6114A86:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:19:33.554402 :B6114A87:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=26 time=1989949439 2025-07-23 22:19:33.554403 :B6114A88:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:19:33.554403 :B6114A89:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:19:33.554404 :B6114A8A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:19:33.554404 :B6114A8B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:19:33.554404 :B6114A8C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:19:33.554875 :B6114A8D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:20:03.635970 :B61154B7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:20:33.655629 :B6115E8B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:20:33.644 2025-07-23 22:20:33.655631 :B6115E8C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16664 pso_num=25 pso_serial#=112 2025-07-23 22:20:33.655765 :B6115E8D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16664 osp_idx=23 osp_ver=211109 osp_pg=0 (spawn #415869) 2025-07-23 22:20:33.655766 :B6115E8E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:20:33.655766 :B6115E8F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=27 time=1990009548 2025-07-23 22:20:33.655767 :B6115E90:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:20:33.655767 :B6115E91:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:20:33.655767 :B6115E92:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:20:33.655768 :B6115E93:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:20:33.655768 :B6115E94:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:20:33.656252 :B6115E95:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:21:03.774300 :B611687B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:21:18.384591 :B611A583:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:21:18.376 2025-07-23 22:21:18.384593 :B611A584:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16984 pso_num=25 pso_serial#=113 2025-07-23 22:21:18.384801 :B611A585:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16984 (legacy spawn) 2025-07-23 22:21:18.391618 :B611A588: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-07-23 22:21:18.391991 :B611A58F: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-07-23 22:21:18.392885 :B611A592:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:21:18.421043 :B611A595:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:21:18.407 2025-07-23 22:21:18.421045 :B611A596:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18500 pso_num=25 pso_serial#=114 2025-07-23 22:21:18.421191 :B611A597:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=18500 (legacy spawn) 2025-07-23 22:21:18.428088 :B611A598: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-07-23 22:21:18.428619 :B611A5A1: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-07-23 22:21:18.429498 :B611A5A2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:21:18.446684 :B611A5A9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:21:18.438 2025-07-23 22:21:18.446686 :B611A5AA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7436 pso_num=25 pso_serial#=115 2025-07-23 22:21:18.446836 :B611A5AB:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=7436 (legacy spawn) 2025-07-23 22:21:18.453751 :B611A5AC: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-07-23 22:21:18.454133 :B611A5B5: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-07-23 22:21:18.455188 :B611A5B6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:21:20.040888 :B611A833:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:21:20.026 2025-07-23 22:21:20.040890 :B611A834:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15600 pso_num=25 pso_serial#=116 2025-07-23 22:21:20.041042 :B611A835:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15600 osp_idx=23 osp_ver=211113 osp_pg=0 (spawn #415871) 2025-07-23 22:21:20.041043 :B611A836:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:21:20.041043 :B611A837:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=28 time=1990055923 2025-07-23 22:21:20.041045 :B611A838:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:21:20.041045 :B611A839:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:21:20.041046 :B611A83A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:21:20.041046 :B611A83B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:21:20.041046 :B611A83C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:21:20.041872 :B611A83D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:21:20.041921 :B611A843:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-23 22:21:20.154517 :B611A875:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 22:21:21.345407 :B611A920:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 22:21:21.333 2025-07-23 22:21:21.345409 :B611A921:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15420 pso_num=25 pso_serial#=117 2025-07-23 22:21:21.345542 :B611A922:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15420 osp_idx=23 osp_ver=211114 osp_pg=0 (spawn #415873) 2025-07-23 22:21:21.345542 :B611A923:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-23 22:21:21.345543 :B611A924:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=29 time=1990057236 2025-07-23 22:21:21.345543 :B611A925:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 22:21:21.345544 :B611A926:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 22:21:21.345544 :B611A927:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 22:21:21.345544 :B611A928:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 22:21:21.345544 :B611A929:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 22:21:21.346061 :B611A92A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-23 22:21:21.346108 :B611A930:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 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: 15420, M002)