Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250713220438\orcl_w000_18388_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:36396M/63366M, Ph+PgF:42430M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 18388, image: ORACLE.EXE (W000) *** 2025-07-13 22:04:38.601 *** SESSION ID:(201.40183) 2025-07-13 22:04:38.601 *** 2025-07-13 22:04:38.601 Process diagnostic dump for ORACLE.EXE (W000), OS id=18388, pid: 25, proc_ser: 184, sid: 201, sess_ser: 40183 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=4.222356 sec, exc=4.222356 sec, total=4.222356 sec wait times: max=5.000000 sec, heur=2 min 49 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.000027 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=5.004611 sec, exc=5.004611 sec, total=5.004611 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=5.008333 sec, exc=5.008333 sec, total=5.008333 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.000281 sec, exc=5.000281 sec, total=5.000281 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.013079 sec, exc=5.013079 sec, total=5.013079 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.008765 sec, exc=5.008765 sec, total=5.008765 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=28 seq_num=29 snap_id=1 wait times: snap=5.011404 sec, exc=5.011404 sec, total=5.011404 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=5.004617 sec, exc=5.004617 sec, total=5.004617 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.004640 sec, exc=5.004640 sec, total=5.004640 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.015232 sec, exc=5.015232 sec, total=5.015232 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=24 seq_num=25 snap_id=1 wait times: snap=5.003493 sec, exc=5.003493 sec, total=5.003493 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 201 serial 40183 --------------------------------------------------- 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:02:38 - 22:04:38] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-13 22:04:38.601 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 18388, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-13 21:30:15.231074 :B1986C74:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:30:16.413755 :B1986CF1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:30:16.402 2025-07-13 21:30:16.413757 :B1986CF2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17752 pso_num=25 pso_serial#=170 2025-07-13 21:30:16.413890 :B1986CF3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17752 osp_idx=23 osp_ver=195867 osp_pg=0 (spawn #382429) 2025-07-13 21:30:16.413891 :B1986CF4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:30:16.413891 :B1986CF5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=151 time=1122992298 2025-07-13 21:30:16.413892 :B1986CF6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:30:16.413893 :B1986CF7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:30:16.413893 :B1986CF8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:30:16.413893 :B1986CF9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:30:16.413893 :B1986CFA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:30:16.414363 :B1986CFF: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-07-13 21:30:45.215985 :B1987633: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-07-13 21:31:10.252557 :B1987E57: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-07-13 21:31:10.252594*:B1987E59:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BDBB58 estart=1752413469 eid=16955582 ctx=0x000000077BD98A08 cwh=0x0000000026B901B0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-13 21:31:10.252594*:B1987E5A:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BDBB58 curCtx=0x0000000026B9F708 pubTabIdxCnt=0 2025-07-13 21:31:10.252594*:B1987E5B:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BDBB58 2025-07-13 21:31:10.252594*:B1987E5C:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BDBB58 2025-07-13 21:31:10.252594*:B1987E5D:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BDBB58 curCtx=0x0000000026B9F708 xsc->flg4=65792 flags=2 2025-07-13 21:31:10.252594*:B1987E5E:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BDBB58 2025-07-13 21:31:10.253207 :B1987E5F: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-07-13 21:31:10.258734 :B1987E67: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-07-13 21:31:10.259810 :B1987E6F: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-07-13 21:31:10.259953 :B1987E78: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-07-13 21:31:40.346170 :B19887DB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:31:45.310535 :B19889E2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:31:45.298 2025-07-13 21:31:45.310537 :B19889E3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16556 pso_num=25 pso_serial#=171 2025-07-13 21:31:45.310659 :B19889E4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16556 osp_idx=23 osp_ver=195868 osp_pg=0 (spawn #382432) 2025-07-13 21:31:45.310660 :B19889E5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:31:45.310660 :B19889E6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=152 time=1123081204 2025-07-13 21:31:45.310660 :B19889E7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:31:45.310661 :B19889E8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:31:45.310661 :B19889E9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:31:45.310661 :B19889EA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:31:45.310662 :B19889EB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:31:45.311154 :B19889EC: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-07-13 21:32:15.413391 :B19893B0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:32:45.426404 :B1989D8D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:32:45.415 2025-07-13 21:32:45.426406 :B1989D8E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4120 pso_num=25 pso_serial#=172 2025-07-13 21:32:45.426532 :B1989D8F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4120 osp_idx=23 osp_ver=195869 osp_pg=0 (spawn #382434) 2025-07-13 21:32:45.426532 :B1989D90:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:32:45.426532 :B1989D91:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=153 time=1123141314 2025-07-13 21:32:45.426532 :B1989D92:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:32:45.426533 :B1989D93:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:32:45.426533 :B1989D94:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:32:45.426534 :B1989D95:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:32:45.426534 :B1989D96:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:32:45.427033 :B1989D97: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-07-13 21:33:15.513368 :B198A74A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:33:45.508794 :B198B122:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:33:45.496 2025-07-13 21:33:45.508796 :B198B123:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11176 pso_num=25 pso_serial#=173 2025-07-13 21:33:45.508908 :B198B124:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11176 osp_idx=23 osp_ver=195870 osp_pg=0 (spawn #382436) 2025-07-13 21:33:45.508909 :B198B125:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:33:45.508909 :B198B126:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=154 time=1123201392 2025-07-13 21:33:45.508910 :B198B127:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:33:45.508910 :B198B128:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:33:45.508910 :B198B129:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:33:45.508911 :B198B12A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:33:45.508911 :B198B12B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:33:45.509406 :B198B12C: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-07-13 21:34:15.581106 :B198BB46:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:34:45.633724 :B198C514:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:34:45.631 2025-07-13 21:34:45.633727 :B198C515:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13352 pso_num=25 pso_serial#=174 2025-07-13 21:34:45.633863 :B198C516:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13352 osp_idx=23 osp_ver=195871 osp_pg=0 (spawn #382439) 2025-07-13 21:34:45.633863 :B198C517:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:34:45.633864 :B198C518:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=155 time=1123261517 2025-07-13 21:34:45.633864 :B198C519:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:34:45.633865 :B198C51A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:34:45.633865 :B198C51B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:34:45.633865 :B198C51C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:34:45.633866 :B198C51D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:34:45.634351 :B198C51E: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-07-13 21:35:15.770416 :B198CE6B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:35:45.769918 :B198D825:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:35:45.759 2025-07-13 21:35:45.769920 :B198D826:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7628 pso_num=25 pso_serial#=175 2025-07-13 21:35:45.770039 :B198D827:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7628 osp_idx=23 osp_ver=195872 osp_pg=0 (spawn #382441) 2025-07-13 21:35:45.770039 :B198D828:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:35:45.770040 :B198D829:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=156 time=1123321658 2025-07-13 21:35:45.770040 :B198D82A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:35:45.770040 :B198D82B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:35:45.770041 :B198D82C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:35:45.770041 :B198D82D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:35:45.770041 :B198D82E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:35:45.770541 :B198D82F: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-07-13 21:36:15.847243 :B198E1EF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:36:45.905882 :B198EBAD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:36:45.894 2025-07-13 21:36:45.905883 :B198EBAE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15876 pso_num=25 pso_serial#=176 2025-07-13 21:36:45.906024 :B198EBAF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15876 osp_idx=23 osp_ver=195873 osp_pg=0 (spawn #382443) 2025-07-13 21:36:45.906025 :B198EBB0:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:36:45.906025 :B198EBB1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=157 time=1123381798 2025-07-13 21:36:45.906026 :B198EBB2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:36:45.906026 :B198EBB3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:36:45.906027 :B198EBB4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:36:45.906027 :B198EBB5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:36:45.906027 :B198EBB6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:36:45.906516 :B198EBB7: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-07-13 21:37:15.973136 :B198F586:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:37:45.979225 :B198FF35:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:37:45.968 2025-07-13 21:37:45.979227 :B198FF36:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18100 pso_num=25 pso_serial#=177 2025-07-13 21:37:45.979350 :B198FF37:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18100 osp_idx=23 osp_ver=195874 osp_pg=0 (spawn #382445) 2025-07-13 21:37:45.979351 :B198FF38:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:37:45.979353 :B198FF39:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=158 time=1123441861 2025-07-13 21:37:45.979353 :B198FF3A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:37:45.979354 :B198FF3B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:37:45.979354 :B198FF3C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:37:45.979354 :B198FF3D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:37:45.979355 :B198FF3E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:37:45.979835 :B198FF3F: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-07-13 21:38:16.053409 :B19908E3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:38:46.072377 :B1991293:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:38:46.060 2025-07-13 21:38:46.072379 :B1991294:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15540 pso_num=25 pso_serial#=178 2025-07-13 21:38:46.072501 :B1991295:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15540 osp_idx=23 osp_ver=195875 osp_pg=0 (spawn #382447) 2025-07-13 21:38:46.072502 :B1991296:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:38:46.072502 :B1991297:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=159 time=1123501954 2025-07-13 21:38:46.072503 :B1991298:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:38:46.072503 :B1991299:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:38:46.072504 :B199129A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:38:46.072504 :B199129B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:38:46.072504 :B199129C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:38:46.072996 :B199129D: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-07-13 21:39:16.192793 :B1991D3D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:39:46.174225 :B19926C5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:39:46.162 2025-07-13 21:39:46.174227 :B19926C6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17332 pso_num=25 pso_serial#=179 2025-07-13 21:39:46.174345 :B19926C7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17332 osp_idx=23 osp_ver=195876 osp_pg=0 (spawn #382449) 2025-07-13 21:39:46.174345 :B19926C8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:39:46.174346 :B19926C9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=160 time=1123562064 2025-07-13 21:39:46.174346 :B19926CA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:39:46.174346 :B19926CB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:39:46.174347 :B19926CC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:39:46.174347 :B19926CD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:39:46.174347 :B19926CE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:39:46.174827 :B19926CF: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-07-13 21:40:16.246818 :B1993054:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:40:46.292933 :B19939F5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:40:46.280 2025-07-13 21:40:46.292936 :B19939F6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12508 pso_num=25 pso_serial#=180 2025-07-13 21:40:46.293077 :B19939F7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12508 osp_idx=23 osp_ver=195877 osp_pg=0 (spawn #382451) 2025-07-13 21:40:46.293078 :B19939F8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:40:46.293078 :B19939F9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=161 time=1123622173 2025-07-13 21:40:46.293078 :B19939FA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:40:46.293078 :B19939FB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:40:46.293079 :B19939FC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:40:46.293079 :B19939FD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:40:46.293080 :B19939FE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:40:46.293615 :B19939FF: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-07-13 21:41:11.309478 :B1994217: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-07-13 21:41:41.388466 :B1994BC2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:41:46.371805 :B1994D7C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:41:46.358 2025-07-13 21:41:46.371807 :B1994D7D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=1168 pso_num=25 pso_serial#=181 2025-07-13 21:41:46.371945 :B1994D7E:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=1168 (legacy spawn) 2025-07-13 21:41:46.378400 :B1994D7F: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-07-13 21:41:46.378565 :B1994D88: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-07-13 21:41:46.379419 :B1994D89:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:41:46.472636 :B1994DD4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:41:46.468 2025-07-13 21:41:46.472638 :B1994DD5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15000 pso_num=25 pso_serial#=182 2025-07-13 21:41:46.472791 :B1994DD6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15000 osp_idx=23 osp_ver=195879 osp_pg=0 (spawn #382454) 2025-07-13 21:41:46.472792 :B1994DD7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:41:46.472792 :B1994DD8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=162 time=1123682361 2025-07-13 21:41:46.472793 :B1994DD9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:41:46.472793 :B1994DDA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:41:46.472794 :B1994DDB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:41:46.472794 :B1994DDC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:41:46.472795 :B1994DDD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:41:46.473331 :B1994DDE: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-07-13 21:41:46.473378 :B1994DE6: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-07-13 21:51:47.500125 :B19A12E5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 21:51:47.786051 :B19A1330:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 21:51:47.781 2025-07-13 21:51:47.786053 :B19A1331:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14972 pso_num=25 pso_serial#=183 2025-07-13 21:51:47.786193 :B19A1332:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14972 osp_idx=23 osp_ver=195880 osp_pg=0 (spawn #382477) 2025-07-13 21:51:47.786194 :B19A1333:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 21:51:47.786194 :B19A1334:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=163 time=1124283673 2025-07-13 21:51:47.786194 :B19A1335:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 21:51:47.786195 :B19A1336:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 21:51:47.786195 :B19A1337:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 21:51:47.786196 :B19A1338:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 21:51:47.786196 :B19A1339:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 21:51:47.786756 :B19A133A: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-07-13 21:51:47.786803 :B19A1342: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-07-13 22:01:48.705308 :B19AD991:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-13 22:01:49.163136 :B19AD9EC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-13 22:01:49.158 2025-07-13 22:01:49.163139 :B19AD9ED:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18388 pso_num=25 pso_serial#=184 2025-07-13 22:01:49.163339 :B19AD9EE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18388 osp_idx=23 osp_ver=195881 osp_pg=0 (spawn #382502) 2025-07-13 22:01:49.163340 :B19AD9EF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-13 22:01:49.163341 :B19AD9F0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=164 time=1124885064 2025-07-13 22:01:49.163341 :B19AD9F1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-13 22:01:49.163342 :B19AD9F2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-13 22:01:49.163342 :B19AD9F3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-13 22:01:49.163342 :B19AD9F4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-13 22:01:49.163343 :B19AD9F5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-13 22:01:49.163854 :B19AD9F6: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-07-13 22:01:49.163899 :B19AD9FE: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: 18388, W000)