Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250614222534\orcl_w000_13500_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:36682M/63366M, Ph+PgF:43137M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13500, image: ORACLE.EXE (W000) *** 2025-06-14 22:25:34.523 *** SESSION ID:(177.8665) 2025-06-14 22:25:34.523 *** 2025-06-14 22:25:34.523 Process diagnostic dump for ORACLE.EXE (W000), OS id=13500, pid: 22, proc_ser: 219, sid: 177, sess_ser: 8665 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=2.584474 sec, exc=2.584474 sec, total=2.584474 sec wait times: max=5.000000 sec, heur=1 min 42 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.000025 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.014767 sec, exc=5.014767 sec, total=5.014767 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.009727 sec, exc=5.009727 sec, total=5.009727 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=18 seq_num=19 snap_id=1 wait times: snap=5.002155 sec, exc=5.002155 sec, total=5.002155 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.001425 sec, exc=5.001425 sec, total=5.001425 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=5.002630 sec, exc=5.002630 sec, total=5.002630 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=5.004615 sec, exc=5.004615 sec, total=5.004615 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=5.004652 sec, exc=5.004652 sec, total=5.004652 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=13 seq_num=14 snap_id=1 wait times: snap=5.014711 sec, exc=5.014711 sec, total=5.014711 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000049 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=5.015241 sec, exc=5.015241 sec, total=5.015241 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=5.003362 sec, exc=5.003362 sec, total=5.003362 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000043 sec of elapsed time Sampled Session History of session 177 serial 8665 --------------------------------------------------- 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 --------------------------------------------------- [103 samples, 22:23:51 - 22:25:34] idle wait at each sample [session created at: 22:23:51] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-14 22:25:34.523 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13500, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-14 20:13:35.304824 :A4B5974B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 20:13:35.887950 :A4B5978F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 20:13:35.883 2025-06-14 20:13:35.887952 :A4B59790:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16996 pso_num=22 pso_serial#=205 2025-06-14 20:13:35.888098 :A4B59791:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16996 osp_idx=0 osp_ver=306022 osp_pg=0 (spawn #285575) 2025-06-14 20:13:35.888099 :A4B59792:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 20:13:35.888099 :A4B59793:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=96 time=2907759079 2025-06-14 20:13:35.888100 :A4B59794:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 20:13:35.888100 :A4B59795:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 20:13:35.888101 :A4B59796:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 20:13:35.888101 :A4B59797:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 20:13:35.888101 :A4B59798:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 20:13:35.888625 :A4B59799: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-06-14 20:13:35.888671 :A4B597A3: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-06-14 20:23:36.732966 :A4B660F5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 20:23:37.253270 :A4B6613A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 20:23:37.249 2025-06-14 20:23:37.253272 :A4B6613B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16860 pso_num=22 pso_serial#=206 2025-06-14 20:23:37.253408 :A4B6613C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16860 osp_idx=0 osp_ver=306023 osp_pg=0 (spawn #285598) 2025-06-14 20:23:37.253408 :A4B6613D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 20:23:37.253409 :A4B6613E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=97 time=2908360438 2025-06-14 20:23:37.253409 :A4B6613F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 20:23:37.253410 :A4B66140:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 20:23:37.253410 :A4B66141:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 20:23:37.253410 :A4B66142:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 20:23:37.253411 :A4B66143:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 20:23:37.253942 :A4B66144: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-06-14 20:23:37.253988 :A4B6614C: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-06-14 20:33:38.036931 :A4B72BCB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 20:33:38.479263 :A4B72C24:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 20:33:38.474 2025-06-14 20:33:38.479265 :A4B72C25:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13244 pso_num=22 pso_serial#=207 2025-06-14 20:33:38.479400 :A4B72C26:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13244 osp_idx=0 osp_ver=306024 osp_pg=0 (spawn #285621) 2025-06-14 20:33:38.479400 :A4B72C27:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 20:33:38.479401 :A4B72C28:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=98 time=2908961672 2025-06-14 20:33:38.479401 :A4B72C29:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 20:33:38.479402 :A4B72C2A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 20:33:38.479402 :A4B72C2B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 20:33:38.479402 :A4B72C2C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 20:33:38.479402 :A4B72C2D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 20:33:38.479887 :A4B72C2E: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-06-14 20:33:38.479934 :A4B72C36: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-06-14 20:43:39.245865 :A4B7F45A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 20:43:39.703799 :A4B7F495:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 20:43:39.699 2025-06-14 20:43:39.703801 :A4B7F496:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16680 pso_num=22 pso_serial#=208 2025-06-14 20:43:39.703941 :A4B7F497:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16680 osp_idx=0 osp_ver=306025 osp_pg=0 (spawn #285643) 2025-06-14 20:43:39.703941 :A4B7F498:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 20:43:39.703942 :A4B7F499:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=99 time=2909562891 2025-06-14 20:43:39.703942 :A4B7F49A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 20:43:39.703943 :A4B7F49B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 20:43:39.703943 :A4B7F49C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 20:43:39.703943 :A4B7F49D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 20:43:39.703944 :A4B7F49E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 20:43:39.704452 :A4B7F49F: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-06-14 20:43:39.704496 :A4B7F4A6: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-06-14 20:53:40.514210 :A4B8BCC5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 20:53:40.972171 :A4B8BD0B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 20:53:40.967 2025-06-14 20:53:40.972173 :A4B8BD0C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15972 pso_num=22 pso_serial#=209 2025-06-14 20:53:40.972313 :A4B8BD0D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15972 osp_idx=0 osp_ver=306026 osp_pg=0 (spawn #285666) 2025-06-14 20:53:40.972314 :A4B8BD0E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 20:53:40.972314 :A4B8BD0F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=100 time=2910164157 2025-06-14 20:53:40.972314 :A4B8BD10:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 20:53:40.972315 :A4B8BD11:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 20:53:40.972315 :A4B8BD12:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 20:53:40.972315 :A4B8BD13:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 20:53:40.972316 :A4B8BD14:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 20:53:40.972836 :A4B8BD15: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-06-14 20:53:40.972890 :A4B8BD1F: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-06-14 21:03:41.889701 :A4B98B1D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 21:03:42.206836 :A4B98B56:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 21:03:42.202 2025-06-14 21:03:42.206838 :A4B98B57:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16700 pso_num=22 pso_serial#=210 2025-06-14 21:03:42.206976 :A4B98B58:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16700 osp_idx=0 osp_ver=306027 osp_pg=0 (spawn #285692) 2025-06-14 21:03:42.206976 :A4B98B59:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 21:03:42.206977 :A4B98B5A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=101 time=2910765391 2025-06-14 21:03:42.206977 :A4B98B5B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 21:03:42.206977 :A4B98B5C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 21:03:42.206978 :A4B98B5D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 21:03:42.206978 :A4B98B5E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 21:03:42.206979 :A4B98B5F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 21:03:42.207478 :A4B98B60: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-06-14 21:03:42.207524 :A4B98B68: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-06-14 21:04:27.270054 :A4B99B4F:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-06-14 21:04:27.270074 :A4B99B54:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-06-14 21:04:27.270075 :A4B99B55:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=19, exc=19, tot=19 2025-06-14 21:13:43.071609 :A4BA59EB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 21:13:43.391923 :A4BA5A26:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 21:13:43.387 2025-06-14 21:13:43.391925 :A4BA5A27:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16256 pso_num=22 pso_serial#=211 2025-06-14 21:13:43.392064 :A4BA5A28:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16256 osp_idx=0 osp_ver=306028 osp_pg=0 (spawn #285714) 2025-06-14 21:13:43.392065 :A4BA5A29:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 21:13:43.392065 :A4BA5A2A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=102 time=2911366579 2025-06-14 21:13:43.392066 :A4BA5A2B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 21:13:43.392066 :A4BA5A2C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 21:13:43.392067 :A4BA5A2D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 21:13:43.392067 :A4BA5A2E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 21:13:43.392067 :A4BA5A2F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 21:13:43.392560 :A4BA5A30: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-06-14 21:13:43.392606 :A4BA5A39: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-06-14 21:15:40.885936 :A4BA81B5: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-06-14 21:23:44.563887 :A4BB238C: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-06-14 21:33:45.392447 :A4BBED50:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 21:33:45.787672 :A4BBED99:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 21:33:45.782 2025-06-14 21:33:45.787675 :A4BBED9A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15368 pso_num=22 pso_serial#=212 2025-06-14 21:33:45.787818 :A4BBED9B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15368 osp_idx=0 osp_ver=306029 osp_pg=0 (spawn #285759) 2025-06-14 21:33:45.787818 :A4BBED9C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 21:33:45.787819 :A4BBED9D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=103 time=2912568985 2025-06-14 21:33:45.787819 :A4BBED9E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 21:33:45.787819 :A4BBED9F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 21:33:45.787820 :A4BBEDA0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 21:33:45.787820 :A4BBEDA1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 21:33:45.787820 :A4BBEDA2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 21:33:45.788315 :A4BBEDA3: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-06-14 21:33:45.788361 :A4BBEDAB: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-06-14 21:43:46.694712 :A4BCB7B3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 21:43:46.970203 :A4BCB7EF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 21:43:46.965 2025-06-14 21:43:46.970205 :A4BCB7F0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17072 pso_num=22 pso_serial#=213 2025-06-14 21:43:46.970339 :A4BCB7F1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17072 osp_idx=0 osp_ver=306030 osp_pg=0 (spawn #285781) 2025-06-14 21:43:46.970339 :A4BCB7F2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 21:43:46.970340 :A4BCB7F3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=104 time=2913170157 2025-06-14 21:43:46.970340 :A4BCB7F4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 21:43:46.970340 :A4BCB7F5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 21:43:46.970341 :A4BCB7F6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 21:43:46.970341 :A4BCB7F7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 21:43:46.970341 :A4BCB7F8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 21:43:46.970823 :A4BCB7F9: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-06-14 21:43:46.970871 :A4BCB801: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-06-14 21:53:47.933072 :A4BD8048:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 21:53:48.187951 :A4BD80A4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 21:53:48.183 2025-06-14 21:53:48.187953 :A4BD80A5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16912 pso_num=22 pso_serial#=214 2025-06-14 21:53:48.188093 :A4BD80A6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16912 osp_idx=0 osp_ver=306031 osp_pg=0 (spawn #285804) 2025-06-14 21:53:48.188094 :A4BD80A7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 21:53:48.188094 :A4BD80A8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=105 time=2913771375 2025-06-14 21:53:48.188095 :A4BD80A9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 21:53:48.188095 :A4BD80AA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 21:53:48.188096 :A4BD80AB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 21:53:48.188096 :A4BD80AC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 21:53:48.188096 :A4BD80AD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 21:53:48.188602 :A4BD80AE: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-06-14 21:53:48.188646 :A4BD80B5: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-06-14 22:03:49.146571 :A4BE4F67:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 22:03:49.354453 :A4BE4FCF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 22:03:49.349 2025-06-14 22:03:49.354455 :A4BE4FD0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17192 pso_num=22 pso_serial#=215 2025-06-14 22:03:49.354589 :A4BE4FD1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17192 osp_idx=0 osp_ver=306032 osp_pg=0 (spawn #285830) 2025-06-14 22:03:49.354589 :A4BE4FD2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 22:03:49.354590 :A4BE4FD3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=106 time=2914372547 2025-06-14 22:03:49.354590 :A4BE4FD4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 22:03:49.354591 :A4BE4FD5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 22:03:49.354591 :A4BE4FD6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 22:03:49.354591 :A4BE4FD7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 22:03:49.354592 :A4BE4FD8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 22:03:49.355070 :A4BE4FD9: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-06-14 22:03:49.355113 :A4BE4FE1: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-06-14 22:13:50.241608 :A4BF25BF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 22:13:50.400988 :A4BF25CE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 22:13:50.398 2025-06-14 22:13:50.400990 :A4BF25CF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12820 pso_num=22 pso_serial#=216 2025-06-14 22:13:50.401122 :A4BF25D0:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12820 (legacy spawn) 2025-06-14 22:13:50.407556 :A4BF25D1: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-06-14 22:13:50.407731 :A4BF25D6: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-06-14 22:13:50.408536 :A4BF25DB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 22:13:50.417330 :A4BF25DE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 22:13:50.414 2025-06-14 22:13:50.417333 :A4BF25DF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17308 pso_num=22 pso_serial#=217 2025-06-14 22:13:50.417469 :A4BF25E0:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=17308 (legacy spawn) 2025-06-14 22:13:50.423928 :A4BF25E1: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-06-14 22:13:50.424106 :A4BF25EA: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-06-14 22:13:50.424916 :A4BF25EB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 22:13:50.543069 :A4BF2623:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 22:13:50.539 2025-06-14 22:13:50.543071 :A4BF2624:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13876 pso_num=22 pso_serial#=218 2025-06-14 22:13:50.543206 :A4BF2625:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13876 osp_idx=0 osp_ver=306035 osp_pg=0 (spawn #285854) 2025-06-14 22:13:50.543207 :A4BF2626:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 22:13:50.543207 :A4BF2627:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=107 time=2914973735 2025-06-14 22:13:50.543208 :A4BF2628:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 22:13:50.543208 :A4BF2629:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 22:13:50.543208 :A4BF262A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 22:13:50.543209 :A4BF262B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 22:13:50.543209 :A4BF262C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 22:13:50.543754 :A4BF262D: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-06-14 22:13:50.543803 :A4BF2633: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-06-14 22:23:51.416540 :A4BFEF63:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-14 22:23:51.765432 :A4BFEF9B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-14 22:23:51.759 2025-06-14 22:23:51.765434 :A4BFEF9C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13500 pso_num=22 pso_serial#=219 2025-06-14 22:23:51.765563 :A4BFEF9D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13500 osp_idx=0 osp_ver=306036 osp_pg=0 (spawn #285877) 2025-06-14 22:23:51.765564 :A4BFEF9E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-14 22:23:51.765564 :A4BFEF9F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=108 time=2915574954 2025-06-14 22:23:51.765564 :A4BFEFA0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-14 22:23:51.765565 :A4BFEFA1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-14 22:23:51.765565 :A4BFEFA2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-14 22:23:51.765565 :A4BFEFA3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-14 22:23:51.765565 :A4BFEFA4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-14 22:23:51.765971 :A4BFEFA5: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-06-14 22:23:51.766373 :A4BFEFAE: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: 13500, W000)