Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250819220008\orcl_w000_21316_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:35336M/63366M, Ph+PgF:40533M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 21316, image: ORACLE.EXE (W000) *** 2025-08-19 22:00:08.717 *** SESSION ID:(201.18045) 2025-08-19 22:00:08.717 *** 2025-08-19 22:00:08.717 Process diagnostic dump for ORACLE.EXE (W000), OS id=21316, pid: 25, proc_ser: 48, sid: 201, sess_ser: 18045 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=86 seq_num=87 snap_id=1 wait times: snap=3.845360 sec, exc=3.845360 sec, total=3.845360 sec wait times: max=5.000000 sec, heur=6 min 19 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=85 seq_num=86 snap_id=1 wait times: snap=5.004621 sec, exc=5.004621 sec, total=5.004621 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=84 seq_num=85 snap_id=1 wait times: snap=5.009753 sec, exc=5.009753 sec, total=5.009753 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=83 seq_num=84 snap_id=1 wait times: snap=5.003269 sec, exc=5.003269 sec, total=5.003269 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=82 seq_num=83 snap_id=1 wait times: snap=5.000513 sec, exc=5.000513 sec, total=5.000513 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=81 seq_num=82 snap_id=1 wait times: snap=5.014564 sec, exc=5.014564 sec, total=5.014564 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=80 seq_num=81 snap_id=1 wait times: snap=5.007564 sec, exc=5.007564 sec, total=5.007564 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=79 seq_num=80 snap_id=1 wait times: snap=5.004616 sec, exc=5.004616 sec, total=5.004616 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=78 seq_num=79 snap_id=1 wait times: snap=5.004633 sec, exc=5.004633 sec, total=5.004633 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.004634 sec, exc=5.004634 sec, total=5.004634 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=76 seq_num=77 snap_id=1 wait times: snap=5.009718 sec, exc=5.009718 sec, total=5.009718 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time Sampled Session History of session 201 serial 18045 --------------------------------------------------- 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, 21:58:08 - 22:00:08] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-19 22:00:08.717 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 21316, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-19 19:42:46.790583 :C1F1F181:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19980 pso_num=25 pso_serial#=35 2025-08-19 19:42:46.790738 :C1F1F182:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19980 osp_idx=23 osp_ver=246222 osp_pg=0 (spawn #505505) 2025-08-19 19:42:46.790739 :C1F1F183:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 19:42:46.790740 :C1F1F184:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=3 time=18268799 2025-08-19 19:42:46.790740 :C1F1F185:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 19:42:46.790741 :C1F1F186:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 19:42:46.790741 :C1F1F187:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 19:42:46.790741 :C1F1F188:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 19:42:46.790742 :C1F1F189:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 19:42:46.791272 :C1F1F18A: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-08-19 19:42:46.791319 :C1F1F192: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-08-19 19:43:16.833513 :C1F1FB04:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-08-19 19:43:16.833517 :C1F1FB05:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-08-19 19:43:16.833518 :C1F1FB06:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=5, exc=5, tot=5 2025-08-19 19:43:16.833524 :C1F1FB0D: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-08-19 19:52:47.697724 :C1F2B24E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 19:52:47.715181 :C1F2B25E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 19:52:47.713 2025-08-19 19:52:47.715183 :C1F2B25F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=5196 pso_num=25 pso_serial#=36 2025-08-19 19:52:47.715329 :C1F2B260:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=5196 (legacy spawn) 2025-08-19 19:52:47.722226 :C1F2B261: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-08-19 19:52:47.722404 :C1F2B26A: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-08-19 19:52:47.723272 :C1F2B26B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 19:52:48.030728 :C1F2B2D1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 19:52:48.030 2025-08-19 19:52:48.030730 :C1F2B2D2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21752 pso_num=25 pso_serial#=37 2025-08-19 19:52:48.030917 :C1F2B2D3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21752 osp_idx=23 osp_ver=246224 osp_pg=0 (spawn #505527) 2025-08-19 19:52:48.030917 :C1F2B2D4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 19:52:48.030918 :C1F2B2D5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=4 time=18870033 2025-08-19 19:52:48.030918 :C1F2B2D6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 19:52:48.030919 :C1F2B2D7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 19:52:48.030919 :C1F2B2D8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 19:52:48.030920 :C1F2B2D9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 19:52:48.030920 :C1F2B2DA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 19:52:48.031443 :C1F2B2DB: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-08-19 19:52:48.031493 :C1F2B2E4: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-08-19 19:53:03.043628 :C1F2B789:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-08-19 19:53:03.043659 :C1F2B796:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-08-19 19:53:03.043660 :C1F2B797:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=29, exc=29, tot=29 2025-08-19 20:02:48.928170 :C1F375D3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 20:02:49.355335 :C1F3763C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 20:02:49.350 2025-08-19 20:02:49.355338 :C1F3763D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14620 pso_num=25 pso_serial#=38 2025-08-19 20:02:49.355491 :C1F3763E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14620 osp_idx=23 osp_ver=246225 osp_pg=0 (spawn #505552) 2025-08-19 20:02:49.355492 :C1F3763F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 20:02:49.355492 :C1F37640:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=5 time=19471362 2025-08-19 20:02:49.355493 :C1F37641:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 20:02:49.355493 :C1F37642:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 20:02:49.355494 :C1F37643:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 20:02:49.355494 :C1F37644:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 20:02:49.355494 :C1F37645:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 20:02:49.356042 :C1F37646: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-08-19 20:02:49.356101 :C1F3764C: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-08-19 20:12:50.301006 :C1F444E6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 20:12:50.633989 :C1F44535:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 20:12:50.629 2025-08-19 20:12:50.633991 :C1F44536:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18716 pso_num=25 pso_serial#=39 2025-08-19 20:12:50.634130 :C1F44537:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18716 osp_idx=23 osp_ver=246226 osp_pg=0 (spawn #505576) 2025-08-19 20:12:50.634131 :C1F44538:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 20:12:50.634131 :C1F44539:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=6 time=20072643 2025-08-19 20:12:50.634132 :C1F4453A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 20:12:50.634132 :C1F4453B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 20:12:50.634133 :C1F4453C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 20:12:50.634133 :C1F4453D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 20:12:50.634133 :C1F4453E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 20:12:50.634639 :C1F4453F: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-08-19 20:12:50.634688 :C1F44547: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-08-19 20:22:51.533965 :C1F50A97:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 20:22:51.898127 :C1F50AE4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 20:22:51.893 2025-08-19 20:22:51.898129 :C1F50AE5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17340 pso_num=25 pso_serial#=40 2025-08-19 20:22:51.898301 :C1F50AE6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17340 osp_idx=23 osp_ver=246227 osp_pg=0 (spawn #505598) 2025-08-19 20:22:51.898302 :C1F50AE7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 20:22:51.898304 :C1F50AE8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=7 time=20673908 2025-08-19 20:22:51.898304 :C1F50AE9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 20:22:51.898304 :C1F50AEA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 20:22:51.898305 :C1F50AEB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 20:22:51.898305 :C1F50AEC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 20:22:51.898306 :C1F50AED:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 20:22:51.898834 :C1F50AEE: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-08-19 20:22:51.898879 :C1F50AF7: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-08-19 20:32:52.856310 :C1F5D0ED:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 20:32:53.221172 :C1F5D133:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 20:32:53.215 2025-08-19 20:32:53.221174 :C1F5D134:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21036 pso_num=25 pso_serial#=41 2025-08-19 20:32:53.221325 :C1F5D135:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21036 osp_idx=23 osp_ver=246228 osp_pg=0 (spawn #505619) 2025-08-19 20:32:53.221326 :C1F5D136:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 20:32:53.221327 :C1F5D137:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=8 time=21275237 2025-08-19 20:32:53.221327 :C1F5D138:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 20:32:53.221327 :C1F5D139:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 20:32:53.221328 :C1F5D13A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 20:32:53.221329 :C1F5D13B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 20:32:53.221329 :C1F5D13C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 20:32:53.221894 :C1F5D13D: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-08-19 20:32:53.221964 :C1F5D147: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-08-19 20:42:54.103743 :C1F6964D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 20:42:54.530436 :C1F696A5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 20:42:54.525 2025-08-19 20:42:54.530438 :C1F696A6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21336 pso_num=25 pso_serial#=42 2025-08-19 20:42:54.530573 :C1F696A7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21336 osp_idx=23 osp_ver=246229 osp_pg=0 (spawn #505643) 2025-08-19 20:42:54.530573 :C1F696A8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 20:42:54.530574 :C1F696A9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=9 time=21876533 2025-08-19 20:42:54.530574 :C1F696AA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 20:42:54.530575 :C1F696AB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 20:42:54.530575 :C1F696AC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 20:42:54.530576 :C1F696AD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 20:42:54.530576 :C1F696AE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 20:42:54.531072 :C1F696AF: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-08-19 20:42:54.531121 :C1F696B7: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-08-19 20:52:55.416572 :C1F75C51:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 20:52:55.890104 :C1F75C98:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 20:52:55.885 2025-08-19 20:52:55.890106 :C1F75C99:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6024 pso_num=25 pso_serial#=43 2025-08-19 20:52:55.890243 :C1F75C9A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=6024 osp_idx=23 osp_ver=246230 osp_pg=0 (spawn #505665) 2025-08-19 20:52:55.890243 :C1F75C9B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 20:52:55.890244 :C1F75C9C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=10 time=22477893 2025-08-19 20:52:55.890244 :C1F75C9D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 20:52:55.890244 :C1F75C9E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 20:52:55.890245 :C1F75C9F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 20:52:55.890245 :C1F75CA0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 20:52:55.890245 :C1F75CA1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 20:52:55.890748 :C1F75CA2: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-08-19 20:52:55.890792 :C1F75CA9: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-08-19 21:02:56.707882 :C1F823A7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 21:02:57.215883 :C1F8240B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 21:02:57.210 2025-08-19 21:02:57.215885 :C1F8240C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22052 pso_num=25 pso_serial#=44 2025-08-19 21:02:57.216024 :C1F8240D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22052 osp_idx=23 osp_ver=246231 osp_pg=0 (spawn #505690) 2025-08-19 21:02:57.216024 :C1F8240E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 21:02:57.216025 :C1F8240F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=11 time=23079221 2025-08-19 21:02:57.216025 :C1F82410:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 21:02:57.216026 :C1F82411:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 21:02:57.216026 :C1F82412:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 21:02:57.216027 :C1F82413:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 21:02:57.216027 :C1F82414:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 21:02:57.216532 :C1F82415: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-08-19 21:02:57.216583 :C1F8241E: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-08-19 21:12:58.165288 :C1F8F063:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 21:12:58.592430 :C1F8F0C0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 21:12:58.586 2025-08-19 21:12:58.592432 :C1F8F0C1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18400 pso_num=25 pso_serial#=45 2025-08-19 21:12:58.592576 :C1F8F0C2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18400 osp_idx=23 osp_ver=246232 osp_pg=0 (spawn #505714) 2025-08-19 21:12:58.592576 :C1F8F0C3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 21:12:58.592577 :C1F8F0C4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=12 time=23680596 2025-08-19 21:12:58.592577 :C1F8F0C5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 21:12:58.592577 :C1F8F0C6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 21:12:58.592578 :C1F8F0C7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 21:12:58.592578 :C1F8F0C8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 21:12:58.592578 :C1F8F0C9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 21:12:58.593170 :C1F8F0CA: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-08-19 21:12:58.593231 :C1F8F0D2: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-08-19 21:22:59.518132 :C1F9B3BD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 21:22:59.929107 :C1F9B416:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 21:22:59.924 2025-08-19 21:22:59.929109 :C1F9B417:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22160 pso_num=25 pso_serial#=46 2025-08-19 21:22:59.929248 :C1F9B418:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22160 osp_idx=23 osp_ver=246233 osp_pg=0 (spawn #505736) 2025-08-19 21:22:59.929249 :C1F9B419:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 21:22:59.929250 :C1F9B41A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=13 time=24281940 2025-08-19 21:22:59.929250 :C1F9B41B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 21:22:59.929251 :C1F9B41C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 21:22:59.929251 :C1F9B41D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 21:22:59.929251 :C1F9B41E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 21:22:59.929251 :C1F9B41F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 21:22:59.929748 :C1F9B420: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-08-19 21:22:59.929793 :C1F9B427: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-08-19 21:23:32.923812 :C1F9BE40: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-08-19 21:33:01.455683 :C1FA7875: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-08-19 21:43:02.373545 :C1FB3BC7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 21:43:02.815644 :C1FB3C44:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 21:43:02.811 2025-08-19 21:43:02.815646 :C1FB3C45:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21084 pso_num=25 pso_serial#=47 2025-08-19 21:43:02.815784 :C1FB3C46:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21084 osp_idx=23 osp_ver=246234 osp_pg=0 (spawn #505781) 2025-08-19 21:43:02.815785 :C1FB3C47:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 21:43:02.815785 :C1FB3C48:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=14 time=25484830 2025-08-19 21:43:02.815786 :C1FB3C49:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 21:43:02.815786 :C1FB3C4A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 21:43:02.815787 :C1FB3C4B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 21:43:02.815787 :C1FB3C4C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 21:43:02.815787 :C1FB3C4D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 21:43:02.816275 :C1FB3C4E: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-08-19 21:43:02.816321 :C1FB3C55: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-08-19 21:53:03.720732 :C1FBFF43:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-19 21:53:04.288079 :C1FBFFD2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-19 21:53:04.282 2025-08-19 21:53:04.288081 :C1FBFFD3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21316 pso_num=25 pso_serial#=48 2025-08-19 21:53:04.288290 :C1FBFFD4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21316 osp_idx=23 osp_ver=246235 osp_pg=0 (spawn #505803) 2025-08-19 21:53:04.288291 :C1FBFFD5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-19 21:53:04.288292 :C1FBFFD6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=15 time=26086299 2025-08-19 21:53:04.288292 :C1FBFFD7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-19 21:53:04.288292 :C1FBFFD8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-19 21:53:04.288293 :C1FBFFD9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-19 21:53:04.288294 :C1FBFFDA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-19 21:53:04.288294 :C1FBFFDB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-19 21:53:04.288826 :C1FBFFDC: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-08-19 21:53:04.288886 :C1FBFFE3: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-08-19 21:53:49.367361 :C1FC0DFC:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-08-19 21:53:49.367384 :C1FC0E0A:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-08-19 21:53:49.367385 :C1FC0E0B:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=23, exc=23, tot=23 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 21316, W000)