Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250601220822\orcl_j001_14652_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:37168M/63366M, Ph+PgF:44063M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 14652, image: ORACLE.EXE (J001) *** 2025-06-01 22:08:22.196 *** SESSION ID:(209.16783) 2025-06-01 22:08:22.196 *** 2025-06-01 22:08:22.196 Process diagnostic dump for ORACLE.EXE (J001), OS id=14652, pid: 26, proc_ser: 24, sid: 209, sess_ser: 16783 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 14652 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.464917 sec, exc=0.464917 sec, total=0.464917 sec wait times: max=0.500000 sec, heur=5.977849 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.000007 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.500014 sec, exc=0.500014 sec, total=0.500014 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=9 seq_num=10 snap_id=1 wait times: snap=0.499995 sec, exc=0.499995 sec, total=0.499995 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499976 sec, exc=0.499976 sec, total=0.499976 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000016 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.504615 sec, exc=0.504615 sec, total=0.504615 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499983 sec, exc=0.499983 sec, total=0.499983 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.500011 sec, exc=0.500011 sec, total=0.500011 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 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.000009 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 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=1 seq_num=2 snap_id=1 wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time Sampled Session History of session 209 serial 16783 --------------------------------------------------- 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, 22:08:16 - 22:08:22] idle wait at each sample [session created at: 22:08:16] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-01 22:08:22.196 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 14652, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-01 21:59:00.239163 :9F0B7A8E:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14984 pso_num=26 pso_serial#=15 2025-06-01 21:59:00.239287 :9F0B7A8F:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14984 osp_idx=24 osp_ver=367470 osp_pg=0 (spawn #242486) 2025-06-01 21:59:00.239287 :9F0B7A90:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 21:59:00.239287 :9F0B7A91:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=97 time=1790898875 2025-06-01 21:59:00.239288 :9F0B7A92:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 21:59:00.239288 :9F0B7A93:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 21:59:00.239289 :9F0B7A94:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 21:59:00.239289 :9F0B7A95:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 21:59:00.239289 :9F0B7A96:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 21:59:00.239802 :9F0B7A97: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-06-01 21:59:30.325331 :9F0B8459:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:00:00.319659 :9F0B8DFC:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:00:00.308 2025-06-01 22:00:00.319662 :9F0B8DFD:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14740 pso_num=26 pso_serial#=16 2025-06-01 22:00:00.319794 :9F0B8DFE:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14740 osp_idx=24 osp_ver=367471 osp_pg=0 (spawn #242488) 2025-06-01 22:00:00.319795 :9F0B8DFF:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:00:00.319795 :9F0B8E00:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=98 time=1790958954 2025-06-01 22:00:00.319796 :9F0B8E01:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:00:00.319796 :9F0B8E02:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:00:00.319796 :9F0B8E03:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:00:00.319797 :9F0B8E04:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:00:00.319797 :9F0B8E05:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:00:00.320304 :9F0B8E06: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-06-01 22:00:04.011523 :9F0B92AC:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-01 22:00:34.102755 :9F0B9D79:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:01:00.393291 :9F0BA5D8:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:01:00.382 2025-06-01 22:01:00.393293 :9F0BA5D9:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10824 pso_num=26 pso_serial#=17 2025-06-01 22:01:00.393419 :9F0BA5DA:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10824 osp_idx=24 osp_ver=367472 osp_pg=0 (spawn #242492) 2025-06-01 22:01:00.393420 :9F0BA5DB:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:01:00.393420 :9F0BA5DC:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=99 time=1791019032 2025-06-01 22:01:00.393421 :9F0BA5DD:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:01:00.393422 :9F0BA5DE:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:01:00.393423 :9F0BA5DF:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:01:00.393423 :9F0BA5E0:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:01:00.393423 :9F0BA5E1:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:01:00.393915 :9F0BA5EA: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-06-01 22:01:30.445903 :9F0BAFA7:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:01:35.456396 :9F0BB1AE:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:01:35.445 2025-06-01 22:01:35.456398 :9F0BB1AF:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13792 pso_num=26 pso_serial#=18 2025-06-01 22:01:35.456532 :9F0BB1B0:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13792 osp_idx=24 osp_ver=367473 osp_pg=0 (spawn #242494) 2025-06-01 22:01:35.456533 :9F0BB1B1:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:01:35.456534 :9F0BB1B2:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=100 time=1791054094 2025-06-01 22:01:35.456534 :9F0BB1B3:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:01:35.456534 :9F0BB1B4:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:01:35.456535 :9F0BB1B5:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:01:35.456535 :9F0BB1B6:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:01:35.456535 :9F0BB1B7:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:01:35.457012 :9F0BB1B8: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-06-01 22:02:00.487578 :9F0BB923:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-01 22:02:30.578163 :9F0BC2E8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:03:00.625229 :9F0BCCE9:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:03:00.613 2025-06-01 22:03:00.625231 :9F0BCCEA:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10856 pso_num=26 pso_serial#=19 2025-06-01 22:03:00.625349 :9F0BCCEB:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10856 osp_idx=24 osp_ver=367474 osp_pg=0 (spawn #242496) 2025-06-01 22:03:00.625350 :9F0BCCEC:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:03:00.625351 :9F0BCCED:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=101 time=1791139266 2025-06-01 22:03:00.625351 :9F0BCCEE:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:03:00.625352 :9F0BCCEF:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:03:00.625352 :9F0BCCF0:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:03:00.625353 :9F0BCCF1:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:03:00.625353 :9F0BCCF2:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:03:00.625839 :9F0BCCF3: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-06-01 22:03:30.692407 :9F0BD731:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:04:00.739310 :9F0BE0FD:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:04:00.729 2025-06-01 22:04:00.739312 :9F0BE0FE:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12644 pso_num=26 pso_serial#=20 2025-06-01 22:04:00.739449 :9F0BE0FF:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12644 osp_idx=24 osp_ver=367475 osp_pg=0 (spawn #242499) 2025-06-01 22:04:00.739449 :9F0BE100:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:04:00.739450 :9F0BE101:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=102 time=1791199375 2025-06-01 22:04:00.739450 :9F0BE102:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:04:00.739450 :9F0BE103:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:04:00.739451 :9F0BE104:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:04:00.739451 :9F0BE105:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:04:00.739451 :9F0BE106:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:04:00.739914 :9F0BE107: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-06-01 22:04:30.798324 :9F0BEA88:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:05:00.832249 :9F0BF437:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:05:00.821 2025-06-01 22:05:00.832251 :9F0BF438:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10360 pso_num=26 pso_serial#=21 2025-06-01 22:05:00.832385 :9F0BF439:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10360 osp_idx=24 osp_ver=367476 osp_pg=0 (spawn #242501) 2025-06-01 22:05:00.832385 :9F0BF43A:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:05:00.832386 :9F0BF43B:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=103 time=1791259469 2025-06-01 22:05:00.832386 :9F0BF43C:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:05:00.832386 :9F0BF43D:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:05:00.832386 :9F0BF43E:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:05:00.832387 :9F0BF43F:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:05:00.832387 :9F0BF440:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:05:00.832862 :9F0BF441: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-06-01 22:05:30.875665 :9F0C04BB:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:06:00.930170 :9F0C0E86:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:06:00.918 2025-06-01 22:06:00.930172 :9F0C0E87:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11988 pso_num=26 pso_serial#=22 2025-06-01 22:06:00.930310 :9F0C0E88:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11988 osp_idx=24 osp_ver=367477 osp_pg=0 (spawn #242503) 2025-06-01 22:06:00.930311 :9F0C0E89:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:06:00.930312 :9F0C0E8A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=104 time=1791319563 2025-06-01 22:06:00.930312 :9F0C0E8B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:06:00.930312 :9F0C0E8C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:06:00.930313 :9F0C0E8D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:06:00.930313 :9F0C0E8E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:06:00.930313 :9F0C0E8F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:06:00.930789 :9F0C0E90: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-06-01 22:06:31.026310 :9F0C184B:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:07:01.060760 :9F0C21EF:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:07:01.048 2025-06-01 22:07:01.060763 :9F0C21F0:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=15192 pso_num=26 pso_serial#=23 2025-06-01 22:07:01.060887 :9F0C21F1:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=15192 osp_idx=24 osp_ver=367478 osp_pg=0 (spawn #242506) 2025-06-01 22:07:01.060888 :9F0C21F2:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:07:01.060888 :9F0C21F3:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=105 time=1791379704 2025-06-01 22:07:01.060888 :9F0C21F4:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:07:01.060889 :9F0C21F5:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:07:01.060889 :9F0C21F6:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:07:01.060890 :9F0C21F7:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:07:01.060890 :9F0C21F8:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:07:01.061394 :9F0C21F9: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-06-01 22:07:31.152020 :9F0C2B6E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-01 22:08:01.173358 :9F0C34E2:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-01 22:08:01.162 2025-06-01 22:08:01.173360 :9F0C34E3:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14652 pso_num=26 pso_serial#=24 2025-06-01 22:08:01.173491 :9F0C34E4:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14652 osp_idx=24 osp_ver=367479 osp_pg=0 (spawn #242508) 2025-06-01 22:08:01.173492 :9F0C34E5:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 22:08:01.173492 :9F0C34E6:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=106 time=1791439813 2025-06-01 22:08:01.173493 :9F0C34E7:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 22:08:01.173493 :9F0C34E8:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 22:08:01.173493 :9F0C34E9:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 22:08:01.173494 :9F0C34EA:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 22:08:01.173494 :9F0C34EB:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 22:08:01.174050 :9F0C34EC: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-06-01 22:08:14.401488 :9F0C3B3B:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-01 22:08:14.499710 :9F0C3E6C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-01 22:08:14.499710*:9F0C3E7A:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000271EC718 estart=1748786894 eid=16781550 ctx=0x000000077FD6A000 cwh=0x00000000271E0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-06-01 22:08:14.499710*:9F0C3E7B:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000271EC718 curCtx=0x00000000271E8938 pubTabIdxCnt=0 2025-06-01 22:08:14.499710*:9F0C3E7C:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000271EC718 2025-06-01 22:08:14.499710*:9F0C3E7D:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000271EC718 2025-06-01 22:08:14.499710*:9F0C3E80:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000271EC718 curCtx=0x00000000271E8938 xsc->flg4=65792 flags=2 2025-06-01 22:08:14.499710*:9F0C3E83:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000271EC718 2025-06-01 22:08:14.505079 :9F0C3E8A: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-06-01 22:08:14.505126 :9F0C3E8D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:jslv.c:9203 2025-06-01 22:08:14.509276 :9F0C3E9D: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-06-01 22:08:14.616044 :9F0C3EA5: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-06-01 22:08:14.748271 :9F0C3EAD: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-06-01 22:08:14.886265 :9F0C3EB5: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-06-01 22:08:16.030796 :9F0C3ECA: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-06-01 22:08:16.031792 :9F0C3ED2: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-06-01 22:08:16.033589 :9F0C3EDA: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-06-01 22:08:16.035224 :9F0C3EE2: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-06-01 22:08:16.037769 :9F0C3EEA: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-06-01 22:08:16.039336 :9F0C3EF2: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-06-01 22:08:16.057313 :9F0C3EFA: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-06-01 22:08:16.058095 :9F0C3F02: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-06-01 22:08:16.058690 :9F0C3F0A: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-06-01 22:08:16.059218 :9F0C3F12: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-06-01 22:08:16.062350 :9F0C3F1A: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-06-01 22:08:16.063351 :9F0C3F22:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.064317 :9F0C3F23:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.065188 :9F0C3F24:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.065661 :9F0C3F25:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.065668 :9F0C3F26:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.066361 :9F0C3F27:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.066904 :9F0C3F28:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.067288 :9F0C3F29:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.068525 :9F0C3F2A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.110606 :9F0C3F2B: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-06-01 22:08:16.110656 :9F0C3F2E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.111659 :9F0C3F34: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-06-01 22:08:16.112585 :9F0C3F3C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.113033 :9F0C3F3D: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-06-01 22:08:16.133708 :9F0C3F45: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-06-01 22:08:16.133761 :9F0C3F48:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.134738 :9F0C3F4E: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-06-01 22:08:16.135637 :9F0C3F56:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.136103 :9F0C3F57: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-06-01 22:08:16.161307 :9F0C3F67: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-06-01 22:08:16.161359 :9F0C3F6A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.162237 :9F0C3F70: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-06-01 22:08:16.173639 :9F0C3F85:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.174342 :9F0C3F86: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-06-01 22:08:16.195161 :9F0C3FC5: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-06-01 22:08:16.195213 :9F0C3FC8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.196133 :9F0C3FCE: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-06-01 22:08:16.197698 :9F0C3FD6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-06-01 22:08:16.198433 :9F0C3FD7: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-06-01 22:08:16.220762 :9F0C3FDF: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-06-01 22:08:16.220812 :9F0C3FE2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-06-01 22:08:16.221665 :9F0C3FE8: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-06-01 22:08:16.222120 :9F0C3FF0: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-06-01 22:08:16.222460 :9F0C3FF8: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-06-01 22:08:16.222683 :9F0C4000: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-06-01 22:08:16.222846 :9F0C4008: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-06-01 22:08:16.223011 :9F0C4010:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:jslv.c:9203 2025-06-01 22:08:16.226949 :9F0C4011: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-06-01 22:08:16.227030 :9F0C4014: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-06-01 22:08:16.227115 :9F0C4021: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: 14652, J001)