Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250705220911\orcl_w000_2512_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:37333M/63366M, Ph+PgF:43334M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 2512, image: ORACLE.EXE (W000) *** 2025-07-05 22:09:11.264 *** SESSION ID:(193.27695) 2025-07-05 22:09:11.264 *** 2025-07-05 22:09:11.264 Process diagnostic dump for ORACLE.EXE (W000), OS id=2512, pid: 24, proc_ser: 193, sid: 193, sess_ser: 27695 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=3.960190 sec, exc=3.960190 sec, total=3.960190 sec wait times: max=5.000000 sec, heur=2 min 39 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.000023 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.014726 sec, exc=5.014726 sec, total=5.014726 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.010161 sec, exc=5.010161 sec, total=5.010161 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.014725 sec, exc=5.014725 sec, total=5.014725 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=5.008307 sec, exc=5.008307 sec, total=5.008307 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=27 seq_num=28 snap_id=1 wait times: snap=5.000337 sec, exc=5.000337 sec, total=5.000337 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.007577 sec, exc=5.007577 sec, total=5.007577 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.003669 sec, exc=5.003669 sec, total=5.003669 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=5.004625 sec, exc=5.004625 sec, total=5.004625 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.014705 sec, exc=5.014705 sec, total=5.014705 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.004612 sec, exc=5.004612 sec, total=5.004612 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time Sampled Session History of session 193 serial 27695 --------------------------------------------------- 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, 22:07:11 - 22:09:11] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-05 22:09:11.264 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 2512, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-05 21:23:56.238724 :AE0492B4:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 21:23:56.238724 :AE0492B5:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 21:23:56.238725 :AE0492B6:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 21:23:56.238725 :AE0492B7:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 21:23:56.239235 :AE0492B8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 21:23:56.239907 :AE0492CD: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-07-05 21:23:56.247442 :AE0492E9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-07-05 21:23:56.247818 :AE0492EA: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-07-05 21:23:56.247853 :AE0492ED:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-07-05 21:23:56.248715 :AE0492F3: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-07-05 21:23:56.248920 :AE0492F9: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-07-05 21:24:26.312745 :AE049D02:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:24:26.358623 :AE049D05:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:24:26.343 2025-07-05 21:24:26.358625 :AE049D06:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10520 pso_num=24 pso_serial#=176 2025-07-05 21:24:26.358756 :AE049D07:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=10520 (legacy spawn) 2025-07-05 21:24:26.365278 :AE049D08: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-07-05 21:24:26.365467 :AE049D0D: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-07-05 21:24:26.366320 :AE049D12:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:24:26.375193 :AE049D15:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:24:26.374 2025-07-05 21:24:26.375194 :AE049D16:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18196 pso_num=24 pso_serial#=177 2025-07-05 21:24:26.375326 :AE049D17:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=18196 (legacy spawn) 2025-07-05 21:24:26.381954 :AE049D18: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-07-05 21:24:26.382114 :AE049D21: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-07-05 21:24:26.382940 :AE049D22:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:24:29.579403 :AE049E37:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:24:29.565 2025-07-05 21:24:29.579405 :AE049E38:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15932 pso_num=24 pso_serial#=178 2025-07-05 21:24:29.579538 :AE049E39:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=15932 (legacy spawn) 2025-07-05 21:24:29.586196 :AE049E3A: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-07-05 21:24:29.586366 :AE049E3F: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-07-05 21:24:29.587252 :AE049E44:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:24:29.596166 :AE049E47:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:24:29.581 2025-07-05 21:24:29.596168 :AE049E48:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12980 pso_num=24 pso_serial#=179 2025-07-05 21:24:29.596304 :AE049E49:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12980 (legacy spawn) 2025-07-05 21:24:29.602985 :AE049E4A: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-07-05 21:24:29.603151 :AE049E53: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-07-05 21:24:29.604002 :AE049E54:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:24:49.647629 :AE04A490:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:24:49.637 2025-07-05 21:24:49.647631 :AE04A491:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12136 pso_num=24 pso_serial#=180 2025-07-05 21:24:49.647761 :AE04A492:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12136 (legacy spawn) 2025-07-05 21:24:49.654310 :AE04A493: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-07-05 21:24:49.654480 :AE04A49C: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-07-05 21:24:49.655258 :AE04A49D:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:24:55.388601 :AE04A689:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:24:55.380 2025-07-05 21:24:55.388603 :AE04A68A:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18420 pso_num=24 pso_serial#=181 2025-07-05 21:24:55.388741 :AE04A68B:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=18420 (legacy spawn) 2025-07-05 21:24:55.395190 :AE04A68C: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-07-05 21:24:55.395372 :AE04A695: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-07-05 21:24:55.396196 :AE04A696:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:24:56.323342 :AE04A713:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:24:56.318 2025-07-05 21:24:56.323344 :AE04A714:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=17216 pso_num=24 pso_serial#=182 2025-07-05 21:24:56.323491 :AE04A715:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=17216 osp_idx=22 osp_ver=524217 osp_pg=0 (spawn #355747) 2025-07-05 21:24:56.323492 :AE04A716:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 21:24:56.323492 :AE04A717:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=96 time=431472220 2025-07-05 21:24:56.323492 :AE04A718:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 21:24:56.323493 :AE04A719:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 21:24:56.323493 :AE04A71A:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 21:24:56.323493 :AE04A71B:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 21:24:56.323494 :AE04A71C:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 21:24:56.323984 :AE04A71D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 21:24:56.324638 :AE04A732: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-07-05 21:24:56.335751 :AE04A74F:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-07-05 21:24:56.336228 :AE04A750:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-07-05 21:24:56.338565 :AE04A751:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-07-05 21:24:56.338969 :AE04A752: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-07-05 21:24:56.339006 :AE04A755:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-07-05 21:24:56.339908 :AE04A75B: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-07-05 21:24:56.340039 :AE04A764: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-07-05 21:25:26.430002 :AE04B159:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:25:26.484818 :AE04B15C:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:25:26.476 2025-07-05 21:25:26.484820 :AE04B15D:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=17400 pso_num=24 pso_serial#=183 2025-07-05 21:25:26.484958 :AE04B15E:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=17400 (legacy spawn) 2025-07-05 21:25:26.491335 :AE04B15F: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-07-05 21:25:26.491505 :AE04B164: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-07-05 21:25:26.492330 :AE04B169:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:25:38.992519 :AE04B58D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:25:38.978 2025-07-05 21:25:38.992521 :AE04B58E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9900 pso_num=24 pso_serial#=184 2025-07-05 21:25:38.992662 :AE04B58F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9900 (legacy spawn) 2025-07-05 21:25:38.999112 :AE04B590: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-07-05 21:25:38.999292 :AE04B599: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-07-05 21:25:39.000097 :AE04B59A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:25:39.008737 :AE04B59D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:25:38.993 2025-07-05 21:25:39.008740 :AE04B59E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9276 pso_num=24 pso_serial#=185 2025-07-05 21:25:39.008878 :AE04B59F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9276 (legacy spawn) 2025-07-05 21:25:39.015371 :AE04B5AB: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-07-05 21:25:39.015539 :AE04B5B4: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-07-05 21:25:39.016336 :AE04B5B5:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:25:42.277476 :AE04B6B1:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:25:42.264 2025-07-05 21:25:42.277478 :AE04B6B2:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18300 pso_num=24 pso_serial#=186 2025-07-05 21:25:42.277616 :AE04B6B3:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=18300 (legacy spawn) 2025-07-05 21:25:42.284371 :AE04B6B4: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-07-05 21:25:42.284541 :AE04B6B9: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-07-05 21:25:42.285338 :AE04B6BE:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:25:42.304176 :AE04B6C1:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:25:42.295 2025-07-05 21:25:42.304178 :AE04B6C2:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=17096 pso_num=24 pso_serial#=187 2025-07-05 21:25:42.304315 :AE04B6C3:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=17096 (legacy spawn) 2025-07-05 21:25:42.310706 :AE04B6C4: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-07-05 21:25:42.310870 :AE04B6CD: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-07-05 21:25:42.311675 :AE04B6CE:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:25:56.415122 :AE04BB5C:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:25:56.409 2025-07-05 21:25:56.415124 :AE04BB5D:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9636 pso_num=24 pso_serial#=188 2025-07-05 21:25:56.415264 :AE04BB5E:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=9636 osp_idx=22 osp_ver=524223 osp_pg=0 (spawn #355749) 2025-07-05 21:25:56.415265 :AE04BB5F:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 21:25:56.415266 :AE04BB60:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=97 time=431532314 2025-07-05 21:25:56.415266 :AE04BB61:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 21:25:56.415266 :AE04BB62:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 21:25:56.415267 :AE04BB63:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 21:25:56.415267 :AE04BB64:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 21:25:56.415267 :AE04BB65:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 21:25:56.415771 :AE04BB66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 21:25:56.416423 :AE04BB7B: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-07-05 21:25:56.424032 :AE04BB97:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-07-05 21:25:56.424397 :AE04BB98: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-07-05 21:25:56.424432 :AE04BB9B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-07-05 21:25:56.425292 :AE04BBA1: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-07-05 21:25:56.425422 :AE04BBAA: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-07-05 21:26:26.512491 :AE04C643:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:26:27.120953 :AE04C6A0:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:26:27.115 2025-07-05 21:26:27.120955 :AE04C6A1:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15420 pso_num=24 pso_serial#=189 2025-07-05 21:26:27.121089 :AE04C6A2:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15420 osp_idx=22 osp_ver=524224 osp_pg=0 (spawn #355751) 2025-07-05 21:26:27.121089 :AE04C6A3:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 21:26:27.121090 :AE04C6A4:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=98 time=431563017 2025-07-05 21:26:27.121090 :AE04C6A5:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 21:26:27.121091 :AE04C6A6:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 21:26:27.121091 :AE04C6A7:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 21:26:27.121091 :AE04C6A8:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 21:26:27.121091 :AE04C6A9:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 21:26:27.121629 :AE04C6AA: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-07-05 21:26:27.121673 :AE04C6B2: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-07-05 21:26:42.138514 :AE04CBB1:db_trace:ksl2.c@2477:kslwtbctx(): [10005:24:193] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-07-05 21:26:42.138523 :AE04CBB2:db_trace:ksl2.c@2611:kslwtectx(): [10005:24:193] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-07-05 21:26:42.138524 :AE04CBB3:db_trace:ksl2.c@2619:kslwtectx(): [10005:24:193] KSL WAIT END wait times (usecs) - snap=11, exc=11, tot=11 2025-07-05 21:36:27.974439 :AE059564:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:36:28.416792 :AE0595BD:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:36:28.412 2025-07-05 21:36:28.416795 :AE0595BE:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11108 pso_num=24 pso_serial#=190 2025-07-05 21:36:28.416942 :AE0595BF:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=11108 osp_idx=22 osp_ver=524225 osp_pg=0 (spawn #355774) 2025-07-05 21:36:28.416942 :AE0595C0:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 21:36:28.416943 :AE0595C1:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=99 time=432164314 2025-07-05 21:36:28.416943 :AE0595C2:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 21:36:28.416943 :AE0595C3:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 21:36:28.416943 :AE0595C4:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 21:36:28.416944 :AE0595C5:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 21:36:28.416944 :AE0595C6:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 21:36:28.417483 :AE0595C7: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-07-05 21:36:28.417526 :AE0595CD: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-07-05 21:46:29.244244 :AE066276:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:46:29.577271 :AE0662BF:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:46:29.573 2025-07-05 21:46:29.577274 :AE0662C0:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=2860 pso_num=24 pso_serial#=191 2025-07-05 21:46:29.577413 :AE0662C1:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=2860 osp_idx=22 osp_ver=524226 osp_pg=0 (spawn #355796) 2025-07-05 21:46:29.577414 :AE0662C2:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 21:46:29.577415 :AE0662C3:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=100 time=432765470 2025-07-05 21:46:29.577415 :AE0662C4:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 21:46:29.577416 :AE0662C5:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 21:46:29.577416 :AE0662C6:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 21:46:29.577416 :AE0662C7:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 21:46:29.577417 :AE0662C8:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 21:46:29.578012 :AE0662C9: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-07-05 21:46:29.578059 :AE0662D1: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-07-05 21:56:30.393461 :AE072FBC:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 21:56:30.867101 :AE073012:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 21:56:30.862 2025-07-05 21:56:30.867103 :AE073013:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=4192 pso_num=24 pso_serial#=192 2025-07-05 21:56:30.867245 :AE073014:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=4192 osp_idx=22 osp_ver=524227 osp_pg=0 (spawn #355819) 2025-07-05 21:56:30.867245 :AE073015:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 21:56:30.867246 :AE073016:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=101 time=433366767 2025-07-05 21:56:30.867247 :AE073017:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 21:56:30.867247 :AE073018:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 21:56:30.867247 :AE073019:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 21:56:30.867248 :AE07301A:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 21:56:30.867248 :AE07301B:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 21:56:30.867794 :AE07301C: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-07-05 21:56:30.867833 :AE073023: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-07-05 22:06:31.740700 :AE0805D9:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-05 22:06:32.089298 :AE080625:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-05 22:06:32.084 2025-07-05 22:06:32.089300 :AE080626:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=2512 pso_num=24 pso_serial#=193 2025-07-05 22:06:32.089438 :AE080627:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=2512 osp_idx=22 osp_ver=524228 osp_pg=0 (spawn #355845) 2025-07-05 22:06:32.089439 :AE080628:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:06:32.089439 :AE080629:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=102 time=433967986 2025-07-05 22:06:32.089440 :AE08062A:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:06:32.089440 :AE08062B:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:06:32.089441 :AE08062C:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:06:32.089441 :AE08062D:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:06:32.089441 :AE08062E:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:06:32.090003 :AE08062F: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-07-05 22:06:32.090047 :AE080637: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: 2512, W000)