Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250720220705\orcl_j001_13944_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:36157M/63366M, Ph+PgF:42078M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 13944, image: ORACLE.EXE (J001) *** 2025-07-20 22:07:05.337 *** SESSION ID:(201.393) 2025-07-20 22:07:05.337 *** 2025-07-20 22:07:05.337 Process diagnostic dump for ORACLE.EXE (J001), OS id=13944, pid: 25, proc_ser: 61, sid: 201, sess_ser: 393 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13944 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.190635 sec, exc=0.190635 sec, total=0.190635 sec wait times: max=0.500000 sec, heur=6.692834 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.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 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 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 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.000012 sec of elapsed time 3: 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.000011 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.510079 sec, exc=0.510079 sec, total=0.510079 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=6 seq_num=7 snap_id=1 wait times: snap=0.500006 sec, exc=0.500006 sec, total=0.500006 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=5 seq_num=6 snap_id=1 wait times: snap=0.499992 sec, exc=0.499992 sec, total=0.499992 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.500004 sec, exc=0.500004 sec, total=0.500004 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500002 sec, exc=0.500002 sec, total=0.500002 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time Sampled Session History of session 201 serial 393 --------------------------------------------------- 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:06:58 - 22:07:05] idle wait at each sample [session created at: 22:06:58] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-20 22:07:05.337 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 13944, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-20 21:57:45.472311 :B4BADBC7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 21:57:45.461 2025-07-20 21:57:45.472313 :B4BADBC8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16084 pso_num=25 pso_serial#=52 2025-07-20 21:57:45.472448 :B4BADBC9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16084 osp_idx=23 osp_ver=207479 osp_pg=0 (spawn #405827) 2025-07-20 21:57:45.472449 :B4BADBCA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 21:57:45.472449 :B4BADBCB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=52 time=1729441361 2025-07-20 21:57:45.472450 :B4BADBCC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 21:57:45.472450 :B4BADBCD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 21:57:45.472450 :B4BADBCE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 21:57:45.472451 :B4BADBCF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 21:57:45.472451 :B4BADBD0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 21:57:45.472980 :B4BADBD1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 21:58:15.560862 :B4BAE57D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 21:58:45.593910 :B4BAEF79:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 21:58:45.582 2025-07-20 21:58:45.593912 :B4BAEF7A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19400 pso_num=25 pso_serial#=53 2025-07-20 21:58:45.594032 :B4BAEF7B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19400 osp_idx=23 osp_ver=207480 osp_pg=0 (spawn #405829) 2025-07-20 21:58:45.594033 :B4BAEF7C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 21:58:45.594033 :B4BAEF7D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=53 time=1729501486 2025-07-20 21:58:45.594034 :B4BAEF7E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 21:58:45.594034 :B4BAEF7F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 21:58:45.594035 :B4BAEF80:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 21:58:45.594035 :B4BAEF81:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 21:58:45.594036 :B4BAEF82:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 21:58:45.594634 :B4BAEF83:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 21:59:15.619703 :B4BAF95E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 21:59:45.675114 :B4BB0347:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 21:59:45.663 2025-07-20 21:59:45.675116 :B4BB0348:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8564 pso_num=25 pso_serial#=54 2025-07-20 21:59:45.675247 :B4BB0349:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8564 osp_idx=23 osp_ver=207481 osp_pg=0 (spawn #405831) 2025-07-20 21:59:45.675248 :B4BB034A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 21:59:45.675248 :B4BB034B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=54 time=1729561564 2025-07-20 21:59:45.675249 :B4BB034C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 21:59:45.675249 :B4BB034D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 21:59:45.675249 :B4BB034E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 21:59:45.675250 :B4BB034F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 21:59:45.675250 :B4BB0350:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 21:59:45.675729 :B4BB0351:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:00:04.028666 :B4BB0942:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-20 22:00:34.115918 :B4BB1453:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 22:00:45.766701 :B4BB184B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 22:00:45.755 2025-07-20 22:00:45.766703 :B4BB184C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19124 pso_num=25 pso_serial#=55 2025-07-20 22:00:45.766833 :B4BB184D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19124 osp_idx=23 osp_ver=207482 osp_pg=0 (spawn #405835) 2025-07-20 22:00:45.766834 :B4BB184E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 22:00:45.766835 :B4BB184F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=55 time=1729621658 2025-07-20 22:00:45.766835 :B4BB1850:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 22:00:45.766835 :B4BB1851:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 22:00:45.766836 :B4BB1852:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 22:00:45.766836 :B4BB1853:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 22:00:45.766836 :B4BB1854:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 22:00:45.767351 :B4BB185D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:01:15.832392 :B4BB23E1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 22:01:45.865340 :B4BB2E0A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 22:01:45.855 2025-07-20 22:01:45.865343 :B4BB2E0B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7628 pso_num=25 pso_serial#=56 2025-07-20 22:01:45.865474 :B4BB2E0C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7628 osp_idx=23 osp_ver=207483 osp_pg=0 (spawn #405837) 2025-07-20 22:01:45.865475 :B4BB2E0D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 22:01:45.865475 :B4BB2E0E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=56 time=1729681751 2025-07-20 22:01:45.865476 :B4BB2E0F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 22:01:45.865476 :B4BB2E10:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 22:01:45.865477 :B4BB2E11:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 22:01:45.865477 :B4BB2E12:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 22:01:45.865477 :B4BB2E13:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 22:01:45.866022 :B4BB2E14:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:02:15.953647 :B4BB3838:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 22:02:45.972787 :B4BB420E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 22:02:45.961 2025-07-20 22:02:45.972789 :B4BB420F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11292 pso_num=25 pso_serial#=57 2025-07-20 22:02:45.972927 :B4BB4210:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11292 osp_idx=23 osp_ver=207484 osp_pg=0 (spawn #405840) 2025-07-20 22:02:45.972927 :B4BB4211:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 22:02:45.972927 :B4BB4212:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=57 time=1729741861 2025-07-20 22:02:45.972928 :B4BB4213:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 22:02:45.972928 :B4BB4214:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 22:02:45.972928 :B4BB4215:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 22:02:45.972929 :B4BB4216:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 22:02:45.972929 :B4BB4217:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 22:02:45.973402 :B4BB4218:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:03:16.083438 :B4BB4BBB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 22:03:46.083256 :B4BB5588:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 22:03:46.071 2025-07-20 22:03:46.083257 :B4BB5589:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16104 pso_num=25 pso_serial#=58 2025-07-20 22:03:46.083373 :B4BB558A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16104 osp_idx=23 osp_ver=207485 osp_pg=0 (spawn #405842) 2025-07-20 22:03:46.083374 :B4BB558B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 22:03:46.083374 :B4BB558C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=58 time=1729801970 2025-07-20 22:03:46.083374 :B4BB558D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 22:03:46.083375 :B4BB558E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 22:03:46.083375 :B4BB558F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 22:03:46.083376 :B4BB5590:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 22:03:46.083376 :B4BB5591:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 22:03:46.083856 :B4BB5592:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:04:16.180211 :B4BB5FB8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 22:04:46.150693 :B4BB69C3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 22:04:46.139 2025-07-20 22:04:46.150695 :B4BB69C4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8732 pso_num=25 pso_serial#=59 2025-07-20 22:04:46.150824 :B4BB69C5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8732 osp_idx=23 osp_ver=207486 osp_pg=0 (spawn #405845) 2025-07-20 22:04:46.150825 :B4BB69C6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 22:04:46.150825 :B4BB69C7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=59 time=1729862033 2025-07-20 22:04:46.150826 :B4BB69C8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 22:04:46.150826 :B4BB69C9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 22:04:46.150827 :B4BB69CA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 22:04:46.150827 :B4BB69CB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 22:04:46.150827 :B4BB69CC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 22:04:46.151307 :B4BB69CD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:05:16.245891 :B4BB7405:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 22:05:46.261511 :B4BB836F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 22:05:46.250 2025-07-20 22:05:46.261513 :B4BB8370:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19136 pso_num=25 pso_serial#=60 2025-07-20 22:05:46.261651 :B4BB8371:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19136 osp_idx=23 osp_ver=207487 osp_pg=0 (spawn #405847) 2025-07-20 22:05:46.261652 :B4BB8372:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 22:05:46.261652 :B4BB8373:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=60 time=1729922142 2025-07-20 22:05:46.261652 :B4BB8374:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 22:05:46.261653 :B4BB8375:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 22:05:46.261653 :B4BB8376:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 22:05:46.261655 :B4BB8377:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 22:05:46.261655 :B4BB8378:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 22:05:46.262132 :B4BB8379:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:06:16.354498 :B4BB8EB9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-20 22:06:46.363422 :B4BB9850:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-20 22:06:46.352 2025-07-20 22:06:46.363424 :B4BB9851:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13944 pso_num=25 pso_serial#=61 2025-07-20 22:06:46.363564 :B4BB9852:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13944 osp_idx=23 osp_ver=207488 osp_pg=0 (spawn #405849) 2025-07-20 22:06:46.363565 :B4BB9853:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 22:06:46.363565 :B4BB9854:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=61 time=1729982251 2025-07-20 22:06:46.363566 :B4BB9855:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 22:06:46.363566 :B4BB9856:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 22:06:46.363567 :B4BB9857:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 22:06:46.363567 :B4BB9858:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 22:06:46.363567 :B4BB9859:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 22:06:46.364063 :B4BB985A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-20 22:06:56.858517 :B4BB9D2D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-20 22:06:56.962780 :B4BBA081:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-20 22:06:56.962780*:B4BBA08F:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEC718 estart=1753020416 eid=16784562 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-20 22:06:56.962780*:B4BBA090:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 pubTabIdxCnt=0 2025-07-20 22:06:56.962780*:B4BBA091:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEC718 2025-07-20 22:06:56.962780*:B4BBA092:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEC718 2025-07-20 22:06:56.962780*:B4BBA093:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 xsc->flg4=65792 flags=2 2025-07-20 22:06:56.962780*:B4BBA094:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEC718 2025-07-20 22:06:56.968034 :B4BBA09F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:56.968072 :B4BBA0A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-20 22:06:56.972452 :B4BBA0B2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:57.079603 :B4BBA0BA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:57.210552 :B4BBA0C2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:57.343966 :B4BBA0CA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.465677 :B4BBA151:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.468532 :B4BBA159:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.469535 :B4BBA161:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.471292 :B4BBA169:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.472920 :B4BBA171:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.475485 :B4BBA179:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.477081 :B4BBA181:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.493982 :B4BBA189:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.494622 :B4BBA191:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.495135 :B4BBA199:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.495627 :B4BBA1A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.498410 :B4BBA1A9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.499314 :B4BBA1B1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.500047 :B4BBA1B2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.500896 :B4BBA1B3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.501329 :B4BBA1B4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.501335 :B4BBA1B5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.501938 :B4BBA1B6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.502436 :B4BBA1B7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.502754 :B4BBA1B8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.503819 :B4BBA1B9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.537783 :B4BBA1BA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.537834 :B4BBA1BD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.538753 :B4BBA1C3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.539681 :B4BBA1CB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.540116 :B4BBA1CC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.560877 :B4BBA1D4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.560930 :B4BBA1D7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.561830 :B4BBA1DD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.573920 :B4BBA1E5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.574470 :B4BBA1E6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.592800 :B4BBA1EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.592851 :B4BBA1F1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.593776 :B4BBA1F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.594678 :B4BBA1FF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.595161 :B4BBA200:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.612838 :B4BBA208:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.612890 :B4BBA20B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.613897 :B4BBA211:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.614801 :B4BBA219:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-20 22:06:58.615250 :B4BBA21A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.637131 :B4BBA222:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.637184 :B4BBA225:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-20 22:06:58.638094 :B4BBA22B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.638575 :B4BBA233:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.638936 :B4BBA23B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.639120 :B4BBA243:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.639256 :B4BBA24B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.639402 :B4BBA253:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-20 22:06:58.643519 :B4BBA254:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.643599 :B4BBA257:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-20 22:06:58.643681 :B4BBA264:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 13944, J001)