Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250425221409\orcl_w000_2956_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:37623M/63366M, Ph+PgF:45334M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 2956, image: ORACLE.EXE (W000) *** 2025-04-25 22:14:09.982 *** SESSION ID:(177.20939) 2025-04-25 22:14:09.982 *** 2025-04-25 22:14:09.982 Process diagnostic dump for ORACLE.EXE (W000), OS id=2956, pid: 22, proc_ser: 213, sid: 177, sess_ser: 20939 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=68 seq_num=69 snap_id=1 wait times: snap=3.006865 sec, exc=3.006865 sec, total=3.006865 sec wait times: max=5.000000 sec, heur=5 min 38 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=67 seq_num=68 snap_id=1 wait times: snap=5.008089 sec, exc=5.008089 sec, total=5.008089 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=66 seq_num=67 snap_id=1 wait times: snap=5.003342 sec, exc=5.003342 sec, total=5.003342 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=65 seq_num=66 snap_id=1 wait times: snap=5.010158 sec, exc=5.010158 sec, total=5.010158 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=64 seq_num=65 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 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=63 seq_num=64 snap_id=1 wait times: snap=5.004615 sec, exc=5.004615 sec, total=5.004615 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=62 seq_num=63 snap_id=1 wait times: snap=5.008328 sec, exc=5.008328 sec, total=5.008328 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=61 seq_num=62 snap_id=1 wait times: snap=5.000330 sec, exc=5.000330 sec, total=5.000330 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=60 seq_num=61 snap_id=1 wait times: snap=5.007827 sec, exc=5.007827 sec, total=5.007827 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 8: 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.003744 sec, exc=5.003744 sec, total=5.003744 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=58 seq_num=59 snap_id=1 wait times: snap=5.014718 sec, exc=5.014718 sec, total=5.014718 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time Sampled Session History of session 177 serial 20939 --------------------------------------------------- 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:12:09 - 22:14:09] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-25 22:14:09.982 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 2956, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-25 20:17:33.611675 :8EB3D7A3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:17:33.605 2025-04-25 20:17:33.611677 :8EB3D7A4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11012 pso_num=22 pso_serial#=200 2025-04-25 20:17:33.611846 :8EB3D7A5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11012 osp_idx=0 osp_ver=122090 osp_pg=0 (spawn #117954) 2025-04-25 20:17:33.611847 :8EB3D7A6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 20:17:33.611848 :8EB3D7A7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=154 time=2883055406 2025-04-25 20:17:33.611848 :8EB3D7A8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 20:17:33.611849 :8EB3D7A9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 20:17:33.611849 :8EB3D7AA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 20:17:33.611850 :8EB3D7AB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 20:17:33.611850 :8EB3D7AC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 20:17:33.612378 :8EB3D7AD: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-04-25 20:17:33.613007 :8EB3D7C2: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-04-25 20:17:33.618461 :8EB3D7DE: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-04-25 20:17:33.619413 :8EB3D7E6: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-04-25 20:17:33.619541 :8EB3D7EF: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-04-25 20:17:38.608723 :8EB3D9B3:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-25 20:17:38.608743*:8EB3D9B6:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002494BB58 estart=1745583458 eid=16830162 ctx=0x000000077BD98A08 cwh=0x00000000232802A0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-04-25 20:17:38.608743*:8EB3D9B7:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002494BB58 curCtx=0x000000002328F300 pubTabIdxCnt=0 2025-04-25 20:17:38.608743*:8EB3D9B8:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002494BB58 2025-04-25 20:17:38.608743*:8EB3D9B9:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002494BB58 2025-04-25 20:17:38.608743*:8EB3D9BA:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002494BB58 curCtx=0x000000002328F300 xsc->flg4=65792 flags=2 2025-04-25 20:17:38.608743*:8EB3D9BB:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002494BB58 2025-04-25 20:17:38.609222 :8EB3D9BC: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-04-25 20:17:38.616582 :8EB3D9C4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-04-25 20:17:38.616959 :8EB3D9C5: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-04-25 20:17:38.616996 :8EB3D9C8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-04-25 20:17:38.617800 :8EB3D9CE: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-04-25 20:17:38.617918 :8EB3D9D7: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-04-25 20:18:08.715467 :8EB3E37A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 20:18:17.884411 :8EB3E631:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:18:17.876 2025-04-25 20:18:17.884413 :8EB3E632:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8604 pso_num=22 pso_serial#=201 2025-04-25 20:18:17.884566 :8EB3E633:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8604 (legacy spawn) 2025-04-25 20:18:17.890941 :8EB3E634: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-04-25 20:18:17.891110 :8EB3E63D: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-04-25 20:18:17.891954 :8EB3E63E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 20:18:17.900593 :8EB3E641:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:18:17.892 2025-04-25 20:18:17.900596 :8EB3E642:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7404 pso_num=22 pso_serial#=202 2025-04-25 20:18:17.900739 :8EB3E643:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=7404 (legacy spawn) 2025-04-25 20:18:17.907240 :8EB3E644: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-04-25 20:18:17.907465 :8EB3E64D: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-04-25 20:18:17.908575 :8EB3E64E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 20:18:18.193279 :8EB3E676:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:18:18.189 2025-04-25 20:18:18.193280 :8EB3E677:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10588 pso_num=22 pso_serial#=203 2025-04-25 20:18:18.193416 :8EB3E678:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10588 osp_idx=0 osp_ver=122093 osp_pg=0 (spawn #117956) 2025-04-25 20:18:18.193417 :8EB3E679:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 20:18:18.193418 :8EB3E67A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=155 time=2883099984 2025-04-25 20:18:18.193418 :8EB3E67B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 20:18:18.193418 :8EB3E67C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 20:18:18.193419 :8EB3E67D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 20:18:18.193419 :8EB3E67E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 20:18:18.193420 :8EB3E67F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 20:18:18.193906 :8EB3E680: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-04-25 20:18:18.193951 :8EB3E688: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-04-25 20:28:18.984682 :8EB4AE43:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 20:28:19.333354 :8EB4AE71:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:28:19.328 2025-04-25 20:28:19.333356 :8EB4AE72:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7964 pso_num=22 pso_serial#=204 2025-04-25 20:28:19.333500 :8EB4AE73:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7964 osp_idx=0 osp_ver=122094 osp_pg=0 (spawn #117979) 2025-04-25 20:28:19.333501 :8EB4AE74:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 20:28:19.333501 :8EB4AE75:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=156 time=2883701125 2025-04-25 20:28:19.333501 :8EB4AE76:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 20:28:19.333502 :8EB4AE77:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 20:28:19.333502 :8EB4AE78:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 20:28:19.333503 :8EB4AE79:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 20:28:19.333503 :8EB4AE7A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 20:28:19.333999 :8EB4AE7B: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-04-25 20:28:19.334044 :8EB4AE83: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-04-25 20:38:20.286432 :8EB5762A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 20:38:20.509988 :8EB5766D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:38:20.505 2025-04-25 20:38:20.509990 :8EB5766E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10264 pso_num=22 pso_serial#=205 2025-04-25 20:38:20.510126 :8EB5766F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10264 osp_idx=0 osp_ver=122095 osp_pg=0 (spawn #118002) 2025-04-25 20:38:20.510127 :8EB57670:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 20:38:20.510127 :8EB57671:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=157 time=2884302312 2025-04-25 20:38:20.510128 :8EB57672:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 20:38:20.510128 :8EB57673:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 20:38:20.510128 :8EB57674:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 20:38:20.510129 :8EB57675:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 20:38:20.510129 :8EB57676:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 20:38:20.510690 :8EB57677: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-04-25 20:38:20.510735 :8EB5767F: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-04-25 20:48:21.527554 :8EB63E3A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 20:48:21.719756 :8EB63E7C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:48:21.714 2025-04-25 20:48:21.719758 :8EB63E7D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8612 pso_num=22 pso_serial#=206 2025-04-25 20:48:21.719901 :8EB63E7E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8612 osp_idx=0 osp_ver=122096 osp_pg=0 (spawn #118024) 2025-04-25 20:48:21.719902 :8EB63E7F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 20:48:21.719902 :8EB63E80:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=158 time=2884903515 2025-04-25 20:48:21.719903 :8EB63E81:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 20:48:21.719903 :8EB63E82:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 20:48:21.719904 :8EB63E83:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 20:48:21.719904 :8EB63E84:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 20:48:21.719904 :8EB63E85:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 20:48:21.720397 :8EB63E86: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-04-25 20:48:21.720442 :8EB63E8D: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-04-25 20:58:22.613994 :8EB7055D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 20:58:22.946694 :8EB70580:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 20:58:22.942 2025-04-25 20:58:22.946696 :8EB70581:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9484 pso_num=22 pso_serial#=207 2025-04-25 20:58:22.946825 :8EB70582:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9484 osp_idx=0 osp_ver=122097 osp_pg=0 (spawn #118047) 2025-04-25 20:58:22.946826 :8EB70583:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 20:58:22.946826 :8EB70584:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=159 time=2885504750 2025-04-25 20:58:22.946827 :8EB70585:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 20:58:22.946827 :8EB70586:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 20:58:22.946827 :8EB70587:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 20:58:22.946828 :8EB70588:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 20:58:22.946828 :8EB70589:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 20:58:22.947317 :8EB7058A: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-04-25 20:58:22.947365 :8EB70592: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-04-25 21:08:23.847701 :8EB7D7F0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 21:08:24.149443 :8EB7D814:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 21:08:24.144 2025-04-25 21:08:24.149445 :8EB7D815:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11240 pso_num=22 pso_serial#=208 2025-04-25 21:08:24.149598 :8EB7D816:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11240 osp_idx=0 osp_ver=122098 osp_pg=0 (spawn #118073) 2025-04-25 21:08:24.149598 :8EB7D817:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 21:08:24.149599 :8EB7D818:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=160 time=2886105937 2025-04-25 21:08:24.149599 :8EB7D819:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 21:08:24.149599 :8EB7D81A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 21:08:24.149600 :8EB7D81B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 21:08:24.149600 :8EB7D81C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 21:08:24.149600 :8EB7D81D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 21:08:24.150157 :8EB7D81E: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-04-25 21:08:24.150204 :8EB7D825: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-04-25 21:15:35.758141 :8EB86808:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-04-25 21:18:25.332287 :8EB8A078:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-04-25 21:28:26.127551 :8EB968C6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 21:28:26.548477 :8EB968E9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 21:28:26.544 2025-04-25 21:28:26.548479 :8EB968EA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9468 pso_num=22 pso_serial#=209 2025-04-25 21:28:26.548612 :8EB968EB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9468 osp_idx=0 osp_ver=122099 osp_pg=0 (spawn #118119) 2025-04-25 21:28:26.548613 :8EB968EC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 21:28:26.548613 :8EB968ED:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=161 time=2887308343 2025-04-25 21:28:26.548614 :8EB968EE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 21:28:26.548614 :8EB968EF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 21:28:26.548614 :8EB968F0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 21:28:26.548615 :8EB968F1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 21:28:26.548615 :8EB968F2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 21:28:26.549105 :8EB968F3: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-04-25 21:28:26.549152 :8EB968FB: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-04-25 21:38:27.487556 :8EBA3217:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 21:38:27.726561 :8EBA323C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 21:38:27.721 2025-04-25 21:38:27.726563 :8EBA323D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10924 pso_num=22 pso_serial#=210 2025-04-25 21:38:27.726699 :8EBA323E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10924 osp_idx=0 osp_ver=122100 osp_pg=0 (spawn #118142) 2025-04-25 21:38:27.726699 :8EBA323F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 21:38:27.726700 :8EBA3240:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=162 time=2887909515 2025-04-25 21:38:27.726700 :8EBA3241:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 21:38:27.726700 :8EBA3242:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 21:38:27.726701 :8EBA3243:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 21:38:27.726701 :8EBA3244:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 21:38:27.726701 :8EBA3245:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 21:38:27.727189 :8EBA3246: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-04-25 21:38:27.727234 :8EBA324E: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-04-25 21:48:28.666362 :8EBAF9F5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 21:48:29.030380 :8EBAFA3E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 21:48:29.026 2025-04-25 21:48:29.030382 :8EBAFA3F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10028 pso_num=22 pso_serial#=211 2025-04-25 21:48:29.030514 :8EBAFA40:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10028 osp_idx=0 osp_ver=122101 osp_pg=0 (spawn #118164) 2025-04-25 21:48:29.030515 :8EBAFA41:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 21:48:29.030515 :8EBAFA42:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=163 time=2888510828 2025-04-25 21:48:29.030516 :8EBAFA43:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 21:48:29.030517 :8EBAFA44:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 21:48:29.030517 :8EBAFA45:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 21:48:29.030517 :8EBAFA46:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 21:48:29.030518 :8EBAFA47:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 21:48:29.031086 :8EBAFA48: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-04-25 21:48:29.031140 :8EBAFA4F: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-04-25 21:58:29.869479 :8EBBC311:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 21:58:30.264807 :8EBBC35D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 21:58:30.259 2025-04-25 21:58:30.264808 :8EBBC35E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4320 pso_num=22 pso_serial#=212 2025-04-25 21:58:30.264942 :8EBBC35F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4320 osp_idx=0 osp_ver=122102 osp_pg=0 (spawn #118187) 2025-04-25 21:58:30.264943 :8EBBC360:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 21:58:30.264943 :8EBBC361:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=164 time=2889112062 2025-04-25 21:58:30.264943 :8EBBC362:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 21:58:30.264944 :8EBBC363:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 21:58:30.264944 :8EBBC364:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 21:58:30.264944 :8EBBC365:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 21:58:30.264945 :8EBBC366:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 21:58:30.265438 :8EBBC367: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-04-25 21:58:30.265483 :8EBBC36E: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-04-25 22:08:31.095911 :8EBCA202:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-04-25 22:08:31.522423 :8EBCA232:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 04-25 22:08:31.518 2025-04-25 22:08:31.522425 :8EBCA233:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2956 pso_num=22 pso_serial#=213 2025-04-25 22:08:31.522561 :8EBCA234:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2956 osp_idx=0 osp_ver=122103 osp_pg=0 (spawn #118223) 2025-04-25 22:08:31.522561 :8EBCA235:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-25 22:08:31.522562 :8EBCA236:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=165 time=2889713312 2025-04-25 22:08:31.522562 :8EBCA237:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-04-25 22:08:31.522563 :8EBCA238:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-04-25 22:08:31.522563 :8EBCA239:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-04-25 22:08:31.522563 :8EBCA23A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-25 22:08:31.522564 :8EBCA23B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-25 22:08:31.523052 :8EBCA23C: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-04-25 22:08:31.523100 :8EBCA243: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: 2956, W000)