Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250525081205\orcl_w000_9492_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:37283M/63366M, Ph+PgF:44291M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 9492, image: ORACLE.EXE (W000) *** 2025-05-25 08:12:05.236 *** SESSION ID:(193.18691) 2025-05-25 08:12:05.236 *** 2025-05-25 08:12:05.236 Process diagnostic dump for ORACLE.EXE (W000), OS id=9492, pid: 24, proc_ser: 171, sid: 193, sess_ser: 18691 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.096778 sec, exc=0.096778 sec, total=0.096778 sec wait times: max=5.000000 sec, heur=10.105828 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.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=5.015267 sec, exc=5.015267 sec, total=5.015267 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=4.993739 sec, exc=4.993739 sec, total=4.993739 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.004005 sec of elapsed time 2: waited for 'class slave wait' slave id=0x11b93b80, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.000042 sec, exc=0.000042 sec, total=0.000042 sec wait times: max=infinite wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 193 serial 18691 --------------------------------------------------- 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 --------------------------------------------------- [11 samples, 08:11:55 - 08:12:05] idle wait at each sample [session created at: 08:11:55] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-25 08:12:05.236 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 9492, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-25 06:01:37.983787 :9BAE6E18:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 06:01:37.983787 :9BAE6E19:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 06:01:37.983788 :9BAE6E1A:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 06:01:37.984275 :9BAE6E1B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 06:01:37.984332 :9BAE6E21:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 06:11:38.832432 :9BAF4157:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 06:11:39.415382 :9BAF419E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 06:11:39.410 2025-05-25 06:11:39.415384 :9BAF419F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12820 pso_num=24 pso_serial#=158 2025-05-25 06:11:39.415524 :9BAF41A0:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12820 osp_idx=22 osp_ver=319417 osp_pg=0 (spawn #216971) 2025-05-25 06:11:39.415524 :9BAF41A1:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 06:11:39.415525 :9BAF41A2:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=5 time=1129271672 2025-05-25 06:11:39.415525 :9BAF41A3:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 06:11:39.415526 :9BAF41A4:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 06:11:39.415526 :9BAF41A5:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 06:11:39.415526 :9BAF41A6:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 06:11:39.415527 :9BAF41A7:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 06:11:39.416024 :9BAF41A8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 06:11:39.416065 :9BAF41B0:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 06:15:56.615264 :9BAF9674:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 06:21:40.852601 :9BB00696:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 06:21:40.852653 :9BB00697:db_trace:ksl2.c@2477:kslwtbctx(): [10005:24:193] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-05-25 06:21:40.852726 :9BB0069D:db_trace:ksl2.c@2611:kslwtectx(): [10005:24:193] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-05-25 06:21:40.852727 :9BB0069E:db_trace:ksl2.c@2619:kslwtectx(): [10005:24:193] KSL WAIT END wait times (usecs) - snap=74, exc=74, tot=74 2025-05-25 06:31:41.825143 :9BB0CC33:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 06:31:42.142155 :9BB0CC67:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 06:31:42.137 2025-05-25 06:31:42.142156 :9BB0CC68:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12968 pso_num=24 pso_serial#=159 2025-05-25 06:31:42.142300 :9BB0CC69:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12968 osp_idx=22 osp_ver=319418 osp_pg=0 (spawn #217016) 2025-05-25 06:31:42.142301 :9BB0CC6A:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 06:31:42.142301 :9BB0CC6B:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=6 time=1130474391 2025-05-25 06:31:42.142302 :9BB0CC6C:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 06:31:42.142302 :9BB0CC6D:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 06:31:42.142302 :9BB0CC6E:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 06:31:42.142303 :9BB0CC6F:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 06:31:42.142303 :9BB0CC70:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 06:31:42.142806 :9BB0CC71:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 06:31:42.142850 :9BB0CC79:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 06:41:43.047801 :9BB19238:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 06:41:43.474377 :9BB192A9:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 06:41:43.469 2025-05-25 06:41:43.474379 :9BB192AA:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15088 pso_num=24 pso_serial#=160 2025-05-25 06:41:43.474553 :9BB192AB:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15088 osp_idx=22 osp_ver=319419 osp_pg=0 (spawn #217038) 2025-05-25 06:41:43.474554 :9BB192AC:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 06:41:43.474554 :9BB192AD:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=7 time=1131075735 2025-05-25 06:41:43.474555 :9BB192AE:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 06:41:43.474555 :9BB192AF:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 06:41:43.474556 :9BB192B0:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 06:41:43.474556 :9BB192B1:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 06:41:43.474557 :9BB192B2:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 06:41:43.475080 :9BB192B3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 06:41:43.475127 :9BB192BA:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 06:51:44.400892 :9BB258F9:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 06:51:44.733876 :9BB25968:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 06:51:44.728 2025-05-25 06:51:44.733878 :9BB25969:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12968 pso_num=24 pso_serial#=161 2025-05-25 06:51:44.734022 :9BB2596A:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12968 osp_idx=22 osp_ver=319420 osp_pg=0 (spawn #217062) 2025-05-25 06:51:44.734022 :9BB2596B:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 06:51:44.734023 :9BB2596C:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=8 time=1131676985 2025-05-25 06:51:44.734023 :9BB2596D:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 06:51:44.734023 :9BB2596E:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 06:51:44.734024 :9BB2596F:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 06:51:44.734024 :9BB25970:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 06:51:44.734024 :9BB25971:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 06:51:44.734531 :9BB25972:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 06:51:44.734577 :9BB2597A:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:01:45.635628 :9BB3213D:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 07:01:46.015384 :9BB321B0:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 07:01:46.011 2025-05-25 07:01:46.015386 :9BB321B1:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14652 pso_num=24 pso_serial#=162 2025-05-25 07:01:46.015527 :9BB321B2:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14652 osp_idx=22 osp_ver=319421 osp_pg=0 (spawn #217087) 2025-05-25 07:01:46.015528 :9BB321B3:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 07:01:46.015528 :9BB321B4:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=9 time=1132278266 2025-05-25 07:01:46.015529 :9BB321B5:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 07:01:46.015529 :9BB321B6:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 07:01:46.015529 :9BB321B7:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 07:01:46.015530 :9BB321B8:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 07:01:46.015530 :9BB321B9:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 07:01:46.016033 :9BB321BA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 07:01:46.016092 :9BB321C3:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:11:46.876587 :9BB3EF96:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 07:11:47.209405 :9BB3EFD1:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 07:11:47.204 2025-05-25 07:11:47.209407 :9BB3EFD2:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11796 pso_num=24 pso_serial#=163 2025-05-25 07:11:47.209544 :9BB3EFD3:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=11796 osp_idx=22 osp_ver=319422 osp_pg=0 (spawn #217110) 2025-05-25 07:11:47.209545 :9BB3EFD4:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 07:11:47.209545 :9BB3EFD5:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=10 time=1132879469 2025-05-25 07:11:47.209546 :9BB3EFD6:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 07:11:47.209546 :9BB3EFD7:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 07:11:47.209546 :9BB3EFD8:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 07:11:47.209547 :9BB3EFD9:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 07:11:47.209547 :9BB3EFDA:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 07:11:47.210033 :9BB3EFDB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 07:11:47.210077 :9BB3EFE2:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:21:48.206838 :9BB4B511:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 07:21:48.570982 :9BB4B557:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 07:21:48.566 2025-05-25 07:21:48.570984 :9BB4B558:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14828 pso_num=24 pso_serial#=164 2025-05-25 07:21:48.571121 :9BB4B559:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14828 osp_idx=22 osp_ver=319423 osp_pg=0 (spawn #217133) 2025-05-25 07:21:48.571122 :9BB4B55A:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 07:21:48.571123 :9BB4B55B:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=11 time=1133480829 2025-05-25 07:21:48.571123 :9BB4B55C:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 07:21:48.571124 :9BB4B55D:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 07:21:48.571125 :9BB4B55E:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 07:21:48.571125 :9BB4B55F:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 07:21:48.571126 :9BB4B560:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 07:21:48.571631 :9BB4B561:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 07:21:48.571678 :9BB4B56A:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:31:49.636212 :9BB57A2E:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 07:31:49.890996 :9BB57A66:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 07:31:49.886 2025-05-25 07:31:49.890998 :9BB57A67:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12148 pso_num=24 pso_serial#=165 2025-05-25 07:31:49.891174 :9BB57A68:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12148 osp_idx=22 osp_ver=319424 osp_pg=0 (spawn #217156) 2025-05-25 07:31:49.891175 :9BB57A69:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 07:31:49.891176 :9BB57A6A:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=12 time=1134082141 2025-05-25 07:31:49.891176 :9BB57A6B:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 07:31:49.891176 :9BB57A6C:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 07:31:49.891176 :9BB57A6D:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 07:31:49.891177 :9BB57A6E:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 07:31:49.891177 :9BB57A6F:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 07:31:49.891704 :9BB57A70:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 07:31:49.891747 :9BB57A78:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:41:50.891045 :9BB63EED:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 07:41:51.223865 :9BB63F2F:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 07:41:51.219 2025-05-25 07:41:51.223867 :9BB63F30:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14748 pso_num=24 pso_serial#=166 2025-05-25 07:41:51.224005 :9BB63F31:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14748 osp_idx=22 osp_ver=319425 osp_pg=0 (spawn #217178) 2025-05-25 07:41:51.224005 :9BB63F32:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 07:41:51.224006 :9BB63F33:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=13 time=1134683485 2025-05-25 07:41:51.224006 :9BB63F34:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 07:41:51.224006 :9BB63F35:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 07:41:51.224007 :9BB63F36:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 07:41:51.224007 :9BB63F37:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 07:41:51.224007 :9BB63F38:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 07:41:51.224500 :9BB63F39:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 07:41:51.224544 :9BB63F40:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:51:52.137139 :9BB70242:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 07:51:52.563719 :9BB7027B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 07:51:52.559 2025-05-25 07:51:52.563722 :9BB7027C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15280 pso_num=24 pso_serial#=167 2025-05-25 07:51:52.563881 :9BB7027D:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15280 osp_idx=22 osp_ver=319426 osp_pg=0 (spawn #217201) 2025-05-25 07:51:52.563881 :9BB7027E:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 07:51:52.563882 :9BB7027F:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=14 time=1135284813 2025-05-25 07:51:52.563882 :9BB70280:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 07:51:52.563883 :9BB70281:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 07:51:52.563883 :9BB70282:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 07:51:52.563883 :9BB70283:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 07:51:52.563884 :9BB70284:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 07:51:52.564383 :9BB70285:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 07:51:52.564438 :9BB7028D:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:52:22.611230 :9BB70C64:db_trace:ksl2.c@2477:kslwtbctx(): [10005:24:193] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-25 07:52:22.611236 :9BB70C65:db_trace:ksl2.c@2611:kslwtectx(): [10005:24:193] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-05-25 07:52:22.611236 :9BB70C66:db_trace:ksl2.c@2619:kslwtectx(): [10005:24:193] KSL WAIT END wait times (usecs) - snap=7, exc=7, tot=7 2025-05-25 07:52:22.611246 :9BB70C6B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 07:52:52.659683 :9BB71654:db_trace:ksl2.c@2477:kslwtbctx(): [10005:24:193] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=15 seq_num=16 snap_id=1 2025-05-25 07:52:52.659705 :9BB7165A:db_trace:ksl2.c@2611:kslwtectx(): [10005:24:193] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=15 seq_num=16 snap_id=1 2025-05-25 07:52:52.659706 :9BB7165B:db_trace:ksl2.c@2619:kslwtectx(): [10005:24:193] KSL WAIT END wait times (usecs) - snap=22, exc=22, tot=22 2025-05-25 08:01:53.562865 :9BB7C7CC:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 08:01:53.835277 :9BB7C811:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 08:01:53.830 2025-05-25 08:01:53.835279 :9BB7C812:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=13548 pso_num=24 pso_serial#=168 2025-05-25 08:01:53.835412 :9BB7C813:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=13548 osp_idx=22 osp_ver=319427 osp_pg=0 (spawn #217226) 2025-05-25 08:01:53.835413 :9BB7C814:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 08:01:53.835414 :9BB7C815:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=15 time=1135886094 2025-05-25 08:01:53.835414 :9BB7C816:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 08:01:53.835414 :9BB7C817:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 08:01:53.835415 :9BB7C818:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 08:01:53.835415 :9BB7C819:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 08:01:53.835415 :9BB7C81A:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 08:01:53.835914 :9BB7C81B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 08:01:53.835958 :9BB7C822:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 08:11:54.921151 :9BB8962A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 08:11:55.029081 :9BB8962D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 08:11:55.015 2025-05-25 08:11:55.029083 :9BB8962E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14408 pso_num=24 pso_serial#=169 2025-05-25 08:11:55.029222 :9BB8962F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=14408 (legacy spawn) 2025-05-25 08:11:55.035659 :9BB89630:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 08:11:55.035837 :9BB89635:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 08:11:55.036650 :9BB8963A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 08:11:55.054329 :9BB8963D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 08:11:55.046 2025-05-25 08:11:55.054331 :9BB8963E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=4696 pso_num=24 pso_serial#=170 2025-05-25 08:11:55.054474 :9BB8963F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=4696 (legacy spawn) 2025-05-25 08:11:55.060912 :9BB89640:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 08:11:55.061076 :9BB89649:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 08:11:55.061893 :9BB8964A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-25 08:11:55.128784 :9BB89684:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-25 08:11:55.124 2025-05-25 08:11:55.128786 :9BB89685:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9492 pso_num=24 pso_serial#=171 2025-05-25 08:11:55.128926 :9BB89686:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=9492 osp_idx=22 osp_ver=319430 osp_pg=0 (spawn #217249) 2025-05-25 08:11:55.128927 :9BB89687:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 08:11:55.128927 :9BB89688:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=16 time=1136487375 2025-05-25 08:11:55.128928 :9BB89689:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 08:11:55.128928 :9BB8968A:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 08:11:55.128928 :9BB8968B:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 08:11:55.128929 :9BB8968C:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 08:11:55.128929 :9BB8968D:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 08:11:55.129418 :9BB8968E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 08:11:55.129467 :9BB89696:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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 24 (osid: 9492, W000)