Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250526081257\orcl_w000_7792_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:37294M/63366M, Ph+PgF:44298M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 7792, image: ORACLE.EXE (W000) *** 2025-05-26 08:12:57.463 *** SESSION ID:(201.6125) 2025-05-26 08:12:57.463 *** 2025-05-26 08:12:57.463 Process diagnostic dump for ORACLE.EXE (W000), OS id=7792, pid: 25, proc_ser: 250, sid: 201, sess_ser: 6125 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=95 seq_num=96 snap_id=1 wait times: snap=1.225216 sec, exc=1.225216 sec, total=1.225216 sec wait times: max=5.000000 sec, heur=7 min 51 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000025 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=94 seq_num=95 snap_id=1 wait times: snap=5.000158 sec, exc=5.000158 sec, total=5.000158 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=93 seq_num=94 snap_id=1 wait times: snap=5.015230 sec, exc=5.015230 sec, total=5.015230 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=92 seq_num=93 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.000023 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=91 seq_num=92 snap_id=1 wait times: snap=5.004636 sec, exc=5.004636 sec, total=5.004636 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=90 seq_num=91 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.000024 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=89 seq_num=90 snap_id=1 wait times: snap=5.014703 sec, exc=5.014703 sec, total=5.014703 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000046 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=88 seq_num=89 snap_id=1 wait times: snap=5.015224 sec, exc=5.015224 sec, total=5.015224 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=87 seq_num=88 snap_id=1 wait times: snap=5.002154 sec, exc=5.002154 sec, total=5.002154 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000079 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=86 seq_num=87 snap_id=1 wait times: snap=5.011189 sec, exc=5.011189 sec, total=5.011189 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000039 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=85 seq_num=86 snap_id=1 wait times: snap=5.004627 sec, exc=5.004627 sec, total=5.004627 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time Sampled Session History of session 201 serial 6125 --------------------------------------------------- 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, 08:10:57 - 08:12:57] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-26 08:12:57.463 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 7792, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-26 06:04:49.701864 :9C1F4962:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:04:50.050231 :9C1F49B5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:04:50.045 2025-05-26 06:04:50.050233 :9C1F49B6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14612 pso_num=25 pso_serial#=235 2025-05-26 06:04:50.050372 :9C1F49B7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14612 osp_idx=23 osp_ver=120084 osp_pg=0 (spawn #220282) 2025-05-26 06:04:50.050372 :9C1F49B8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 06:04:50.050373 :9C1F49B9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=84 time=1215262297 2025-05-26 06:04:50.050373 :9C1F49BA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 06:04:50.050374 :9C1F49BB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 06:04:50.050374 :9C1F49BC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 06:04:50.050374 :9C1F49BD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 06:04:50.050375 :9C1F49BE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 06:04:50.050871 :9C1F49BF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 06:04:50.050916 :9C1F49C6:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 06:14:50.990705 :9C2014C6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:14:51.040664 :9C2014C9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:14:51.037 2025-05-26 06:14:51.040666 :9C2014CA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6844 pso_num=25 pso_serial#=236 2025-05-26 06:14:51.040817 :9C2014CB:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=6844 (legacy spawn) 2025-05-26 06:14:51.047273 :9C2014CC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-26 06:14:51.047445 :9C2014D1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-26 06:14:51.048251 :9C2014D6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:14:51.057249 :9C2014D9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:14:51.053 2025-05-26 06:14:51.057250 :9C2014DA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14768 pso_num=25 pso_serial#=237 2025-05-26 06:14:51.057390 :9C2014DB:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=14768 (legacy spawn) 2025-05-26 06:14:51.063831 :9C2014DC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-26 06:14:51.064000 :9C2014E3:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-26 06:14:51.064788 :9C2014E6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:14:51.292185 :9C201565:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:14:51.287 2025-05-26 06:14:51.292189 :9C201566:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14056 pso_num=25 pso_serial#=238 2025-05-26 06:14:51.292331 :9C201567:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14056 osp_idx=23 osp_ver=120087 osp_pg=0 (spawn #220304) 2025-05-26 06:14:51.292332 :9C201568:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 06:14:51.292332 :9C201569:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=85 time=1215863547 2025-05-26 06:14:51.292332 :9C20156A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 06:14:51.292333 :9C20156B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 06:14:51.292333 :9C20156C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 06:14:51.292333 :9C20156D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 06:14:51.292334 :9C20156E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 06:14:51.292816 :9C20156F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 06:14:51.292859 :9C201578:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 06:24:52.325326 :9C20DAD3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:24:52.579896 :9C20DB16:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:24:52.575 2025-05-26 06:24:52.579898 :9C20DB17:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14832 pso_num=25 pso_serial#=239 2025-05-26 06:24:52.580034 :9C20DB18:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14832 osp_idx=23 osp_ver=120088 osp_pg=0 (spawn #220327) 2025-05-26 06:24:52.580035 :9C20DB19:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 06:24:52.580035 :9C20DB1A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=86 time=1216464829 2025-05-26 06:24:52.580036 :9C20DB1B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 06:24:52.580036 :9C20DB1C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 06:24:52.580036 :9C20DB1D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 06:24:52.580037 :9C20DB1E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 06:24:52.580037 :9C20DB1F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 06:24:52.580538 :9C20DB20:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 06:24:52.580583 :9C20DB28:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 06:34:53.601203 :9C21A08F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:34:53.603226 :9C21A092:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:34:53.601 2025-05-26 06:34:53.603232 :9C21A093:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11092 pso_num=25 pso_serial#=240 2025-05-26 06:34:53.603359 :9C21A094:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=11092 (legacy spawn) 2025-05-26 06:34:53.609698 :9C21A095:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-26 06:34:53.609876 :9C21A09A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-26 06:34:53.610715 :9C21A09F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:34:53.619374 :9C21A0A2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:34:53.617 2025-05-26 06:34:53.619375 :9C21A0A3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13172 pso_num=25 pso_serial#=241 2025-05-26 06:34:53.619515 :9C21A0A4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13172 (legacy spawn) 2025-05-26 06:34:53.625995 :9C21A0A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-26 06:34:53.626162 :9C21A0AE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-26 06:34:53.626959 :9C21A0AF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:34:53.881586 :9C21A0E6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:34:53.877 2025-05-26 06:34:53.881588 :9C21A0E7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12904 pso_num=25 pso_serial#=242 2025-05-26 06:34:53.881737 :9C21A0E8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12904 osp_idx=23 osp_ver=120091 osp_pg=0 (spawn #220350) 2025-05-26 06:34:53.881738 :9C21A0E9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 06:34:53.881738 :9C21A0EA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=87 time=1217066141 2025-05-26 06:34:53.881739 :9C21A0EB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 06:34:53.881739 :9C21A0EC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 06:34:53.881739 :9C21A0ED:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 06:34:53.881740 :9C21A0EE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 06:34:53.881740 :9C21A0EF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 06:34:53.882240 :9C21A0F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 06:34:53.882286 :9C21A0F7:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 06:43:23.887994 :9C224848:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-26 06:44:55.127428 :9C226753:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-26 06:44:55.127462 :9C226754:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-05-26 06:44:55.127487 :9C226759:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-05-26 06:44:55.127488 :9C22675A:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=24, exc=24, tot=24 2025-05-26 06:54:56.150892 :9C232D12:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 06:54:56.436620 :9C232D50:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 06:54:56.432 2025-05-26 06:54:56.436624 :9C232D51:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11128 pso_num=25 pso_serial#=243 2025-05-26 06:54:56.436759 :9C232D52:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11128 osp_idx=23 osp_ver=120092 osp_pg=0 (spawn #220395) 2025-05-26 06:54:56.436760 :9C232D53:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 06:54:56.436760 :9C232D54:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=88 time=1218268688 2025-05-26 06:54:56.436761 :9C232D55:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 06:54:56.436761 :9C232D56:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 06:54:56.436761 :9C232D57:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 06:54:56.436762 :9C232D58:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 06:54:56.436762 :9C232D59:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 06:54:56.437275 :9C232D5A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 06:54:56.437320 :9C232D63:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 07:04:57.400016 :9C23F78A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 07:04:57.717250 :9C23F7C2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 07:04:57.713 2025-05-26 07:04:57.717252 :9C23F7C3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13888 pso_num=25 pso_serial#=244 2025-05-26 07:04:57.717396 :9C23F7C4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13888 osp_idx=23 osp_ver=120093 osp_pg=0 (spawn #220421) 2025-05-26 07:04:57.717397 :9C23F7C5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 07:04:57.717397 :9C23F7C6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=89 time=1218869969 2025-05-26 07:04:57.717397 :9C23F7C7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 07:04:57.717398 :9C23F7C8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 07:04:57.717398 :9C23F7C9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 07:04:57.717398 :9C23F7CA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 07:04:57.717399 :9C23F7CB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 07:04:57.717900 :9C23F7CC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 07:04:57.717944 :9C23F7D4:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 07:14:58.723678 :9C24C3F4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 07:14:59.025154 :9C24C43B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 07:14:59.021 2025-05-26 07:14:59.025156 :9C24C43C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13980 pso_num=25 pso_serial#=245 2025-05-26 07:14:59.025295 :9C24C43D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13980 osp_idx=23 osp_ver=120094 osp_pg=0 (spawn #220443) 2025-05-26 07:14:59.025295 :9C24C43E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 07:14:59.025295 :9C24C43F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=90 time=1219471282 2025-05-26 07:14:59.025296 :9C24C440:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 07:14:59.025296 :9C24C441:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 07:14:59.025297 :9C24C442:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 07:14:59.025297 :9C24C443:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 07:14:59.025297 :9C24C444:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 07:14:59.025799 :9C24C445:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 07:14:59.025842 :9C24C44E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 07:24:59.976576 :9C2589B9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 07:25:00.356169 :9C2589F1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 07:25:00.351 2025-05-26 07:25:00.356171 :9C2589F2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14452 pso_num=25 pso_serial#=246 2025-05-26 07:25:00.356356 :9C2589F3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14452 osp_idx=23 osp_ver=120095 osp_pg=0 (spawn #220466) 2025-05-26 07:25:00.356356 :9C2589F4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 07:25:00.356357 :9C2589F5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=91 time=1220072610 2025-05-26 07:25:00.356357 :9C2589F6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 07:25:00.356358 :9C2589F7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 07:25:00.356358 :9C2589F8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 07:25:00.356359 :9C2589F9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 07:25:00.356359 :9C2589FA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 07:25:00.356882 :9C2589FB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 07:25:00.356934 :9C258A02:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 07:35:01.419229 :9C264F51:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 07:35:01.621460 :9C264F8C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 07:35:01.616 2025-05-26 07:35:01.621462 :9C264F8D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13792 pso_num=25 pso_serial#=247 2025-05-26 07:35:01.621601 :9C264F8E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13792 osp_idx=23 osp_ver=120096 osp_pg=0 (spawn #220489) 2025-05-26 07:35:01.621602 :9C264F8F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 07:35:01.621602 :9C264F90:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=92 time=1220673875 2025-05-26 07:35:01.621602 :9C264F91:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 07:35:01.621603 :9C264F92:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 07:35:01.621604 :9C264F93:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 07:35:01.621604 :9C264F94:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 07:35:01.621604 :9C264F95:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 07:35:01.622082 :9C264F96:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 07:35:01.622125 :9C264F9E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 07:45:02.446209 :9C27154A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 07:45:02.920739 :9C271586:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 07:45:02.916 2025-05-26 07:45:02.920741 :9C271587:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9628 pso_num=25 pso_serial#=248 2025-05-26 07:45:02.920871 :9C271588:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9628 osp_idx=23 osp_ver=120097 osp_pg=0 (spawn #220509) 2025-05-26 07:45:02.920872 :9C271589:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 07:45:02.920872 :9C27158A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=93 time=1221275172 2025-05-26 07:45:02.920873 :9C27158B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 07:45:02.920873 :9C27158C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 07:45:02.920873 :9C27158D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 07:45:02.920874 :9C27158E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 07:45:02.920874 :9C27158F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 07:45:02.921381 :9C271590:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 07:45:02.921427 :9C271597:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 07:55:03.745846 :9C27DAEF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 07:55:04.188096 :9C27DB35:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 07:55:04.183 2025-05-26 07:55:04.188098 :9C27DB36:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14400 pso_num=25 pso_serial#=249 2025-05-26 07:55:04.188239 :9C27DB37:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14400 osp_idx=23 osp_ver=120098 osp_pg=0 (spawn #220532) 2025-05-26 07:55:04.188240 :9C27DB38:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 07:55:04.188240 :9C27DB39:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=94 time=1221876438 2025-05-26 07:55:04.188241 :9C27DB3A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 07:55:04.188241 :9C27DB3B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 07:55:04.188241 :9C27DB3C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 07:55:04.188242 :9C27DB3D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 07:55:04.188242 :9C27DB3E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 07:55:04.188745 :9C27DB3F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 07:55:04.188790 :9C27DB47:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-26 08:05:04.978336 :9C28A336:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-26 08:05:05.498695 :9C28A370:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-26 08:05:05.494 2025-05-26 08:05:05.498697 :9C28A371:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7792 pso_num=25 pso_serial#=250 2025-05-26 08:05:05.498835 :9C28A372:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7792 osp_idx=23 osp_ver=120099 osp_pg=0 (spawn #220558) 2025-05-26 08:05:05.498836 :9C28A373:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 08:05:05.498837 :9C28A374:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=95 time=1222477750 2025-05-26 08:05:05.498837 :9C28A375:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 08:05:05.498837 :9C28A376:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 08:05:05.498838 :9C28A377:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 08:05:05.498838 :9C28A378:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 08:05:05.498839 :9C28A379:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 08:05:05.499332 :9C28A37A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-26 08:05:05.499380 :9C28A381:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 7792, W000)