Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250810140900\orcl_w000_6572_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:35603M/63366M, Ph+PgF:41086M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 6572, image: ORACLE.EXE (W000) *** 2025-08-10 14:09:00.914 *** SESSION ID:(177.13947) 2025-08-10 14:09:00.914 *** 2025-08-10 14:09:00.914 Process diagnostic dump for ORACLE.EXE (W000), OS id=6572, pid: 22, proc_ser: 65, sid: 177, sess_ser: 13947 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=60 seq_num=61 snap_id=1 wait times: snap=2.719441 sec, exc=2.719441 sec, total=2.719441 sec wait times: max=5.000000 sec, heur=4 min 58 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=59 seq_num=60 snap_id=1 wait times: snap=5.014723 sec, exc=5.014723 sec, total=5.014723 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000018 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=58 seq_num=59 snap_id=1 wait times: snap=5.004634 sec, exc=5.004634 sec, total=5.004634 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=57 seq_num=58 snap_id=1 wait times: snap=5.015235 sec, exc=5.015235 sec, total=5.015235 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=56 seq_num=57 snap_id=1 wait times: snap=5.005807 sec, exc=5.005807 sec, total=5.005807 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=55 seq_num=56 snap_id=1 wait times: snap=5.004785 sec, exc=5.004785 sec, total=5.004785 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=54 seq_num=55 snap_id=1 wait times: snap=5.014764 sec, exc=5.014764 sec, total=5.014764 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=53 seq_num=54 snap_id=1 wait times: snap=5.015250 sec, exc=5.015250 sec, total=5.015250 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=52 seq_num=53 snap_id=1 wait times: snap=5.003212 sec, exc=5.003212 sec, total=5.003212 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=51 seq_num=52 snap_id=1 wait times: snap=5.000298 sec, exc=5.000298 sec, total=5.000298 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=50 seq_num=51 snap_id=1 wait times: snap=5.000491 sec, exc=5.000491 sec, total=5.000491 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 177 serial 13947 --------------------------------------------------- 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, 14:07:00 - 14:09:00] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-10 14:09:00.914 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 6572, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-10 12:51:23.795539 :BDDDB34D: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-08-10 12:51:23.803099 :BDDDB369:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-10 12:51:23.803452 :BDDDB36A: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-08-10 12:51:23.803485 :BDDDB36D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-10 12:51:23.804460 :BDDDB3A0: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-08-10 12:51:23.804584 :BDDDB3A9: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-08-10 12:51:53.878757 :BDDDBDA1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:52:12.690922 :BDDDC36B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:52:12.676 2025-08-10 12:52:12.690923 :BDDDC36C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19500 pso_num=22 pso_serial#=50 2025-08-10 12:52:12.691068 :BDDDC36D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19500 (legacy spawn) 2025-08-10 12:52:12.709374 :BDDDC36E: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-08-10 12:52:12.709559 :BDDDC373: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-08-10 12:52:12.710414 :BDDDC378:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:52:12.719271 :BDDDC37B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:52:12.707 2025-08-10 12:52:12.719273 :BDDDC37C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20968 pso_num=22 pso_serial#=51 2025-08-10 12:52:12.719413 :BDDDC37D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20968 (legacy spawn) 2025-08-10 12:52:12.725991 :BDDDC37E: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-08-10 12:52:12.726162 :BDDDC387: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-08-10 12:52:12.727007 :BDDDC388:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:52:15.982173 :BDDDC479:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:52:15.967 2025-08-10 12:52:15.982175 :BDDDC47A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19376 pso_num=22 pso_serial#=52 2025-08-10 12:52:15.982322 :BDDDC47B:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19376 (legacy spawn) 2025-08-10 12:52:15.989524 :BDDDC49F: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-08-10 12:52:15.989725 :BDDDC4A4: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-08-10 12:52:15.990686 :BDDDC4A9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:52:16.000444 :BDDDC4AC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:52:15.998 2025-08-10 12:52:16.000446 :BDDDC4AD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19728 pso_num=22 pso_serial#=53 2025-08-10 12:52:16.000622 :BDDDC4AE:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19728 (legacy spawn) 2025-08-10 12:52:16.007876 :BDDDC4AF: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-08-10 12:52:16.008094 :BDDDC4B8: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-08-10 12:52:16.009113 :BDDDC4B9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:52:23.863769 :BDDDC6D7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:52:23.857 2025-08-10 12:52:23.863772 :BDDDC6D8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19064 pso_num=22 pso_serial#=54 2025-08-10 12:52:23.863925 :BDDDC6D9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19064 osp_idx=0 osp_ver=502476 osp_pg=0 (spawn #474562) 2025-08-10 12:52:23.863926 :BDDDC6DA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 12:52:23.863927 :BDDDC6DB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=200 time=3511013173 2025-08-10 12:52:23.863927 :BDDDC6DC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 12:52:23.863928 :BDDDC6DD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 12:52:23.863928 :BDDDC6DE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 12:52:23.863929 :BDDDC6DF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 12:52:23.863929 :BDDDC6E0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 12:52:23.864450 :BDDDC6E1: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-08-10 12:52:23.865134 :BDDDC6F6: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-08-10 12:52:23.876521 :BDDDC712:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-10 12:52:23.877023 :BDDDC713:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-10 12:52:23.879512 :BDDDC714:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-10 12:52:23.879875 :BDDDC715: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-08-10 12:52:23.879913 :BDDDC718:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-10 12:52:23.880831 :BDDDC71E: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-08-10 12:52:23.880962 :BDDDC727: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-08-10 12:52:53.974042 :BDDDD07C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:52:59.728523 :BDDDD25B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:52:59.719 2025-08-10 12:52:59.728524 :BDDDD25C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15304 pso_num=22 pso_serial#=55 2025-08-10 12:52:59.728666 :BDDDD25D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15304 (legacy spawn) 2025-08-10 12:52:59.735274 :BDDDD25E: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-08-10 12:52:59.735445 :BDDDD267: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-08-10 12:52:59.736274 :BDDDD268:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:53:11.863204 :BDDDD62B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:53:11.855 2025-08-10 12:53:11.863206 :BDDDD62C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18796 pso_num=22 pso_serial#=56 2025-08-10 12:53:11.863347 :BDDDD62D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=18796 (legacy spawn) 2025-08-10 12:53:11.869776 :BDDDD62E: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-08-10 12:53:11.869956 :BDDDD633: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-08-10 12:53:11.870777 :BDDDD637:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:53:23.984600 :BDDDDA03:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:53:23.979 2025-08-10 12:53:23.984602 :BDDDDA04:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15732 pso_num=22 pso_serial#=57 2025-08-10 12:53:23.984738 :BDDDDA05:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15732 osp_idx=0 osp_ver=502479 osp_pg=0 (spawn #474564) 2025-08-10 12:53:23.984738 :BDDDDA06:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 12:53:23.984739 :BDDDDA07:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=201 time=3511073283 2025-08-10 12:53:23.984739 :BDDDDA08:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 12:53:23.984740 :BDDDDA09:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 12:53:23.984740 :BDDDDA0A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 12:53:23.984740 :BDDDDA0B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 12:53:23.984741 :BDDDDA0C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 12:53:23.985262 :BDDDDA0D: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-08-10 12:53:23.985921 :BDDDDA22: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-08-10 12:53:23.993467 :BDDDDA3E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-10 12:53:23.994530 :BDDDDA3F: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-08-10 12:53:23.994563 :BDDDDA42:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-10 12:53:23.995512 :BDDDDA48: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-08-10 12:53:23.995633 :BDDDDA51: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-08-10 12:53:54.074302 :BDDDE412:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 12:53:54.110222 :BDDDE44D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 12:53:54.106 2025-08-10 12:53:54.110224 :BDDDE44E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19108 pso_num=22 pso_serial#=58 2025-08-10 12:53:54.110367 :BDDDE44F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19108 osp_idx=0 osp_ver=502480 osp_pg=0 (spawn #474567) 2025-08-10 12:53:54.110368 :BDDDE450:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 12:53:54.110369 :BDDDE451:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=202 time=3511103423 2025-08-10 12:53:54.110369 :BDDDE452:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 12:53:54.110369 :BDDDE453:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 12:53:54.110370 :BDDDE454:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 12:53:54.110370 :BDDDE455:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 12:53:54.110370 :BDDDE456:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 12:53:54.110857 :BDDDE457: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-08-10 12:53:54.110904 :BDDDE45F: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-08-10 13:03:54.954552 :BDDEACA5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 13:03:55.475370 :BDDEACF4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 13:03:55.469 2025-08-10 13:03:55.475372 :BDDEACF5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19096 pso_num=22 pso_serial#=59 2025-08-10 13:03:55.475528 :BDDEACF6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19096 osp_idx=0 osp_ver=502481 osp_pg=0 (spawn #474590) 2025-08-10 13:03:55.475529 :BDDEACF7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 13:03:55.475529 :BDDEACF8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=203 time=3511704783 2025-08-10 13:03:55.475530 :BDDEACF9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 13:03:55.475530 :BDDEACFA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 13:03:55.475530 :BDDEACFB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 13:03:55.475531 :BDDEACFC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 13:03:55.475531 :BDDEACFD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 13:03:55.476064 :BDDEACFE: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-08-10 13:03:55.476110 :BDDEAD04: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-08-10 13:13:56.307743 :BDDF772F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 13:13:56.812485 :BDDF7764:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 13:13:56.807 2025-08-10 13:13:56.812487 :BDDF7765:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21424 pso_num=22 pso_serial#=60 2025-08-10 13:13:56.812624 :BDDF7766:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21424 osp_idx=0 osp_ver=502482 osp_pg=0 (spawn #474614) 2025-08-10 13:13:56.812625 :BDDF7767:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 13:13:56.812625 :BDDF7768:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=204 time=3512306111 2025-08-10 13:13:56.812626 :BDDF7769:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 13:13:56.812626 :BDDF776A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 13:13:56.812626 :BDDF776B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 13:13:56.812627 :BDDF776C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 13:13:56.812627 :BDDF776D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 13:13:56.813115 :BDDF776E: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-08-10 13:13:56.813158 :BDDF7775: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-08-10 13:23:57.571941 :BDE03A47:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 13:23:58.071310 :BDE03A8D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 13:23:58.066 2025-08-10 13:23:58.071313 :BDE03A8E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21432 pso_num=22 pso_serial#=61 2025-08-10 13:23:58.071449 :BDE03A8F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21432 osp_idx=0 osp_ver=502483 osp_pg=0 (spawn #474637) 2025-08-10 13:23:58.071450 :BDE03A90:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 13:23:58.071450 :BDE03A91:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=205 time=3512907376 2025-08-10 13:23:58.071451 :BDE03A92:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 13:23:58.071451 :BDE03A93:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 13:23:58.071451 :BDE03A94:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 13:23:58.071452 :BDE03A95:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 13:23:58.071452 :BDE03A96:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 13:23:58.071944 :BDE03A97: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-08-10 13:23:58.071991 :BDE03A9F: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-08-10 13:33:58.913397 :BDE0FCB9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 13:33:59.293359 :BDE0FCF6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 13:33:59.288 2025-08-10 13:33:59.293361 :BDE0FCF7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8568 pso_num=22 pso_serial#=62 2025-08-10 13:33:59.293505 :BDE0FCF8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8568 osp_idx=0 osp_ver=502484 osp_pg=0 (spawn #474659) 2025-08-10 13:33:59.293506 :BDE0FCF9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 13:33:59.293506 :BDE0FCFA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=206 time=3513508595 2025-08-10 13:33:59.293507 :BDE0FCFB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 13:33:59.293507 :BDE0FCFC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 13:33:59.293508 :BDE0FCFD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 13:33:59.293509 :BDE0FCFE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 13:33:59.293509 :BDE0FCFF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 13:33:59.294013 :BDE0FD00: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-08-10 13:33:59.294064 :BDE0FD07: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-08-10 13:44:00.110319 :BDE1C0CC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 13:44:00.469047 :BDE1C104:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 13:44:00.463 2025-08-10 13:44:00.469049 :BDE1C105:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16496 pso_num=22 pso_serial#=63 2025-08-10 13:44:00.469195 :BDE1C106:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16496 osp_idx=0 osp_ver=502485 osp_pg=0 (spawn #474682) 2025-08-10 13:44:00.469196 :BDE1C107:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 13:44:00.469196 :BDE1C108:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=207 time=3514109767 2025-08-10 13:44:00.469197 :BDE1C109:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 13:44:00.469197 :BDE1C10A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 13:44:00.469197 :BDE1C10B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 13:44:00.469198 :BDE1C10C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 13:44:00.469198 :BDE1C10D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 13:44:00.469748 :BDE1C10E: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-08-10 13:44:00.469807 :BDE1C116: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-08-10 13:54:01.223687 :BDE282C2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 13:54:01.603679 :BDE282FD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 13:54:01.599 2025-08-10 13:54:01.603681 :BDE282FE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19936 pso_num=22 pso_serial#=64 2025-08-10 13:54:01.603824 :BDE282FF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19936 osp_idx=0 osp_ver=502486 osp_pg=0 (spawn #474705) 2025-08-10 13:54:01.603825 :BDE28300:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 13:54:01.603825 :BDE28301:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=208 time=3514710908 2025-08-10 13:54:01.603825 :BDE28302:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 13:54:01.603826 :BDE28303:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 13:54:01.603826 :BDE28304:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 13:54:01.603827 :BDE28305:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 13:54:01.603827 :BDE28306:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 13:54:01.604325 :BDE28307: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-08-10 13:54:01.604372 :BDE2830E: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-08-10 14:04:02.545696 :BDE34942:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-10 14:04:02.831717 :BDE3498A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-10 14:04:02.827 2025-08-10 14:04:02.831718 :BDE3498B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6572 pso_num=22 pso_serial#=65 2025-08-10 14:04:02.831862 :BDE3498C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6572 osp_idx=0 osp_ver=502487 osp_pg=0 (spawn #474729) 2025-08-10 14:04:02.831863 :BDE3498D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-10 14:04:02.831863 :BDE3498E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=209 time=3515312142 2025-08-10 14:04:02.831863 :BDE3498F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-10 14:04:02.831864 :BDE34990:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-10 14:04:02.831864 :BDE34991:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-10 14:04:02.831864 :BDE34992:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-10 14:04:02.831865 :BDE34993:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-10 14:04:02.832345 :BDE34994: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-08-10 14:04:02.832391 :BDE3499A: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 6572, W000)