Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250907220737\orcl_w000_18424_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:34951M/63366M, Ph+PgF:39715M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 18424, image: ORACLE.EXE (W000) *** 2025-09-07 22:07:37.850 *** SESSION ID:(177.15679) 2025-09-07 22:07:37.850 *** 2025-09-07 22:07:37.850 Process diagnostic dump for ORACLE.EXE (W000), OS id=18424, pid: 22, proc_ser: 168, sid: 177, sess_ser: 15679 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=213 seq_num=214 snap_id=1 wait times: snap=2.868096 sec, exc=2.868096 sec, total=2.868096 sec wait times: max=5.000000 sec, heur=14 min 17 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.000040 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=212 seq_num=213 snap_id=1 wait times: snap=5.003957 sec, exc=5.003957 sec, total=5.003957 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000041 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=211 seq_num=212 snap_id=1 wait times: snap=5.009228 sec, exc=5.009228 sec, total=5.009228 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=210 seq_num=211 snap_id=1 wait times: snap=5.004602 sec, exc=5.004602 sec, total=5.004602 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=209 seq_num=210 snap_id=1 wait times: snap=5.004638 sec, exc=5.004638 sec, total=5.004638 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=208 seq_num=209 snap_id=1 wait times: snap=5.015234 sec, exc=5.015234 sec, total=5.015234 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=207 seq_num=208 snap_id=1 wait times: snap=5.006340 sec, exc=5.006340 sec, total=5.006340 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=206 seq_num=207 snap_id=1 wait times: snap=5.013616 sec, exc=5.013616 sec, total=5.013616 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=205 seq_num=206 snap_id=1 wait times: snap=5.004787 sec, exc=5.004787 sec, total=5.004787 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=204 seq_num=205 snap_id=1 wait times: snap=5.004606 sec, exc=5.004606 sec, total=5.004606 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=203 seq_num=204 snap_id=1 wait times: snap=5.014708 sec, exc=5.014708 sec, total=5.014708 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time Sampled Session History of session 177 serial 15679 --------------------------------------------------- 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:05:37 - 22:07:37] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-07 22:07:37.850 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 18424, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-07 20:38:24.345275 :CA596754:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:ktcc.c:879 2025-09-07 20:38:24.347192 :CA59675A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 20:38:24.347238 :CA59675B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 20:38:24.347946 :CA59675C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 20:38:24.348185 :CA59675D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:38:24.348218 :CA596760:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 20:38:24.355104 :CA596766:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:38:24.355182 :CA596769:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:ktcc.c:879 2025-09-07 20:38:24.355216 :CA59676A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:ktcc.c:879 2025-09-07 20:38:24.356959 :CA596770:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 20:38:24.357008 :CA596771:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 20:38:24.360244 :CA596772:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 20:38:24.360526 :CA596773:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:38:24.360570 :CA596776:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 20:38:24.365443 :CA59677C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:38:24.365501 :CA59677F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:ktcc.c:879 2025-09-07 20:38:24.365536 :CA596780:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:ktcc.c:879 2025-09-07 20:38:24.365825 :CA596786:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-07 20:38:24.366168 :CA596787:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-07 20:38:24.366292 :CA596788:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 20:38:24.366496 :CA596789:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:38:24.366517 :CA59678C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 20:38:24.368176 :CA596792:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 20:38:24.368380 :CA596793:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:38:24.368409 :CA596796:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 20:38:24.369301 :CA59679C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:38:24.369394 :CA5967A5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 20:38:54.486288 :CA59715F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:39:16.058383 :CA59780B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:39:16.045 2025-09-07 20:39:16.058385 :CA59780C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22800 pso_num=22 pso_serial#=155 2025-09-07 20:39:16.058518 :CA59780D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22800 (legacy spawn) 2025-09-07 20:39:16.065045 :CA59780E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:16.065216 :CA597813:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 20:39:16.066025 :CA597818:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:39:19.883421 :CA59795E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:39:19.868 2025-09-07 20:39:19.883423 :CA59795F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8216 pso_num=22 pso_serial#=156 2025-09-07 20:39:19.883576 :CA597960:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8216 (legacy spawn) 2025-09-07 20:39:19.890575 :CA59796D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:19.890768 :CA597976:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 20:39:19.891676 :CA597977:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:39:19.900972 :CA59797A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:39:19.899 2025-09-07 20:39:19.900974 :CA59797B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24208 pso_num=22 pso_serial#=157 2025-09-07 20:39:19.901115 :CA59797C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=24208 (legacy spawn) 2025-09-07 20:39:19.907981 :CA59797D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:19.908154 :CA597986:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 20:39:19.909012 :CA597987:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:39:22.985070 :CA597A89:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:39:22.972 2025-09-07 20:39:22.985072 :CA597A8A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20088 pso_num=22 pso_serial#=158 2025-09-07 20:39:22.985214 :CA597A8B:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20088 (legacy spawn) 2025-09-07 20:39:22.991760 :CA597A8C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:22.991942 :CA597A95:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 20:39:22.992724 :CA597A96:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:39:23.001519 :CA597A99:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:39:22.988 2025-09-07 20:39:23.001520 :CA597A9A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23372 pso_num=22 pso_serial#=159 2025-09-07 20:39:23.001663 :CA597A9B:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23372 (legacy spawn) 2025-09-07 20:39:23.008204 :CA597A9C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:23.008369 :CA597AA5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 20:39:23.009169 :CA597AA6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:39:24.347158 :CA597AF0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:39:24.341 2025-09-07 20:39:24.347160 :CA597AF1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21584 pso_num=22 pso_serial#=160 2025-09-07 20:39:24.347295 :CA597AF2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21584 osp_idx=0 osp_ver=586732 osp_pg=0 (spawn #568981) 2025-09-07 20:39:24.347296 :CA597AF3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 20:39:24.347296 :CA597AF4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=158 time=1663215658 2025-09-07 20:39:24.347297 :CA597AF5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 20:39:24.347297 :CA597AF6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 20:39:24.347297 :CA597AF7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 20:39:24.347298 :CA597AF8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 20:39:24.347298 :CA597AF9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 20:39:24.347832 :CA597AFA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-07 20:39:24.348475 :CA597B0F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:24.356090 :CA597B2B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 20:39:24.356460 :CA597B2C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:24.356500 :CA597B2F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 20:39:24.357373 :CA597B35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 20:39:24.357489 :CA597B3E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 20:39:54.467304 :CA5984DF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:39:54.675113 :CA598544:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:39:54.670 2025-09-07 20:39:54.675115 :CA598545:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21600 pso_num=22 pso_serial#=161 2025-09-07 20:39:54.675248 :CA598546:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21600 osp_idx=0 osp_ver=586733 osp_pg=0 (spawn #568983) 2025-09-07 20:39:54.675249 :CA598547:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 20:39:54.675249 :CA598548:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=159 time=1663245987 2025-09-07 20:39:54.675249 :CA598549:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 20:39:54.675250 :CA59854A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 20:39:54.675250 :CA59854B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 20:39:54.675250 :CA59854C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 20:39:54.675251 :CA59854D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 20:39:54.675738 :CA59854E: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-09-07 20:39:54.675782 :CA598556: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-09-07 20:49:55.497078 :CA5A4E56:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:49:55.886962 :CA5A4EC6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:49:55.882 2025-09-07 20:49:55.886965 :CA5A4EC7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22912 pso_num=22 pso_serial#=162 2025-09-07 20:49:55.887106 :CA5A4EC8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22912 osp_idx=0 osp_ver=586734 osp_pg=0 (spawn #569005) 2025-09-07 20:49:55.887107 :CA5A4EC9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 20:49:55.887108 :CA5A4ECA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=160 time=1663847190 2025-09-07 20:49:55.887108 :CA5A4ECB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 20:49:55.887109 :CA5A4ECC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 20:49:55.887109 :CA5A4ECD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 20:49:55.887109 :CA5A4ECE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 20:49:55.887110 :CA5A4ECF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 20:49:55.887615 :CA5A4ED0: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-09-07 20:49:55.887668 :CA5A4ED8: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-09-07 20:59:56.900812 :CA5B16EF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 20:59:57.124351 :CA5B1729:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 20:59:57.119 2025-09-07 20:59:57.124353 :CA5B172A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22828 pso_num=22 pso_serial#=163 2025-09-07 20:59:57.124488 :CA5B172B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22828 osp_idx=0 osp_ver=586735 osp_pg=0 (spawn #569029) 2025-09-07 20:59:57.124489 :CA5B172C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 20:59:57.124489 :CA5B172D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=161 time=1664448424 2025-09-07 20:59:57.124490 :CA5B172E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 20:59:57.124490 :CA5B172F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 20:59:57.124490 :CA5B1730:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 20:59:57.124491 :CA5B1731:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 20:59:57.124491 :CA5B1732:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 20:59:57.124987 :CA5B1733: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-09-07 20:59:57.125030 :CA5B173A: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-09-07 21:09:57.989561 :CA5BEA7D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 21:09:58.338158 :CA5BEAC5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 21:09:58.333 2025-09-07 21:09:58.338161 :CA5BEAC6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23080 pso_num=22 pso_serial#=164 2025-09-07 21:09:58.338297 :CA5BEAC7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23080 osp_idx=0 osp_ver=586736 osp_pg=0 (spawn #569055) 2025-09-07 21:09:58.338298 :CA5BEAC8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 21:09:58.338298 :CA5BEAC9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=162 time=1665049643 2025-09-07 21:09:58.338299 :CA5BEACA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 21:09:58.338299 :CA5BEACB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 21:09:58.338299 :CA5BEACC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 21:09:58.338300 :CA5BEACD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 21:09:58.338300 :CA5BEACE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 21:09:58.338801 :CA5BEACF: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-09-07 21:09:58.338851 :CA5BEAD6: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-09-07 21:19:59.099806 :CA5CB356:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 21:19:59.526555 :CA5CB390:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 21:19:59.521 2025-09-07 21:19:59.526557 :CA5CB391:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23432 pso_num=22 pso_serial#=165 2025-09-07 21:19:59.526699 :CA5CB392:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23432 osp_idx=0 osp_ver=586737 osp_pg=0 (spawn #569077) 2025-09-07 21:19:59.526700 :CA5CB393:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 21:19:59.526700 :CA5CB394:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=163 time=1665650830 2025-09-07 21:19:59.526701 :CA5CB395:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 21:19:59.526701 :CA5CB396:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 21:19:59.526702 :CA5CB397:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 21:19:59.526702 :CA5CB398:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 21:19:59.526702 :CA5CB399:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 21:19:59.527245 :CA5CB39A: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-09-07 21:19:59.527290 :CA5CB3A1: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-09-07 21:30:00.266961 :CA5D7BE5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 21:30:00.615423 :CA5D7C1F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 21:30:00.610 2025-09-07 21:30:00.615425 :CA5D7C20:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24280 pso_num=22 pso_serial#=166 2025-09-07 21:30:00.615565 :CA5D7C21:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24280 osp_idx=0 osp_ver=586738 osp_pg=0 (spawn #569100) 2025-09-07 21:30:00.615565 :CA5D7C22:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 21:30:00.615566 :CA5D7C23:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=164 time=1666251924 2025-09-07 21:30:00.615566 :CA5D7C24:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 21:30:00.615566 :CA5D7C25:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 21:30:00.615567 :CA5D7C26:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 21:30:00.615567 :CA5D7C27:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 21:30:00.615567 :CA5D7C28:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 21:30:00.616047 :CA5D7C29: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-09-07 21:30:00.616093 :CA5D7C31: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-09-07 21:40:01.404578 :CA5E4568:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 21:40:01.863578 :CA5E45B3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 21:40:01.857 2025-09-07 21:40:01.863580 :CA5E45B4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23872 pso_num=22 pso_serial#=167 2025-09-07 21:40:01.863743 :CA5E45B5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23872 osp_idx=0 osp_ver=586739 osp_pg=0 (spawn #569123) 2025-09-07 21:40:01.863744 :CA5E45B6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 21:40:01.863745 :CA5E45B7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=165 time=1666853174 2025-09-07 21:40:01.863745 :CA5E45B8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 21:40:01.863746 :CA5E45B9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 21:40:01.863746 :CA5E45BA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 21:40:01.863747 :CA5E45BB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 21:40:01.863747 :CA5E45BC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 21:40:01.864346 :CA5E45BD: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-09-07 21:40:01.864404 :CA5E45C6: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-09-07 21:50:02.667047 :CA5F0F07:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 21:50:03.109646 :CA5F0F42:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 21:50:03.104 2025-09-07 21:50:03.109648 :CA5F0F43:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18424 pso_num=22 pso_serial#=168 2025-09-07 21:50:03.109791 :CA5F0F44:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18424 osp_idx=0 osp_ver=586740 osp_pg=0 (spawn #569145) 2025-09-07 21:50:03.109792 :CA5F0F45:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 21:50:03.109792 :CA5F0F46:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=166 time=1667454408 2025-09-07 21:50:03.109792 :CA5F0F47:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 21:50:03.109793 :CA5F0F48:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 21:50:03.109793 :CA5F0F49:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 21:50:03.109793 :CA5F0F4A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 21:50:03.109793 :CA5F0F4B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 21:50:03.110361 :CA5F0F4C: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-09-07 21:50:03.110414 :CA5F0F55: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-09-07 21:53:20.028414 :CA5F5129: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-09-07 22:00:04.366241 :CA5FD8CA: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: 18424, W000)