Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250727100628\orcl_w000_9904_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:36006M/63366M, Ph+PgF:41789M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 9904, image: ORACLE.EXE (W000) *** 2025-07-27 10:06:29.054 *** SESSION ID:(177.36781) 2025-07-27 10:06:29.054 *** 2025-07-27 10:06:29.054 Process diagnostic dump for ORACLE.EXE (W000), OS id=9904, pid: 22, proc_ser: 40, sid: 177, sess_ser: 36781 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.055368 sec, exc=0.055368 sec, total=0.055368 sec wait times: max=5.000000 sec, heur=3 min 0 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.000033 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=36 seq_num=37 snap_id=1 wait times: snap=5.003204 sec, exc=5.003204 sec, total=5.003204 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=35 seq_num=36 snap_id=1 wait times: snap=5.011240 sec, exc=5.011240 sec, total=5.011240 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=5.004624 sec, exc=5.004624 sec, total=5.004624 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000046 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=5.014725 sec, exc=5.014725 sec, total=5.014725 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=5.001689 sec, exc=5.001689 sec, total=5.001689 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.001122 sec, exc=5.001122 sec, total=5.001122 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.000475 sec, exc=5.000475 sec, total=5.000475 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.001034 sec, exc=5.001034 sec, total=5.001034 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=5.007784 sec, exc=5.007784 sec, total=5.007784 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=5.004637 sec, exc=5.004637 sec, total=5.004637 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time Sampled Session History of session 177 serial 36781 --------------------------------------------------- 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, 10:04:29 - 10:06:29] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-27 10:06:29.054 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 9904, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-27 07:43:12.655558 :B7916D8F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18548 pso_num=22 pso_serial#=27 2025-07-27 07:43:12.655697 :B7916D90:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18548 osp_idx=0 osp_ver=456549 osp_pg=0 (spawn #427175) 2025-07-27 07:43:12.655698 :B7916D91:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 07:43:12.655698 :B7916D92:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=39 time=2282968548 2025-07-27 07:43:12.655699 :B7916D93:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 07:43:12.655699 :B7916D94:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 07:43:12.655699 :B7916D95:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 07:43:12.655699 :B7916D96:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 07:43:12.655699 :B7916D97:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 07:43:12.656197 :B7916D98: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-07-27 07:43:12.656243 :B7916DA2: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-07-27 07:53:13.375468 :B7923326:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 07:53:13.655905 :B792338B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 07:53:13.651 2025-07-27 07:53:13.655907 :B792338C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6844 pso_num=22 pso_serial#=28 2025-07-27 07:53:13.656045 :B792338D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6844 osp_idx=0 osp_ver=456550 osp_pg=0 (spawn #427198) 2025-07-27 07:53:13.656046 :B792338E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 07:53:13.656046 :B792338F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=40 time=2283569548 2025-07-27 07:53:13.656047 :B7923390:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 07:53:13.656047 :B7923391:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 07:53:13.656048 :B7923392:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 07:53:13.656048 :B7923393:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 07:53:13.656048 :B7923394:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 07:53:13.656536 :B7923395: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-07-27 07:53:13.656584 :B792339C: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-07-27 08:03:14.468853 :B792FB64:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 08:03:14.707950 :B792FBB1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 08:03:14.703 2025-07-27 08:03:14.707952 :B792FBB2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18676 pso_num=22 pso_serial#=29 2025-07-27 08:03:14.708084 :B792FBB3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18676 osp_idx=0 osp_ver=456551 osp_pg=0 (spawn #427224) 2025-07-27 08:03:14.708085 :B792FBB4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 08:03:14.708086 :B792FBB5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=41 time=2284170595 2025-07-27 08:03:14.708086 :B792FBB6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 08:03:14.708087 :B792FBB7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 08:03:14.708087 :B792FBB8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 08:03:14.708087 :B792FBB9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 08:03:14.708088 :B792FBBA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 08:03:14.708653 :B792FBBB: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-07-27 08:03:14.708696 :B792FBC2: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-07-27 08:13:15.529837 :B793C714:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 08:13:15.846946 :B793C776:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 08:13:15.842 2025-07-27 08:13:15.846948 :B793C777:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14640 pso_num=22 pso_serial#=30 2025-07-27 08:13:15.847089 :B793C778:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14640 osp_idx=0 osp_ver=456552 osp_pg=0 (spawn #427247) 2025-07-27 08:13:15.847090 :B793C779:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 08:13:15.847090 :B793C77A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=42 time=2284771736 2025-07-27 08:13:15.847090 :B793C77B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 08:13:15.847091 :B793C77C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 08:13:15.847091 :B793C77D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 08:13:15.847091 :B793C77E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 08:13:15.847092 :B793C77F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 08:13:15.847593 :B793C780: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-07-27 08:13:15.847636 :B793C787: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-07-27 08:23:16.694022 :B7948F39:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 08:23:16.964172 :B7948FA6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 08:23:16.959 2025-07-27 08:23:16.964174 :B7948FA7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6128 pso_num=22 pso_serial#=31 2025-07-27 08:23:16.964304 :B7948FA8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6128 osp_idx=0 osp_ver=456553 osp_pg=0 (spawn #427269) 2025-07-27 08:23:16.964304 :B7948FA9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 08:23:16.964304 :B7948FAA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=43 time=2285372861 2025-07-27 08:23:16.964305 :B7948FAB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 08:23:16.964305 :B7948FAC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 08:23:16.964306 :B7948FAD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 08:23:16.964306 :B7948FAE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 08:23:16.964306 :B7948FAF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 08:23:16.964847 :B7948FB0: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-07-27 08:23:16.964893 :B7948FB8: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-07-27 08:33:17.684081 :B7955497:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 08:33:18.079464 :B7955524:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 08:33:18.074 2025-07-27 08:33:18.079466 :B7955525:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6356 pso_num=22 pso_serial#=32 2025-07-27 08:33:18.079602 :B7955526:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6356 osp_idx=0 osp_ver=456554 osp_pg=0 (spawn #427292) 2025-07-27 08:33:18.079603 :B7955527:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 08:33:18.079604 :B7955528:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=44 time=2285973970 2025-07-27 08:33:18.079604 :B7955529:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 08:33:18.079605 :B795552A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 08:33:18.079605 :B795552B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 08:33:18.079605 :B795552C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 08:33:18.079606 :B795552D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 08:33:18.080104 :B795552E: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-07-27 08:33:18.080147 :B7955536: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-07-27 08:40:04.752526 :B795DC4E: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-07-27 08:43:19.348745 :B7961BF4: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-07-27 08:53:20.048442 :B796DFCB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 08:53:20.474953 :B796E04C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 08:53:20.470 2025-07-27 08:53:20.474955 :B796E04D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14860 pso_num=22 pso_serial#=33 2025-07-27 08:53:20.475094 :B796E04E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14860 osp_idx=0 osp_ver=456555 osp_pg=0 (spawn #427336) 2025-07-27 08:53:20.475094 :B796E04F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 08:53:20.475095 :B796E050:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=45 time=2287176376 2025-07-27 08:53:20.475096 :B796E051:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 08:53:20.475096 :B796E052:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 08:53:20.475096 :B796E053:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 08:53:20.475096 :B796E054:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 08:53:20.475097 :B796E055:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 08:53:20.475601 :B796E056: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-07-27 08:53:20.475647 :B796E05D: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-07-27 09:03:21.208217 :B797A7AD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 09:03:21.754425 :B797A805:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 09:03:21.749 2025-07-27 09:03:21.754427 :B797A806:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18888 pso_num=22 pso_serial#=34 2025-07-27 09:03:21.754562 :B797A807:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18888 osp_idx=0 osp_ver=456556 osp_pg=0 (spawn #427362) 2025-07-27 09:03:21.754563 :B797A808:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 09:03:21.754563 :B797A809:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=46 time=2287777642 2025-07-27 09:03:21.754564 :B797A80A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 09:03:21.754564 :B797A80B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 09:03:21.754564 :B797A80C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 09:03:21.754565 :B797A80D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 09:03:21.754565 :B797A80E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 09:03:21.755053 :B797A80F: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-07-27 09:03:21.755099 :B797A816: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-07-27 09:03:36.756650 :B797ACEF:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-07-27 09:03:36.756655 :B797ACF2:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-07-27 09:03:36.756656 :B797ACF4:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=7, exc=7, tot=7 2025-07-27 09:03:36.756664 :B797ACF8: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-07-27 09:13:22.564441 :B79878E8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 09:13:23.037962 :B798793C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 09:13:23.033 2025-07-27 09:13:23.037964 :B798793D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14392 pso_num=22 pso_serial#=35 2025-07-27 09:13:23.038100 :B798793E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14392 osp_idx=0 osp_ver=456557 osp_pg=0 (spawn #427385) 2025-07-27 09:13:23.038100 :B798793F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 09:13:23.038101 :B7987940:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=47 time=2288378939 2025-07-27 09:13:23.038102 :B7987941:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 09:13:23.038102 :B7987942:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 09:13:23.038102 :B7987943:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 09:13:23.038103 :B7987944:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 09:13:23.038103 :B7987945:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 09:13:23.038599 :B7987946: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-07-27 09:13:23.038645 :B798794E: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-07-27 09:23:23.709135 :B7993F07:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 09:23:24.182656 :B7993F69:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 09:23:24.178 2025-07-27 09:23:24.182658 :B7993F6A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15780 pso_num=22 pso_serial#=36 2025-07-27 09:23:24.182794 :B7993F6B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15780 osp_idx=0 osp_ver=456558 osp_pg=0 (spawn #427407) 2025-07-27 09:23:24.182795 :B7993F6C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 09:23:24.182795 :B7993F6D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=48 time=2288980079 2025-07-27 09:23:24.182795 :B7993F6E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 09:23:24.182796 :B7993F6F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 09:23:24.182796 :B7993F70:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 09:23:24.182796 :B7993F71:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 09:23:24.182797 :B7993F72:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 09:23:24.183298 :B7993F73: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-07-27 09:23:24.183347 :B7993F7B: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-07-27 09:33:24.965870 :B79A05A8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 09:33:25.361323 :B79A05FD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 09:33:25.356 2025-07-27 09:33:25.361325 :B79A05FE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11076 pso_num=22 pso_serial#=37 2025-07-27 09:33:25.361467 :B79A05FF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11076 osp_idx=0 osp_ver=456559 osp_pg=0 (spawn #427428) 2025-07-27 09:33:25.361467 :B79A0600:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 09:33:25.361468 :B79A0601:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=49 time=2289581251 2025-07-27 09:33:25.361468 :B79A0602:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 09:33:25.361469 :B79A0603:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 09:33:25.361469 :B79A0604:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 09:33:25.361470 :B79A0605:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 09:33:25.361471 :B79A0606:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 09:33:25.361978 :B79A0607: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-07-27 09:33:25.362023 :B79A060F: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-07-27 09:43:26.092062 :B79ACB5F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 09:43:26.534218 :B79ACBB7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 09:43:26.530 2025-07-27 09:43:26.534221 :B79ACBB8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18704 pso_num=22 pso_serial#=38 2025-07-27 09:43:26.534358 :B79ACBB9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18704 osp_idx=0 osp_ver=456560 osp_pg=0 (spawn #427451) 2025-07-27 09:43:26.534358 :B79ACBBA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 09:43:26.534359 :B79ACBBB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=50 time=2290182423 2025-07-27 09:43:26.534359 :B79ACBBC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 09:43:26.534359 :B79ACBBD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 09:43:26.534360 :B79ACBBE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 09:43:26.534360 :B79ACBBF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 09:43:26.534361 :B79ACBC0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 09:43:26.534835 :B79ACBC1: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-07-27 09:43:26.534886 :B79ACBCA: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-07-27 09:53:27.271579 :B79B90A0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 09:53:27.667112 :B79B9102:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 09:53:27.662 2025-07-27 09:53:27.667114 :B79B9103:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7320 pso_num=22 pso_serial#=39 2025-07-27 09:53:27.667254 :B79B9104:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7320 osp_idx=0 osp_ver=456561 osp_pg=0 (spawn #427473) 2025-07-27 09:53:27.667255 :B79B9105:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 09:53:27.667255 :B79B9106:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=51 time=2290783564 2025-07-27 09:53:27.667256 :B79B9107:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 09:53:27.667256 :B79B9108:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 09:53:27.667257 :B79B9109:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 09:53:27.667257 :B79B910A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 09:53:27.667257 :B79B910B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 09:53:27.667735 :B79B910C: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-07-27 09:53:27.667784 :B79B9115: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-07-27 10:03:28.477077 :B79C58D9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-27 10:03:28.763295 :B79C5918:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-27 10:03:28.758 2025-07-27 10:03:28.763297 :B79C5919:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9904 pso_num=22 pso_serial#=40 2025-07-27 10:03:28.763437 :B79C591A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9904 osp_idx=0 osp_ver=456562 osp_pg=0 (spawn #427499) 2025-07-27 10:03:28.763438 :B79C591B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 10:03:28.763438 :B79C591C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=52 time=2291384658 2025-07-27 10:03:28.763439 :B79C591D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 10:03:28.763439 :B79C591E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 10:03:28.763439 :B79C591F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 10:03:28.763440 :B79C5920:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 10:03:28.763440 :B79C5921:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 10:03:28.763951 :B79C5922: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-07-27 10:03:28.764007 :B79C592B: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: 9904, W000)