Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250704220010\orcl_j002_8008_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:37224M/63366M, Ph+PgF:43201M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 8008, image: ORACLE.EXE (J002) *** 2025-07-04 22:00:10.169 *** SESSION ID:(233.27901) 2025-07-04 22:00:10.169 *** 2025-07-04 22:00:10.169 Process diagnostic dump for ORACLE.EXE (J002), OS id=8008, pid: 29, proc_ser: 134, sid: 233, sess_ser: 27901 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 8008 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.147387 sec, exc=0.147387 sec, total=0.147387 sec wait times: max=0.500000 sec, heur=6.142551 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.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 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.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 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.000008 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.505103 sec, exc=0.505103 sec, total=0.505103 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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.000007 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 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.000012 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.502063 sec, exc=0.502063 sec, total=0.502063 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.501099 sec, exc=0.501099 sec, total=0.501099 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 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.000012 sec of elapsed time Sampled Session History of session 233 serial 27901 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 22:00:04 - 22:00:10] idle wait at each sample [session created at: 22:00:04] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-04 22:00:10.169 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 8008, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-04 01:00:26.517137 :AD30D815:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 01:00:26.525773 :AD30D818:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 01:00:26.512 2025-07-04 01:00:26.525775 :AD30D819:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9008 pso_num=29 pso_serial#=125 2025-07-04 01:00:26.525906 :AD30D81A:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9008 (legacy spawn) 2025-07-04 01:00:26.532328 :AD30D81B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 01:00:26.532495 :AD30D824:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04 01:00:26.533320 :AD30D825:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 14:00:00.820991 :AD6E334D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 14:00:00.818 2025-07-04 14:00:00.820992 :AD6E334E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14676 pso_num=29 pso_serial#=126 2025-07-04 14:00:00.821122 :AD6E334F:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14676 osp_idx=27 osp_ver=13895 osp_pg=0 (spawn #351377) 2025-07-04 14:00:00.821123 :AD6E3350:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 14:00:00.821124 :AD6E3351:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=54 time=318376704 2025-07-04 14:00:00.821125 :AD6E3352:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 14:00:00.821126 :AD6E3353:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 14:00:00.821126 :AD6E3354:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 14:00:00.821127 :AD6E3355:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 14:00:00.821127 :AD6E3356:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 14:00:00.821684 :AD6E3357:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 14:00:00.821721 :AD6E335D:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 14:00:00.830581 :AD6E3382:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 15:00:08.324403 :AD72E6A2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 15:00:08.322 2025-07-04 15:00:08.324405 :AD72E6A3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18160 pso_num=29 pso_serial#=127 2025-07-04 15:00:08.324537 :AD72E6A4:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=18160 osp_idx=27 osp_ver=13896 osp_pg=0 (spawn #351515) 2025-07-04 15:00:08.324538 :AD72E6A5:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 15:00:08.324538 :AD72E6A6:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=55 time=321984204 2025-07-04 15:00:08.324539 :AD72E6A7:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 15:00:08.324539 :AD72E6A8:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 15:00:08.324539 :AD72E6A9:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 15:00:08.324540 :AD72E6AA:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 15:00:08.324540 :AD72E6AB:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 15:00:08.325038 :AD72E6AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 15:00:08.325076 :AD72E6B3:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 15:00:08.333775 :AD72E6D7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 16:00:15.931961 :AD778CC9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 16:00:15.919 2025-07-04 16:00:15.931963 :AD778CCA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12568 pso_num=29 pso_serial#=128 2025-07-04 16:00:15.932113 :AD778CCB:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12568 osp_idx=27 osp_ver=13897 osp_pg=0 (spawn #351654) 2025-07-04 16:00:15.932115 :AD778CCC:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 16:00:15.932115 :AD778CCD:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=56 time=325591814 2025-07-04 16:00:15.932116 :AD778CCE:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 16:00:15.932116 :AD778CCF:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 16:00:15.932117 :AD778CD0:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 16:00:15.932117 :AD778CD1:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 16:00:15.932117 :AD778CD2:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 16:00:15.932704 :AD778CD3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 16:00:15.932744 :AD778CD9:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 16:00:15.937155 :AD778CEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:15.965226 :AD778D1E:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 4286476573 8490728) 2025-07-04 16:00:15.965234 :AD778D1F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:15.965302 :AD778D34:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 16:00:15.965336 :AD778D37:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:15.980076 :AD778D3F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:16.008499 :AD778D47:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:16.012236 :AD778D4F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:16.016173 :AD778D57:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:16.020404 :AD778D5F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:16.021589 :AD778D67:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:17.275634 :AD778D99:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:17.310312 :AD778DBA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:17.310617 :AD778DC2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:17.310902 :AD778DCA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:17.310918 :AD778DCD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 16:00:17.310981 :AD778DDB:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04 16:00:17.314056 :AD778DE7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 17:00:23.379629 :AD7C316C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 17:00:23.376 2025-07-04 17:00:23.379631 :AD7C316D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12136 pso_num=29 pso_serial#=129 2025-07-04 17:00:23.379772 :AD7C316E:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12136 osp_idx=27 osp_ver=13898 osp_pg=0 (spawn #351793) 2025-07-04 17:00:23.379772 :AD7C316F:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 17:00:23.379773 :AD7C3170:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=57 time=329199267 2025-07-04 17:00:23.379774 :AD7C3171:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 17:00:23.379774 :AD7C3172:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 17:00:23.379775 :AD7C3173:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 17:00:23.379775 :AD7C3174:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 17:00:23.379776 :AD7C3175:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 17:00:23.380377 :AD7C3176:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 17:00:23.380420 :AD7C317C:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 17:00:23.389251 :AD7C3191:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 18:00:30.809270 :AD80D524:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 18:00:30.803 2025-07-04 18:00:30.809271 :AD80D525:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12108 pso_num=29 pso_serial#=130 2025-07-04 18:00:30.809403 :AD80D526:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12108 osp_idx=27 osp_ver=13899 osp_pg=0 (spawn #351932) 2025-07-04 18:00:30.809403 :AD80D527:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 18:00:30.809404 :AD80D528:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=58 time=332806704 2025-07-04 18:00:30.809404 :AD80D529:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 18:00:30.809405 :AD80D52A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 18:00:30.809405 :AD80D52B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 18:00:30.809406 :AD80D52C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 18:00:30.809406 :AD80D52D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 18:00:30.810007 :AD80D52E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 18:00:30.810052 :AD80D534:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 18:00:30.819638 :AD80D549:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 19:00:38.506883 :AD857DBA:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 19:00:38.503 2025-07-04 19:00:38.506884 :AD857DBB:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15576 pso_num=29 pso_serial#=131 2025-07-04 19:00:38.507014 :AD857DBC:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15576 osp_idx=27 osp_ver=13900 osp_pg=0 (spawn #352070) 2025-07-04 19:00:38.507015 :AD857DBD:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 19:00:38.507016 :AD857DBE:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=59 time=336414392 2025-07-04 19:00:38.507016 :AD857DBF:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 19:00:38.507017 :AD857DC0:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 19:00:38.507017 :AD857DC1:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 19:00:38.507018 :AD857DC2:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 19:00:38.507018 :AD857DC3:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 19:00:38.507602 :AD857DC4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 19:00:38.507656 :AD857DCA:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 19:00:38.516406 :AD857DDF:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 20:00:46.160916 :AD8A2AFF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 20:00:46.158 2025-07-04 20:00:46.160918 :AD8A2B00:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18088 pso_num=29 pso_serial#=132 2025-07-04 20:00:46.161062 :AD8A2B01:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=18088 osp_idx=27 osp_ver=13901 osp_pg=0 (spawn #352210) 2025-07-04 20:00:46.161063 :AD8A2B02:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 20:00:46.161064 :AD8A2B03:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=60 time=340022048 2025-07-04 20:00:46.161065 :AD8A2B04:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 20:00:46.161065 :AD8A2B05:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 20:00:46.161065 :AD8A2B06:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 20:00:46.161066 :AD8A2B07:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 20:00:46.161066 :AD8A2B08:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 20:00:46.161556 :AD8A2B09:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 20:00:46.161600 :AD8A2B0F:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 20:00:46.170310 :AD8A2B24:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 21:00:53.565595 :AD8ED613:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 21:00:53.563 2025-07-04 21:00:53.565596 :AD8ED614:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17240 pso_num=29 pso_serial#=133 2025-07-04 21:00:53.565723 :AD8ED615:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=17240 osp_idx=27 osp_ver=13902 osp_pg=0 (spawn #352349) 2025-07-04 21:00:53.565724 :AD8ED616:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 21:00:53.565725 :AD8ED617:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=61 time=343629439 2025-07-04 21:00:53.565725 :AD8ED618:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 21:00:53.565726 :AD8ED619:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 21:00:53.565726 :AD8ED61A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 21:00:53.565726 :AD8ED61B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 21:00:53.565727 :AD8ED61C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 21:00:53.566259 :AD8ED61D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 21:00:53.566301 :AD8ED624:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-07-04 21:00:53.591675 :AD8ED63D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-04 22:00:02.030267 :AD937001:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-04 22:00:02.024 2025-07-04 22:00:02.030269 :AD937002:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8008 pso_num=29 pso_serial#=134 2025-07-04 22:00:02.030393 :AD937003:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=8008 osp_idx=27 osp_ver=13903 osp_pg=0 (spawn #352486) 2025-07-04 22:00:02.030394 :AD937004:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-04 22:00:02.030394 :AD937005:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=62 time=347177923 2025-07-04 22:00:02.030395 :AD937006:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-04 22:00:02.030395 :AD937007:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-04 22:00:02.030396 :AD937008:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-04 22:00:02.030397 :AD937009:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-04 22:00:02.030397 :AD93700A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-04 22:00:02.031000 :AD937017:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.036195 :AD93703F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.036236 :AD937042:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-07-04 22:00:02.084249 :AD937365:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-04 22:00:02.084804 :AD937366:db_trace:kcc.c@13684:kccwbp(): [10021:29:233:1] 0115000000000000 0115000000000000 9e2f120000000000 2025-07-04 22:00:02.096266 :AD937367:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.096343 :AD937375:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 22:00:02.096352 :AD93737B:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-07-04 22:00:02.096356 :AD93737C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.096385 :AD93738A:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 22:00:02.097149 :AD937394:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 230371096) 2025-07-04 22:00:02.097154 :AD937395:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.097178 :AD9373A0:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 22:00:02.097185 :AD9373AD:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65565 1) 2025-07-04 22:00:02.097188 :AD9373AE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.097212 :AD9373BE:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 22:00:02.097218 :AD9373C6:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65565) 2025-07-04 22:00:02.097220 :AD9373C7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.097275 :AD9373E7:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 22:00:02.101900 :AD937757:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 22:00:02.101920 :AD937758:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-04 22:00:02.102874 :AD93775F:db_trace:kcc.c@13684:kccwbp(): [10021:29:233:1] 0115000000000000 0115000000000000 9f2f120000000000 2025-07-04 22:00:02.103354 :AD937760:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 230371096) 2025-07-04 22:00:02.103359 :AD937761:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.103384 :AD93776B:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-04 22:00:02.150475 :AD937781:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:jslv.c:9203 2025-07-04 22:00:02.152252 :AD93778A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.152314 :AD93778D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-04 22:00:02.152451 :AD93779A:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04 22:00:04.005245 :AD937CB5:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-04 22:00:04.005245*:AD937CBA:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002B53C718 estart=1751637603 eid=16783567 ctx=0x000000077FD6A000 cwh=0x000000002B530068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-04 22:00:04.005245*:AD937CBB:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002B53C718 curCtx=0x000000002B538938 pubTabIdxCnt=0 2025-07-04 22:00:04.005245*:AD937CBC:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002B53C718 2025-07-04 22:00:04.005245*:AD937CBD:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002B53C718 2025-07-04 22:00:04.005245*:AD937CBE:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002B53C718 curCtx=0x000000002B538938 xsc->flg4=65792 flags=2 2025-07-04 22:00:04.005245*:AD937CBF:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002B53C718 2025-07-04 22:00:04.007872 :AD937CC0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:04.007916 :AD937CC3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-07-04 22:00:04.025263 :AD937CC9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:04.025980 :AD937CD1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:04.030580 :AD937CD9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:04.030821 :AD937CE1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:jslv.c:9203 2025-07-04 22:00:04.032339 :AD937CE2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-04 22:00:04.032384 :AD937CE5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-04 22:00:04.032471 :AD937CF2:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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 29 (osid: 8008, J002)