Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250430220009\orcl_w000_11440_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:37636M/63366M, Ph+PgF:45238M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 11440, image: ORACLE.EXE (W000) *** 2025-04-30 22:00:09.525 *** SESSION ID:(201.27661) 2025-04-30 22:00:09.525 *** 2025-04-30 22:00:09.525 Process diagnostic dump for ORACLE.EXE (W000), OS id=11440, pid: 25, proc_ser: 144, sid: 201, sess_ser: 27661 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=79 seq_num=80 snap_id=1 wait times: snap=2.739100 sec, exc=2.739100 sec, total=2.739100 sec wait times: max=5.000000 sec, heur=6 min 33 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.000021 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=78 seq_num=79 snap_id=1 wait times: snap=5.014760 sec, exc=5.014760 sec, total=5.014760 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.004657 sec, exc=5.004657 sec, total=5.004657 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=76 seq_num=77 snap_id=1 wait times: snap=5.004623 sec, exc=5.004623 sec, total=5.004623 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=75 seq_num=76 snap_id=1 wait times: snap=5.009719 sec, exc=5.009719 sec, total=5.009719 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=74 seq_num=75 snap_id=1 wait times: snap=5.003417 sec, exc=5.003417 sec, total=5.003417 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=73 seq_num=74 snap_id=1 wait times: snap=5.005645 sec, exc=5.005645 sec, total=5.005645 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=72 seq_num=73 snap_id=1 wait times: snap=5.014742 sec, exc=5.014742 sec, total=5.014742 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=71 seq_num=72 snap_id=1 wait times: snap=5.014724 sec, exc=5.014724 sec, total=5.014724 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=70 seq_num=71 snap_id=1 wait times: snap=5.014727 sec, exc=5.014727 sec, total=5.014727 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=69 seq_num=70 snap_id=1 wait times: snap=5.010150 sec, exc=5.010150 sec, total=5.010150 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 201 serial 27661 --------------------------------------------------- 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, 21:58:09 - 22:00:09] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-30 22:00:09.525 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 11440, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-30 20:46:27.176414 :90F16EC8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11668 osp_idx=23 osp_ver=71019 osp_pg=0 (spawn #134985) 2025-04-30 20:46:27.176415 :90F16EC9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:46:27.176416 :90F16ECA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=198 time=3316776656 2025-04-30 20:46:27.176416 :90F16ECB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:46:27.176416 :90F16ECC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:46:27.176416 :90F16ECD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:46:27.176416 :90F16ECE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:46:27.176417 :90F16ECF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:46:27.176883 :90F16ED0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:46:57.216275 :90F178A3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 20:47:27.251148 :90F182B4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 20:47:27.240 2025-04-30 20:47:27.251150 :90F182B5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8396 pso_num=25 pso_serial#=131 2025-04-30 20:47:27.251281 :90F182B6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8396 osp_idx=23 osp_ver=71020 osp_pg=0 (spawn #134987) 2025-04-30 20:47:27.251282 :90F182B7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:47:27.251282 :90F182B8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=199 time=3316836734 2025-04-30 20:47:27.251282 :90F182B9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:47:27.251283 :90F182BA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:47:27.251283 :90F182BB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:47:27.251283 :90F182BC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:47:27.251284 :90F182BD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:47:27.251767 :90F182BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:47:57.304707 :90F18CC0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 20:48:22.356119 :90F1949D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 20:48:22.345 2025-04-30 20:48:22.356121 :90F1949E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3452 pso_num=25 pso_serial#=132 2025-04-30 20:48:22.356255 :90F1949F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=3452 osp_idx=23 osp_ver=71021 osp_pg=0 (spawn #134989) 2025-04-30 20:48:22.356256 :90F194A0:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:48:22.356257 :90F194A1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=200 time=3316891828 2025-04-30 20:48:22.356257 :90F194A2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:48:22.356257 :90F194A3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:48:22.356257 :90F194A4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:48:22.356257 :90F194A5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:48:22.356258 :90F194A6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:48:22.356751 :90F194A7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:48:27.357857 :90F1967B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-30 20:48:27.357884*:90F1967C:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DCBB58 estart=1746017306 eid=16838129 ctx=0x000000077BD98A08 cwh=0x0000000024D801B0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-04-30 20:48:27.357884*:90F1967D:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DCBB58 curCtx=0x0000000024D8F708 pubTabIdxCnt=0 2025-04-30 20:48:27.357884*:90F1967E:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DCBB58 2025-04-30 20:48:27.357884*:90F1967F:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DCBB58 2025-04-30 20:48:27.357884*:90F19680:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DCBB58 curCtx=0x0000000024D8F708 xsc->flg4=65792 flags=2 2025-04-30 20:48:27.357884*:90F19681:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DCBB58 2025-04-30 20:48:27.358405 :90F19682:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-30 20:48:27.369470 :90F1968A:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-30 20:48:27.369963 :90F1968B:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-30 20:48:27.372446 :90F1968C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-04-30 20:48:27.372831 :90F1968D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-30 20:48:27.372874 :90F19690:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-04-30 20:48:27.373803 :90F19696:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-30 20:48:27.373946 :90F1969F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-04-30 20:48:57.451046 :90F19FD8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 20:49:27.441720 :90F1A95E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 20:49:27.430 2025-04-30 20:49:27.441722 :90F1A95F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12224 pso_num=25 pso_serial#=133 2025-04-30 20:49:27.441840 :90F1A960:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12224 osp_idx=23 osp_ver=71022 osp_pg=0 (spawn #134991) 2025-04-30 20:49:27.441841 :90F1A961:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:49:27.441842 :90F1A962:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=201 time=3316956921 2025-04-30 20:49:27.441842 :90F1A963:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:49:27.441843 :90F1A964:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:49:27.441843 :90F1A965:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:49:27.441844 :90F1A966:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:49:27.441844 :90F1A967:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:49:27.442362 :90F1A968:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:49:57.520406 :90F1B360:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 20:50:27.500454 :90F1BD13:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 20:50:27.489 2025-04-30 20:50:27.500456 :90F1BD14:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11116 pso_num=25 pso_serial#=134 2025-04-30 20:50:27.500585 :90F1BD15:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11116 osp_idx=23 osp_ver=71023 osp_pg=0 (spawn #134995) 2025-04-30 20:50:27.500586 :90F1BD16:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:50:27.500586 :90F1BD17:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=202 time=3317016968 2025-04-30 20:50:27.500586 :90F1BD18:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:50:27.500587 :90F1BD19:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:50:27.500587 :90F1BD1A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:50:27.500588 :90F1BD1B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:50:27.500588 :90F1BD1C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:50:27.501089 :90F1BD1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:50:57.584184 :90F1C6BC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 20:51:27.572567 :90F1D04E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 20:51:27.561 2025-04-30 20:51:27.572569 :90F1D04F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10664 pso_num=25 pso_serial#=135 2025-04-30 20:51:27.572703 :90F1D050:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10664 osp_idx=23 osp_ver=71024 osp_pg=0 (spawn #134997) 2025-04-30 20:51:27.572704 :90F1D051:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:51:27.572704 :90F1D052:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=203 time=3317077046 2025-04-30 20:51:27.572705 :90F1D053:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:51:27.572705 :90F1D054:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:51:27.572706 :90F1D055:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:51:27.572706 :90F1D056:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:51:27.572706 :90F1D057:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:51:27.573211 :90F1D058:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:51:57.630371 :90F1D9CD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 20:52:27.657782 :90F1E3B3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 20:52:27.647 2025-04-30 20:52:27.657784 :90F1E3B4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10164 pso_num=25 pso_serial#=136 2025-04-30 20:52:27.657912 :90F1E3B5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10164 osp_idx=23 osp_ver=71025 osp_pg=0 (spawn #134999) 2025-04-30 20:52:27.657913 :90F1E3B6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:52:27.657913 :90F1E3B7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=204 time=3317137140 2025-04-30 20:52:27.657914 :90F1E3B8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:52:27.657914 :90F1E3B9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:52:27.657914 :90F1E3BA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:52:27.657915 :90F1E3BB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:52:27.657915 :90F1E3BC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:52:27.658389 :90F1E3BD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:52:57.740234 :90F1EE53:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 20:53:28.012175 :90F1F84F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 20:53:28.007 2025-04-30 20:53:28.012177 :90F1F850:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10244 pso_num=25 pso_serial#=137 2025-04-30 20:53:28.012319 :90F1F851:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10244 osp_idx=23 osp_ver=71026 osp_pg=0 (spawn #135002) 2025-04-30 20:53:28.012320 :90F1F852:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 20:53:28.012320 :90F1F853:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=205 time=3317197500 2025-04-30 20:53:28.012321 :90F1F854:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 20:53:28.012321 :90F1F855:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 20:53:28.012321 :90F1F856:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 20:53:28.012322 :90F1F857:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 20:53:28.012322 :90F1F858:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 20:53:28.012838 :90F1F859:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 20:53:28.012886 :90F1F860:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-30 21:03:28.855097 :90F2BEFA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 21:03:29.359623 :90F2BF32:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 21:03:29.355 2025-04-30 21:03:29.359625 :90F2BF33:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=2312 pso_num=25 pso_serial#=138 2025-04-30 21:03:29.359757 :90F2BF34:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=2312 osp_idx=23 osp_ver=71027 osp_pg=0 (spawn #135026) 2025-04-30 21:03:29.359758 :90F2BF35:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 21:03:29.359758 :90F2BF36:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=206 time=3317798843 2025-04-30 21:03:29.359758 :90F2BF37:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 21:03:29.359759 :90F2BF38:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 21:03:29.359759 :90F2BF39:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 21:03:29.359760 :90F2BF3A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 21:03:29.359760 :90F2BF3B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 21:03:29.360241 :90F2BF3C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 21:03:29.360283 :90F2BF43:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-30 21:13:30.197102 :90F38808:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 21:13:30.639258 :90F3883C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 21:13:30.634 2025-04-30 21:13:30.639260 :90F3883D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=2196 pso_num=25 pso_serial#=139 2025-04-30 21:13:30.639400 :90F3883E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=2196 osp_idx=23 osp_ver=71028 osp_pg=0 (spawn #135050) 2025-04-30 21:13:30.639401 :90F3883F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 21:13:30.639402 :90F38840:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=207 time=3318400125 2025-04-30 21:13:30.639402 :90F38841:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 21:13:30.639404 :90F38842:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 21:13:30.639404 :90F38843:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 21:13:30.639404 :90F38844:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 21:13:30.639405 :90F38845:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 21:13:30.639898 :90F38846:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 21:13:30.639945 :90F3884D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-30 21:17:05.719559 :90F3CD0C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-04-30 21:23:31.949838 :90F44AEE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-04-30 21:33:32.841411 :90F50D67:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 21:33:33.345992 :90F50DA9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 21:33:33.341 2025-04-30 21:33:33.345995 :90F50DAA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11492 pso_num=25 pso_serial#=140 2025-04-30 21:33:33.346135 :90F50DAB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11492 osp_idx=23 osp_ver=71029 osp_pg=0 (spawn #135096) 2025-04-30 21:33:33.346135 :90F50DAC:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 21:33:33.346136 :90F50DAD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=208 time=3319602828 2025-04-30 21:33:33.346136 :90F50DAE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 21:33:33.346136 :90F50DAF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 21:33:33.346137 :90F50DB0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 21:33:33.346137 :90F50DB1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 21:33:33.346137 :90F50DB2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 21:33:33.346637 :90F50DB3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 21:33:33.346680 :90F50DBB:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-30 21:43:34.164738 :90F5D068:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 21:43:34.288464 :90F5D06B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 21:43:34.274 2025-04-30 21:43:34.288466 :90F5D06C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11292 pso_num=25 pso_serial#=141 2025-04-30 21:43:34.288606 :90F5D06D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=11292 (legacy spawn) 2025-04-30 21:43:34.309640 :90F5D06E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-30 21:43:34.309812 :90F5D077:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-04-30 21:43:34.310596 :90F5D078:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 21:43:34.319163 :90F5D07B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 21:43:34.305 2025-04-30 21:43:34.319165 :90F5D07C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8088 pso_num=25 pso_serial#=142 2025-04-30 21:43:34.319353 :90F5D07D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=8088 (legacy spawn) 2025-04-30 21:43:34.325862 :90F5D07E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-30 21:43:34.326033 :90F5D087:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-04-30 21:43:34.326829 :90F5D088:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 21:43:34.763124 :90F5D0C0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 21:43:34.758 2025-04-30 21:43:34.763126 :90F5D0C1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11512 pso_num=25 pso_serial#=143 2025-04-30 21:43:34.763278 :90F5D0C2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11512 osp_idx=23 osp_ver=71032 osp_pg=0 (spawn #135119) 2025-04-30 21:43:34.763279 :90F5D0C3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 21:43:34.763279 :90F5D0C4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=209 time=3320204250 2025-04-30 21:43:34.763280 :90F5D0C5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 21:43:34.763280 :90F5D0C6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 21:43:34.763280 :90F5D0C7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 21:43:34.763281 :90F5D0C8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 21:43:34.763281 :90F5D0C9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 21:43:34.763818 :90F5D0CA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 21:43:34.763866 :90F5D0D2:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-30 21:53:35.601591 :90F69375:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-30 21:53:36.168829 :90F693B8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-30 21:53:36.164 2025-04-30 21:53:36.168831 :90F693B9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11440 pso_num=25 pso_serial#=144 2025-04-30 21:53:36.168968 :90F693BA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11440 osp_idx=23 osp_ver=71033 osp_pg=0 (spawn #135142) 2025-04-30 21:53:36.168969 :90F693BB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-30 21:53:36.168969 :90F693BC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=210 time=3320805656 2025-04-30 21:53:36.168970 :90F693BD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-30 21:53:36.168970 :90F693BE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-30 21:53:36.168970 :90F693BF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-30 21:53:36.168970 :90F693C0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-30 21:53:36.168971 :90F693C1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-30 21:53:36.169480 :90F693C2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-30 21:53:36.169525 :90F693C9:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 11440, W000)