Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250607100443\orcl_w000_13360_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:36840M/63366M, Ph+PgF:43502M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13360, image: ORACLE.EXE (W000) *** 2025-06-07 10:04:43.717 *** SESSION ID:(177.64717) 2025-06-07 10:04:43.717 *** 2025-06-07 10:04:43.717 Process diagnostic dump for ORACLE.EXE (W000), OS id=13360, pid: 22, proc_ser: 132, sid: 177, sess_ser: 64717 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=151 seq_num=152 snap_id=1 wait times: snap=0.752432 sec, exc=0.752432 sec, total=0.752432 sec wait times: max=5.000000 sec, heur=8 min 12 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.000030 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=150 seq_num=151 snap_id=1 wait times: snap=5.004608 sec, exc=5.004608 sec, total=5.004608 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=149 seq_num=150 snap_id=1 wait times: snap=5.014720 sec, exc=5.014720 sec, total=5.014720 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=148 seq_num=149 snap_id=1 wait times: snap=5.001709 sec, exc=5.001709 sec, total=5.001709 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=147 seq_num=148 snap_id=1 wait times: snap=5.001131 sec, exc=5.001131 sec, total=5.001131 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=146 seq_num=147 snap_id=1 wait times: snap=5.001427 sec, exc=5.001427 sec, total=5.001427 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=145 seq_num=146 snap_id=1 wait times: snap=5.013902 sec, exc=5.013902 sec, total=5.013902 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=144 seq_num=145 snap_id=1 wait times: snap=5.004618 sec, exc=5.004618 sec, total=5.004618 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000039 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=143 seq_num=144 snap_id=1 wait times: snap=5.004642 sec, exc=5.004642 sec, total=5.004642 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=142 seq_num=143 snap_id=1 wait times: snap=5.014719 sec, exc=5.014719 sec, total=5.014719 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=141 seq_num=142 snap_id=1 wait times: snap=5.004578 sec, exc=5.004578 sec, total=5.004578 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000050 sec of elapsed time Sampled Session History of session 177 serial 64717 --------------------------------------------------- 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:02:43 - 10:04:43] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-07 10:04:43.717 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13360, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-07 07:32:05.601709 :A16AFCF8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15544 osp_idx=0 osp_ver=274316 osp_pg=0 (spawn #260462) 2025-06-07 07:32:05.601709 :A16AFCF9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 07:32:05.601710 :A16AFCFA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=228 time=2257284250 2025-06-07 07:32:05.601710 :A16AFCFB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 07:32:05.601710 :A16AFCFC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 07:32:05.601711 :A16AFCFD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 07:32:05.601711 :A16AFCFE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 07:32:05.601711 :A16AFCFF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 07:32:05.602232 :A16AFD00:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 07:32:05.602288 :A16AFD0A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 07:42:06.432591 :A16BC795:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 07:42:06.874821 :A16BC7E8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 07:42:06.870 2025-06-07 07:42:06.874823 :A16BC7E9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15804 pso_num=22 pso_serial#=120 2025-06-07 07:42:06.874969 :A16BC7EA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15804 osp_idx=0 osp_ver=274317 osp_pg=0 (spawn #260485) 2025-06-07 07:42:06.874970 :A16BC7EB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 07:42:06.874970 :A16BC7EC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=229 time=2257885516 2025-06-07 07:42:06.874971 :A16BC7ED:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 07:42:06.874971 :A16BC7EE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 07:42:06.874972 :A16BC7EF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 07:42:06.874972 :A16BC7F0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 07:42:06.874972 :A16BC7F1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 07:42:06.875455 :A16BC7F2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 07:42:06.875498 :A16BC7F9:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 07:52:07.677945 :A16C9085:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 07:52:08.057671 :A16C90B7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 07:52:08.053 2025-06-07 07:52:08.057674 :A16C90B8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12920 pso_num=22 pso_serial#=121 2025-06-07 07:52:08.057818 :A16C90B9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12920 osp_idx=0 osp_ver=274318 osp_pg=0 (spawn #260507) 2025-06-07 07:52:08.057819 :A16C90BA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 07:52:08.057819 :A16C90BB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=230 time=2258486704 2025-06-07 07:52:08.057820 :A16C90BC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 07:52:08.057820 :A16C90BD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 07:52:08.057820 :A16C90BE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 07:52:08.057821 :A16C90BF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 07:52:08.057821 :A16C90C0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 07:52:08.058320 :A16C90C1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 07:52:08.058368 :A16C90C7:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 07:53:16.983551 :A16CA87C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-07 08:02:09.232826 :A16D5BBF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-07 08:12:09.997515 :A16E2A8B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 08:12:10.403044 :A16E2AC2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 08:12:10.397 2025-06-07 08:12:10.403047 :A16E2AC3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8276 pso_num=22 pso_serial#=122 2025-06-07 08:12:10.403195 :A16E2AC4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8276 osp_idx=0 osp_ver=274319 osp_pg=0 (spawn #260555) 2025-06-07 08:12:10.403196 :A16E2AC5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 08:12:10.403196 :A16E2AC6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=231 time=2259689047 2025-06-07 08:12:10.403197 :A16E2AC7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 08:12:10.403197 :A16E2AC8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 08:12:10.403198 :A16E2AC9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 08:12:10.403198 :A16E2ACA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 08:12:10.403198 :A16E2ACB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 08:12:10.403721 :A16E2ACC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 08:12:10.403767 :A16E2AD3:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 08:22:11.391464 :A16EF66B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 08:22:11.552417 :A16EF6A2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 08:22:11.548 2025-06-07 08:22:11.552419 :A16EF6A3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15864 pso_num=22 pso_serial#=123 2025-06-07 08:22:11.552563 :A16EF6A4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15864 osp_idx=0 osp_ver=274320 osp_pg=0 (spawn #260577) 2025-06-07 08:22:11.552563 :A16EF6A5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 08:22:11.552564 :A16EF6A6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=232 time=2260290204 2025-06-07 08:22:11.552564 :A16EF6A7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 08:22:11.552565 :A16EF6A8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 08:22:11.552565 :A16EF6A9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 08:22:11.552565 :A16EF6AA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 08:22:11.552566 :A16EF6AB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 08:22:11.553054 :A16EF6AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 08:22:11.553100 :A16EF6B4:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 08:32:12.428795 :A16FC086:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 08:32:12.636645 :A16FC0D3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 08:32:12.631 2025-06-07 08:32:12.636648 :A16FC0D4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16352 pso_num=22 pso_serial#=124 2025-06-07 08:32:12.636786 :A16FC0D5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16352 osp_idx=0 osp_ver=274321 osp_pg=0 (spawn #260600) 2025-06-07 08:32:12.636787 :A16FC0D6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 08:32:12.636787 :A16FC0D7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=233 time=2260891282 2025-06-07 08:32:12.636788 :A16FC0D8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 08:32:12.636788 :A16FC0D9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 08:32:12.636789 :A16FC0DA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 08:32:12.636789 :A16FC0DB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 08:32:12.636789 :A16FC0DC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 08:32:12.637279 :A16FC0DD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 08:32:12.637322 :A16FC0E6:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 08:42:13.482722 :A1708A46:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 08:42:13.862419 :A1708AB2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 08:42:13.857 2025-06-07 08:42:13.862421 :A1708AB3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12004 pso_num=22 pso_serial#=125 2025-06-07 08:42:13.862568 :A1708AB4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12004 osp_idx=0 osp_ver=274322 osp_pg=0 (spawn #260623) 2025-06-07 08:42:13.862568 :A1708AB5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 08:42:13.862569 :A1708AB6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=234 time=2261492516 2025-06-07 08:42:13.862569 :A1708AB7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 08:42:13.862570 :A1708AB8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 08:42:13.862570 :A1708AB9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 08:42:13.862570 :A1708ABA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 08:42:13.862571 :A1708ABB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 08:42:13.863083 :A1708ABC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 08:42:13.863128 :A1708AC4:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 08:52:14.709990 :A1715407:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 08:52:14.933373 :A171547E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 08:52:14.929 2025-06-07 08:52:14.933375 :A171547F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11776 pso_num=22 pso_serial#=126 2025-06-07 08:52:14.933512 :A1715480:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11776 osp_idx=0 osp_ver=274323 osp_pg=0 (spawn #260646) 2025-06-07 08:52:14.933512 :A1715481:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 08:52:14.933513 :A1715482:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=235 time=2262093579 2025-06-07 08:52:14.933513 :A1715483:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 08:52:14.933514 :A1715484:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 08:52:14.933514 :A1715485:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 08:52:14.933514 :A1715486:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 08:52:14.933515 :A1715487:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 08:52:14.933992 :A1715488:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 08:52:14.934037 :A171548E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 08:52:29.965987 :A1715968: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-06-07 08:52:29.966002 :A1715970: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-06-07 08:52:29.966003 :A1715971:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=14, exc=14, tot=14 2025-06-07 09:02:15.766924 :A1721F8C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 09:02:16.024496 :A1721FBF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 09:02:16.020 2025-06-07 09:02:16.024498 :A1721FC0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14216 pso_num=22 pso_serial#=127 2025-06-07 09:02:16.024640 :A1721FC1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14216 osp_idx=0 osp_ver=274324 osp_pg=0 (spawn #260671) 2025-06-07 09:02:16.024641 :A1721FC2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 09:02:16.024642 :A1721FC3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=236 time=2262694672 2025-06-07 09:02:16.024642 :A1721FC4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 09:02:16.024642 :A1721FC5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 09:02:16.024643 :A1721FC6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 09:02:16.024643 :A1721FC7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 09:02:16.024643 :A1721FC8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 09:02:16.025134 :A1721FC9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 09:02:16.025180 :A1721FD1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 09:12:16.886374 :A172F2B1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 09:12:17.062925 :A172F2FC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 09:12:17.058 2025-06-07 09:12:17.062927 :A172F2FD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15964 pso_num=22 pso_serial#=128 2025-06-07 09:12:17.063071 :A172F2FE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15964 osp_idx=0 osp_ver=274325 osp_pg=0 (spawn #260695) 2025-06-07 09:12:17.063071 :A172F2FF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 09:12:17.063072 :A172F300:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=237 time=2263295704 2025-06-07 09:12:17.063072 :A172F301:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 09:12:17.063073 :A172F302:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 09:12:17.063073 :A172F303:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 09:12:17.063073 :A172F304:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 09:12:17.063074 :A172F305:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 09:12:17.063573 :A172F306:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 09:12:17.063618 :A172F30E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 09:22:17.951132 :A173BB80:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 09:22:18.221543 :A173BBBD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 09:22:18.216 2025-06-07 09:22:18.221545 :A173BBBE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14276 pso_num=22 pso_serial#=129 2025-06-07 09:22:18.221686 :A173BBBF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14276 osp_idx=0 osp_ver=274326 osp_pg=0 (spawn #260717) 2025-06-07 09:22:18.221686 :A173BBC0:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 09:22:18.221687 :A173BBC1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=238 time=2263896875 2025-06-07 09:22:18.221687 :A173BBC2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 09:22:18.221688 :A173BBC3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 09:22:18.221688 :A173BBC4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 09:22:18.221688 :A173BBC5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 09:22:18.221689 :A173BBC6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 09:22:18.222184 :A173BBC7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 09:22:18.222230 :A173BBCF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 09:32:19.103323 :A174859D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 09:32:19.399642 :A17485D7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 09:32:19.394 2025-06-07 09:32:19.399644 :A17485D8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14140 pso_num=22 pso_serial#=130 2025-06-07 09:32:19.399785 :A17485D9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14140 osp_idx=0 osp_ver=274327 osp_pg=0 (spawn #260740) 2025-06-07 09:32:19.399785 :A17485DA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 09:32:19.399786 :A17485DB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=239 time=2264498047 2025-06-07 09:32:19.399786 :A17485DC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 09:32:19.399786 :A17485DD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 09:32:19.399787 :A17485DE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 09:32:19.399787 :A17485DF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 09:32:19.399787 :A17485E0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 09:32:19.400274 :A17485E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 09:32:19.400317 :A17485E7:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 09:42:20.201484 :A1754ECF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 09:42:20.503045 :A1754F05:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 09:42:20.498 2025-06-07 09:42:20.503049 :A1754F06:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16192 pso_num=22 pso_serial#=131 2025-06-07 09:42:20.503189 :A1754F07:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16192 osp_idx=0 osp_ver=274328 osp_pg=0 (spawn #260763) 2025-06-07 09:42:20.503189 :A1754F08:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 09:42:20.503190 :A1754F09:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=240 time=2265099157 2025-06-07 09:42:20.503190 :A1754F0A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 09:42:20.503190 :A1754F0B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 09:42:20.503191 :A1754F0C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 09:42:20.503191 :A1754F0D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 09:42:20.503191 :A1754F0E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 09:42:20.503677 :A1754F0F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 09:42:20.503720 :A1754F17:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 09:52:21.234729 :A1761853:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-07 09:52:21.583614 :A176188D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-07 09:52:21.578 2025-06-07 09:52:21.583617 :A176188E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13360 pso_num=22 pso_serial#=132 2025-06-07 09:52:21.583769 :A176188F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13360 osp_idx=0 osp_ver=274329 osp_pg=0 (spawn #260785) 2025-06-07 09:52:21.583770 :A1761890:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 09:52:21.583770 :A1761891:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=241 time=2265700235 2025-06-07 09:52:21.583771 :A1761892:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 09:52:21.583771 :A1761893:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 09:52:21.583771 :A1761894:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 09:52:21.583772 :A1761895:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 09:52:21.583772 :A1761896:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 09:52:21.584365 :A1761897:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-07 09:52:21.584412 :A176189E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-07 09:56:31.074313 :A1766C7C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-07 10:02:22.747981 :A176E345: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 13360, W000)