Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250509220008\orcl_j000_12192_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:37482M/63366M, Ph+PgF:44850M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 12192, image: ORACLE.EXE (J000) *** 2025-05-09 22:00:08.728 *** SESSION ID:(201.52255) 2025-05-09 22:00:08.728 *** 2025-05-09 22:00:08.728 Process diagnostic dump for ORACLE.EXE (J000), OS id=12192, pid: 25, proc_ser: 113, sid: 201, sess_ser: 52255 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12192 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.193656 sec, exc=0.193656 sec, total=0.193656 sec wait times: max=0.500000 sec, heur=4.708500 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=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.000011 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.500008 sec, exc=0.500008 sec, total=0.500008 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.499971 sec, exc=0.499971 sec, total=0.499971 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.510129 sec, exc=0.510129 sec, total=0.510129 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 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.000007 sec of elapsed time 5: 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.000008 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 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.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.510103 sec, exc=0.510103 sec, total=0.510103 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.494566 sec, exc=0.494566 sec, total=0.494566 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 201 serial 52255 --------------------------------------------------- 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 --------------------------------------------------- [5 samples, 22:00:04 - 22:00:08] 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-05-09 22:00:08.728 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 12192, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-09 21:51:28.720060 :94F299CD:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:51:28.720060 :94F299CE:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=115 time=4098265875 2025-05-09 21:51:28.720061 :94F299CF:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:51:28.720061 :94F299D0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:51:28.720062 :94F299D1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:51:28.720062 :94F299D2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:51:28.720063 :94F299D3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:51:28.720536 :94F299D4: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-05-09 21:51:58.792369 :94F2A354:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:52:28.806107 :94F2ACE4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:52:28.795 2025-05-09 21:52:28.806109 :94F2ACE5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4660 pso_num=25 pso_serial#=104 2025-05-09 21:52:28.806243 :94F2ACE6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4660 osp_idx=23 osp_ver=82468 osp_pg=0 (spawn #165645) 2025-05-09 21:52:28.806243 :94F2ACE7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:52:28.806244 :94F2ACE8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=116 time=4098325968 2025-05-09 21:52:28.806244 :94F2ACE9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:52:28.806244 :94F2ACEA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:52:28.806245 :94F2ACEB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:52:28.806245 :94F2ACEC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:52:28.806245 :94F2ACED:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:52:28.806713 :94F2ACEE: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-05-09 21:52:58.922826 :94F2B718:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:53:28.914080 :94F2C023:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:53:28.902 2025-05-09 21:53:28.914082 :94F2C024:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12272 pso_num=25 pso_serial#=105 2025-05-09 21:53:28.914213 :94F2C025:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12272 osp_idx=23 osp_ver=82469 osp_pg=0 (spawn #165647) 2025-05-09 21:53:28.914214 :94F2C026:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:53:28.914215 :94F2C027:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=117 time=4098386078 2025-05-09 21:53:28.914215 :94F2C028:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:53:28.914215 :94F2C029:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:53:28.914216 :94F2C02A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:53:28.914216 :94F2C02B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:53:28.914217 :94F2C02C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:53:28.914706 :94F2C02D: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-05-09 21:53:59.002300 :94F2C9EC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:54:29.013635 :94F2D3A7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:54:29.002 2025-05-09 21:54:29.013637 :94F2D3A8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13148 pso_num=25 pso_serial#=106 2025-05-09 21:54:29.013772 :94F2D3A9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13148 osp_idx=23 osp_ver=82470 osp_pg=0 (spawn #165649) 2025-05-09 21:54:29.013773 :94F2D3AA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:54:29.013773 :94F2D3AB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=118 time=4098446171 2025-05-09 21:54:29.013774 :94F2D3AC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:54:29.013774 :94F2D3AD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:54:29.013775 :94F2D3AE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:54:29.013775 :94F2D3AF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:54:29.013775 :94F2D3B0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:54:29.014283 :94F2D3B1: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-05-09 21:54:59.074404 :94F2DD7C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:55:29.093759 :94F2E722:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:55:29.082 2025-05-09 21:55:29.093762 :94F2E723:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12028 pso_num=25 pso_serial#=107 2025-05-09 21:55:29.093896 :94F2E724:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12028 osp_idx=23 osp_ver=82471 osp_pg=0 (spawn #165651) 2025-05-09 21:55:29.093896 :94F2E725:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:55:29.093897 :94F2E726:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=119 time=4098506250 2025-05-09 21:55:29.093897 :94F2E727:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:55:29.093897 :94F2E728:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:55:29.093898 :94F2E729:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:55:29.093898 :94F2E72A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:55:29.093898 :94F2E72B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:55:29.094405 :94F2E72C: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-05-09 21:55:59.185138 :94F2F11C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:56:29.173113 :94F2FAA7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:56:29.162 2025-05-09 21:56:29.173115 :94F2FAA8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11796 pso_num=25 pso_serial#=108 2025-05-09 21:56:29.173251 :94F2FAA9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11796 osp_idx=23 osp_ver=82472 osp_pg=0 (spawn #165653) 2025-05-09 21:56:29.173252 :94F2FAAA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:56:29.173252 :94F2FAAB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=120 time=4098566328 2025-05-09 21:56:29.173253 :94F2FAAC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:56:29.173253 :94F2FAAD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:56:29.173254 :94F2FAAE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:56:29.173254 :94F2FAAF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:56:29.173254 :94F2FAB0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:56:29.173740 :94F2FAB1: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-05-09 21:56:59.277703 :94F30429:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:57:29.267119 :94F30D79:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:57:29.255 2025-05-09 21:57:29.267121 :94F30D7A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12908 pso_num=25 pso_serial#=109 2025-05-09 21:57:29.267258 :94F30D7B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12908 osp_idx=23 osp_ver=82473 osp_pg=0 (spawn #165655) 2025-05-09 21:57:29.267259 :94F30D7C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:57:29.267259 :94F30D7D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=121 time=4098626421 2025-05-09 21:57:29.267260 :94F30D7E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:57:29.267260 :94F30D7F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:57:29.267261 :94F30D80:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:57:29.267261 :94F30D81:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:57:29.267262 :94F30D82:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:57:29.267732 :94F30D83: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-05-09 21:57:59.368149 :94F31787:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:58:24.344677 :94F31F32:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:58:24.333 2025-05-09 21:58:24.344679 :94F31F33:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12964 pso_num=25 pso_serial#=110 2025-05-09 21:58:24.344814 :94F31F34:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12964 osp_idx=23 osp_ver=82474 osp_pg=0 (spawn #165657) 2025-05-09 21:58:24.344815 :94F31F35:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:58:24.344815 :94F31F36:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=122 time=4098681500 2025-05-09 21:58:24.344816 :94F31F37:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:58:24.344816 :94F31F38:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:58:24.344817 :94F31F39:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:58:24.344817 :94F31F3A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:58:24.344817 :94F31F3B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:58:24.345295 :94F31F3C: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-05-09 21:58:29.350061 :94F320F7: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-05-09 21:58:59.441674 :94F32AA4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 21:59:29.463045 :94F3341E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 21:59:29.452 2025-05-09 21:59:29.463048 :94F3341F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10224 pso_num=25 pso_serial#=111 2025-05-09 21:59:29.463209 :94F33420:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10224 osp_idx=23 osp_ver=82475 osp_pg=0 (spawn #165660) 2025-05-09 21:59:29.463210 :94F33421:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:59:29.463210 :94F33422:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=123 time=4098746625 2025-05-09 21:59:29.463211 :94F33423:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:59:29.463211 :94F33424:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:59:29.463211 :94F33425:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:59:29.463212 :94F33426:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:59:29.463212 :94F33427:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:59:29.463706 :94F33428: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-05-09 21:59:59.536802 :94F33D84:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 22:00:00.045632 :94F33E42:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 22:00:00.037 2025-05-09 22:00:00.045633 :94F33E43:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13048 pso_num=25 pso_serial#=112 2025-05-09 22:00:00.045777 :94F33E44:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13048 osp_idx=23 osp_ver=82476 osp_pg=0 (spawn #165662) 2025-05-09 22:00:00.045778 :94F33E45:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 22:00:00.045778 :94F33E46:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=124 time=4098777203 2025-05-09 22:00:00.045779 :94F33E47:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 22:00:00.045779 :94F33E48:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 22:00:00.045779 :94F33E49:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 22:00:00.045780 :94F33E4A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 22:00:00.045780 :94F33E4B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 22:00:00.046282 :94F33E4C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-09 22:00:00.046326 :94F33E53:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-09 22:00:00.046401 :94F33E66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-09 22:00:00.050243 :94F33E75: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-05-09 22:00:00.051397 :94F33E7D: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-05-09 22:00:00.051423 :94F33E80:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-09 22:00:00.051462 :94F33E8B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-09 22:00:00.053313 :94F33E96: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-05-09 22:00:00.053339 :94F33E99:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-09 22:00:00.053387 :94F33EA4:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-09 22:00:00.053909 :94F33EAF: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-05-09 22:00:00.056360 :94F33EB7: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-05-09 22:00:00.061629 :94F33EBF: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-05-09 22:00:00.067081 :94F33EC7: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-05-09 22:00:00.068719 :94F33EDB: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-05-09 22:00:00.069712 :94F33EE3: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-05-09 22:00:00.072456 :94F33EEB: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-05-09 22:00:00.073774 :94F33EF3: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-05-09 22:00:00.076809 :94F33EFB: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-05-09 22:00:00.080202 :94F33F03:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-09 22:00:00.080592 :94F33F12: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-05-09 22:00:00.080639 :94F33F15:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-09 22:00:00.080653 :94F33F16:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-09 22:00:00.082625 :94F33F1C: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-05-09 22:00:00.082673 :94F33F1F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-09 22:00:00.082685 :94F33F20:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-09 22:00:00.084668 :94F33F26: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-05-09 22:00:00.084716 :94F33F29:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-09 22:00:00.084728 :94F33F2A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-09 22:00:00.084908 :94F33F30: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-05-09 22:00:00.084923 :94F33F33:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-09 22:00:00.084961 :94F33F3E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-09 22:00:00.086468 :94F33F49:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-09 22:00:02.052252 :94F33FCF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-09 22:00:02.047 2025-05-09 22:00:02.052254 :94F33FD0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12192 pso_num=25 pso_serial#=113 2025-05-09 22:00:02.052389 :94F33FD1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12192 osp_idx=23 osp_ver=82477 osp_pg=0 (spawn #165663) 2025-05-09 22:00:02.052390 :94F33FD2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 22:00:02.052390 :94F33FD3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=125 time=4098779218 2025-05-09 22:00:02.052390 :94F33FD4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 22:00:02.052391 :94F33FD5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 22:00:02.052391 :94F33FD6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 22:00:02.052392 :94F33FD7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 22:00:02.052392 :94F33FD8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 22:00:02.052871 :94F33FD9: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-05-09 22:00:02.058146 :94F33FFB: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-05-09 22:00:02.058190 :94F34007:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-09 22:00:02.069279 :94F34067: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-05-09 22:00:02.074501 :94F3408B: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-05-09 22:00:02.075278 :94F340A8: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-05-09 22:00:02.080912 :94F34210:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-09 22:00:02.081053 :94F3421F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-09 22:00:02.081961 :94F34231: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-05-09 22:00:02.082155 :94F34239:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-09 22:00:02.083655 :94F3423A: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-05-09 22:00:02.083710 :94F3423D: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-05-09 22:00:02.083803 :94F3424A: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 2025-05-09 22:00:02.187755 :94F3433F: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-05-09 22:00:02.189913 :94F34346: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-05-09 22:00:02.189952 :94F34349:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-09 22:00:02.192462 :94F3434F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-09 22:00:02.195791 :94F34350: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-05-09 22:00:02.195870 :94F34353: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-05-09 22:00:02.195953 :94F34360: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 2025-05-09 22:00:04.010430 :94F34759: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-05-09 22:00:04.012537 :94F3475B: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-05-09 22:00:04.012575 :94F3475E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-09 22:00:04.021316 :94F34764: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-05-09 22:00:04.021977 :94F3476C: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-05-09 22:00:04.022653 :94F34774: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-05-09 22:00:04.022843 :94F3477C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-09 22:00:04.024313 :94F3477D: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-05-09 22:00:04.024355 :94F34780: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-05-09 22:00:04.024420 :94F3478D: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: 12192, J000)