Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510060009\orcl_j001_4728_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:37473M/63366M, Ph+PgF:44814M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 4728, image: ORACLE.EXE (J001) *** 2025-05-10 06:00:09.402 *** SESSION ID:(209.32677) 2025-05-10 06:00:09.402 *** 2025-05-10 06:00:09.402 Process diagnostic dump for ORACLE.EXE (J001), OS id=4728, pid: 26, proc_ser: 165, sid: 209, sess_ser: 32677 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 4728 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.107866 sec, exc=0.107866 sec, total=0.107866 sec wait times: max=0.500000 sec, heur=5.129001 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.000011 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.512656 sec, exc=0.512656 sec, total=0.512656 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.499984 sec, exc=0.499984 sec, total=0.499984 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.510113 sec, exc=0.510113 sec, total=0.510113 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.510082 sec, exc=0.510082 sec, total=0.510082 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500023 sec, exc=0.500023 sec, total=0.500023 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.500000 sec, exc=0.500000 sec, total=0.500000 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.488190 sec, exc=0.488190 sec, total=0.488190 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 209 serial 32677 --------------------------------------------------- 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 --------------------------------------------------- [6 samples, 06:00:04 - 06:00:09] idle wait at each sample [session created at: 06:00:04] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 06:00:09.402 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 4728, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 05:58:19.022474 :951875EB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:58:19.022646 :951875F3:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:58:19.023490 :951875F5:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:58:19.032640 :951875F8:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:58:19.028 2025-05-10 05:58:19.032642 :951875F9:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11912 pso_num=26 pso_serial#=154 2025-05-10 05:58:19.032782 :951875FA:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=11912 (legacy spawn) 2025-05-10 05:58:19.039450 :951875FB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:58:19.039620 :95187604:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:58:19.040488 :95187605:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:58:19.676609 :9518762C:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:58:19.668 2025-05-10 05:58:19.676611 :9518762D:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11808 pso_num=26 pso_serial#=155 2025-05-10 05:58:19.676752 :9518762E:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=11808 (legacy spawn) 2025-05-10 05:58:19.688724 :9518762F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:58:19.688889 :95187638:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:58:19.689701 :95187639:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:58:25.706762 :9518780D:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:58:25.699 2025-05-10 05:58:25.706764 :9518780E:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13176 pso_num=26 pso_serial#=156 2025-05-10 05:58:25.706899 :9518780F:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=13176 (legacy spawn) 2025-05-10 05:58:25.713367 :95187810:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:58:25.713560 :95187815:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:58:25.714348 :9518781A:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:58:28.057586 :951878E8:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:58:28.048 2025-05-10 05:58:28.057588 :951878E9:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12512 pso_num=26 pso_serial#=157 2025-05-10 05:58:28.057720 :951878EA:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=12512 (legacy spawn) 2025-05-10 05:58:28.064229 :951878EB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:58:28.064394 :951878F1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:58:28.065232 :951878F5:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:59:21.870060 :95188A71:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:59:21.862 2025-05-10 05:59:21.870062 :95188A72:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12016 pso_num=26 pso_serial#=158 2025-05-10 05:59:21.870199 :95188A73:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=12016 (legacy spawn) 2025-05-10 05:59:21.876613 :95188A74:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:59:21.876777 :95188A7D:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:59:21.877597 :95188A97:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:59:28.520628 :95188CB5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:59:28.506 2025-05-10 05:59:28.520630 :95188CB6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10440 pso_num=26 pso_serial#=159 2025-05-10 05:59:28.520771 :95188CB7:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=10440 (legacy spawn) 2025-05-10 05:59:28.527290 :95188CB8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:59:28.527462 :95188CBE:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:59:28.528263 :95188CC2:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:59:28.536756 :95188CC5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:59:28.522 2025-05-10 05:59:28.536758 :95188CC6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11828 pso_num=26 pso_serial#=160 2025-05-10 05:59:28.536891 :95188CC7:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=11828 (legacy spawn) 2025-05-10 05:59:28.543361 :95188CC8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:59:28.543522 :95188CD1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:59:28.544297 :95188CD2:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:59:31.717148 :95188DC5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:59:31.704 2025-05-10 05:59:31.717150 :95188DC6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=5024 pso_num=26 pso_serial#=161 2025-05-10 05:59:31.717286 :95188DC7:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=5024 (legacy spawn) 2025-05-10 05:59:31.723774 :95188DC8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:59:31.723955 :95188DCF:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:59:31.724744 :95188DD2:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:59:31.743903 :95188DD5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:59:31.735 2025-05-10 05:59:31.743905 :95188DD6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10332 pso_num=26 pso_serial#=162 2025-05-10 05:59:31.744046 :95188DD7:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=10332 (legacy spawn) 2025-05-10 05:59:31.750458 :95188DD8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:59:31.750633 :95188DE1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:59:31.751426 :95188DE2:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:59:36.345207 :95188F06:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:59:36.336 2025-05-10 05:59:36.345209 :95188F07:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12064 pso_num=26 pso_serial#=163 2025-05-10 05:59:36.345352 :95188F08:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=12064 (legacy spawn) 2025-05-10 05:59:36.351985 :95188F15:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 05:59:36.352166 :95188F1A:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-10 05:59:36.353051 :95188F1F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 05:59:38.466631 :95189001:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 05:59:38.461 2025-05-10 05:59:38.466633 :95189002:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9744 pso_num=26 pso_serial#=164 2025-05-10 05:59:38.466763 :95189003:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9744 osp_idx=24 osp_ver=244708 osp_pg=0 (spawn #166793) 2025-05-10 05:59:38.466764 :95189004:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 05:59:38.466765 :95189005:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=102 time=4127555625 2025-05-10 05:59:38.466765 :95189006:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 05:59:38.466766 :95189007:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 05:59:38.466766 :95189008:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 05:59:38.466766 :95189009:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 05:59:38.466767 :9518900A:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 05:59:38.467259 :9518900B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 05:59:38.467306 :95189011:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 05:59:38.471552 :9518902A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:kelt.c:517 2025-05-10 05:59:38.471595 :9518902B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:kelt.c:517 2025-05-10 05:59:38.471860 :9518902C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:kelt.c:517 2025-05-10 05:59:38.471876 :9518902D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:kelt.c:517 2025-05-10 05:59:38.472091 :9518902E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:kelt.c:517 2025-05-10 05:59:38.472104 :9518902F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:kelt.c:517 2025-05-10 05:59:38.472322 :95189030:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:kelt.c:517 2025-05-10 05:59:38.472336 :95189031:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:kelt.c:517 2025-05-10 05:59:38.472550 :95189032:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:kelt.c:517 2025-05-10 05:59:38.472563 :95189033:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:kelt.c:517 2025-05-10 05:59:38.472774 :95189034:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:kelt.c:517 2025-05-10 05:59:38.472786 :95189035:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:kelt.c:517 2025-05-10 05:59:38.475014 :95189036:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-10 06:00:02.047291 :95189902:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-10 06:00:02.037 2025-05-10 06:00:02.047293 :95189903:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=4728 pso_num=26 pso_serial#=165 2025-05-10 06:00:02.047420 :95189904:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=4728 osp_idx=24 osp_ver=244709 osp_pg=0 (spawn #166797) 2025-05-10 06:00:02.047422 :95189905:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-10 06:00:02.047422 :95189906:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=103 time=4127579203 2025-05-10 06:00:02.047422 :95189907:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 06:00:02.047423 :95189908:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 06:00:02.047423 :95189909:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 06:00:02.047423 :9518990A:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 06:00:02.047423 :9518990B:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 06:00:02.047899 :9518990F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.053137 :9518992F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.053180 :95189930:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:jslv.c:9203 2025-05-10 06:00:02.056533 :95189957:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.365885 :95189C81:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.409096 :95189C89:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.424969 :95189C9D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.482661 :95189CAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.616058 :95189CD8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.628532 :95189CE0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.637900 :95189CE8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.652476 :95189CF0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.666448 :95189CF8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.681068 :95189D00:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.690393 :95189D08:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.704942 :95189D10:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.713844 :95189D18:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.728392 :95189D20:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.737967 :95189D28:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.746883 :95189D30:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.761270 :95189D38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.770526 :95189D40:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.785276 :95189D48:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.799918 :95189D50:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.814330 :95189D58:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.828636 :95189D60:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.838226 :95189D68:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.852801 :95189D70:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.862679 :95189D78:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.871487 :95189D80:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.886833 :95189D88:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.901259 :95189D90:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.908249 :95189D98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.916797 :95189DA0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.925250 :95189DA8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.935100 :95189DB0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.949877 :95189DB8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.964457 :95189DC0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.974295 :95189DC8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.982942 :95189DD0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:02.997774 :95189DD8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.012033 :95189DE0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.021231 :95189DE8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.030539 :95189DF0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.044686 :95189DF8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.054545 :95189E00:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.063721 :95189E08:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.078169 :95189E10:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.085255 :95189E18:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.092050 :95189E20:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.098947 :95189E28:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.106010 :95189E30:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.113056 :95189E38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.120306 :95189E40:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.127885 :95189E48:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.134984 :95189E50:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.142374 :95189E58:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.149812 :95189E60:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.157001 :95189E68:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:03.395952*:95189E70:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000029216918 estart=1746828002 eid=16777311 ctx=0x00000007831EA738 cwh=0x00000000291E0068 cpu=234375 buffg=45715 interb=229376 r=14 rb=229376 w=0 wb=0 2025-05-10 06:00:03.395952*:95189E71:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000029216918 curCtx=0x000000003ADE58F8 pubTabIdxCnt=0 2025-05-10 06:00:03.395952*:95189E72:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000029216918 2025-05-10 06:00:03.395952*:95189E73:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000029216918 2025-05-10 06:00:03.395952*:95189E75:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000271EC288 estart=1746828001 eid=16777263 ctx=0x000000079F654AA8 cwh=0x00000000271E0158 cpu=1312500 buffg=133686 interb=28606464 r=1466 rb=26288128 w=12 wb=2318336 2025-05-10 06:00:03.395952*:95189E78:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000271EC288 curCtx=0x0000000029218510 pubTabIdxCnt=0 2025-05-10 06:00:03.395952*:95189E79:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000271EC288 2025-05-10 06:00:03.395952*:95189E7A:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000271EC288 2025-05-10 06:00:03.708453*:95189F50:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000029216918 curCtx=0x000000003ADE58F8 xsc->flg4=65792 flags=1 2025-05-10 06:00:03.708453*:95189F51:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000029216918 2025-05-10 06:00:04.233098 :9518A05E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.235518 :9518A066:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.235773 :9518A06E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.243260 :9518A076:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.252342 :9518A07E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.259843 :9518A086:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.267281 :9518A08E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.275760 :9518A096:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.276067 :9518A09E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.276067*:9518A0A1:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000271EC288 curCtx=0x0000000029218510 xsc->flg4=65792 flags=2 2025-05-10 06:00:04.276067*:9518A0A5:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000271EC288 2025-05-10 06:00:04.276348 :9518A0A8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:jslv.c:9203 2025-05-10 06:00:04.277276 :9518A0A9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.280973 :9518A0B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.281062 :9518A0B4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-10 06:00:04.281148 :9518A0C1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 4728, J001)