Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250529220010\orcl_j002_1880_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:37269M/63366M, Ph+PgF:44190M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 1880, image: ORACLE.EXE (J002) *** 2025-05-29 22:00:10.638 *** SESSION ID:(225.49667) 2025-05-29 22:00:10.638 *** 2025-05-29 22:00:10.638 Process diagnostic dump for ORACLE.EXE (J002), OS id=1880, pid: 28, proc_ser: 185, sid: 225, sess_ser: 49667 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 1880 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=0.332385 sec, exc=0.332385 sec, total=0.332385 sec wait times: max=0.500000 sec, heur=8.966170 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.000003 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=0.500010 sec, exc=0.500010 sec, total=0.500010 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000003 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=16 seq_num=17 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.000007 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.500013 sec, exc=0.500013 sec, total=0.500013 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 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.000004 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.510096 sec, exc=0.510096 sec, total=0.510096 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.510097 sec, exc=0.510097 sec, total=0.510097 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.500013 sec, exc=0.500013 sec, total=0.500013 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 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.000003 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 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.000004 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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.000008 sec of elapsed time Sampled Session History of session 225 serial 49667 --------------------------------------------------- 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 --------------------------------------------------- [9 samples, 22:00:01 - 22:00:10] idle wait at each sample [session created at: 22:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-29 22:00:10.638 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 1880, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-29 18:58:09.496865 :9DAC7A67:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 18:58:09.496866 :9DAC7A68:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=232 time=1520850266 2025-05-29 18:58:09.496866 :9DAC7A69:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 18:58:09.496866 :9DAC7A6A:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 18:58:09.496867 :9DAC7A6B:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 18:58:09.496867 :9DAC7A6C:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 18:58:09.496867 :9DAC7A6D:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 18:58:09.497309 :9DAC7A6E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 18:58:09.497347 :9DAC7A75:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 18:58:09.501814 :9DAC7A9D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 18:58:09.501876 :9DAC7A9E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 18:58:09.502197 :9DAC7A9F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 18:58:09.502217 :9DAC7AA0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 18:58:09.502486 :9DAC7AA1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 18:58:09.502504 :9DAC7AA2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 18:58:09.502770 :9DAC7AA3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 18:58:09.502788 :9DAC7AA4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 18:58:09.503049 :9DAC7AA5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 18:58:09.503066 :9DAC7AA6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 18:58:09.503320 :9DAC7AA7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 18:58:09.503337 :9DAC7AA8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 18:58:09.506277 :9DAC7AA9:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-29 19:00:10.801122 :9DACA3F3:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-29 19:00:10.798 2025-05-29 19:00:10.801123 :9DACA3F4:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13828 pso_num=28 pso_serial#=179 2025-05-29 19:00:10.801259 :9DACA3F5:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=13828 osp_idx=26 osp_ver=155777 osp_pg=0 (spawn #232057) 2025-05-29 19:00:10.801259 :9DACA3F6:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 19:00:10.801260 :9DACA3F7:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=233 time=1520971563 2025-05-29 19:00:10.801260 :9DACA3F8:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 19:00:10.801260 :9DACA3F9:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 19:00:10.801260 :9DACA3FA:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 19:00:10.801261 :9DACA3FB:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 19:00:10.801261 :9DACA3FC:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 19:00:10.801710 :9DACA3FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.801742 :9DACA406:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 19:00:10.809386 :9DACA411:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.810385 :9DACA419:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.810961 :9DACA421:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.811484 :9DACA429:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.812001 :9DACA431:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.814410 :9DACA439:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.815779 :9DACA441:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.859570 :9DACA449:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.860387 :9DACA451:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.860618 :9DACA459:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.860857 :9DACA461:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 19:00:10.862338 :9DACA469:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-29 19:28:13.505605 :9DAEDD49:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-29 19:28:13.492 2025-05-29 19:28:13.505607 :9DAEDD4A:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=11956 pso_num=28 pso_serial#=180 2025-05-29 19:28:13.505739 :9DAEDD4B:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=11956 osp_idx=26 osp_ver=155778 osp_pg=0 (spawn #232122) 2025-05-29 19:28:13.505740 :9DAEDD4C:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 19:28:13.505740 :9DAEDD4D:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=234 time=1522654266 2025-05-29 19:28:13.505741 :9DAEDD4E:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 19:28:13.505741 :9DAEDD4F:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 19:28:13.505741 :9DAEDD50:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 19:28:13.505742 :9DAEDD51:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 19:28:13.505742 :9DAEDD52:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 19:28:13.506287 :9DAEDD53:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 19:28:13.506326 :9DAEDD59:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 19:28:13.510356 :9DAEDD72:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:28:13.510435 :9DAEDD73:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:28:13.510719 :9DAEDD74:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:28:13.510738 :9DAEDD75:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:28:13.510962 :9DAEDD76:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:28:13.510977 :9DAEDD77:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:28:13.511188 :9DAEDD78:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:28:13.511201 :9DAEDD79:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:28:13.511411 :9DAEDD7A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:28:13.511423 :9DAEDD7B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:28:13.511626 :9DAEDD7C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:28:13.511638 :9DAEDD7D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:28:13.513980 :9DAEDD7E:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-29 19:58:17.513757 :9DB12D9F:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-29 19:58:17.500 2025-05-29 19:58:17.513759 :9DB12DA0:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=4804 pso_num=28 pso_serial#=181 2025-05-29 19:58:17.513904 :9DB12DA1:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=4804 osp_idx=26 osp_ver=155779 osp_pg=0 (spawn #232190) 2025-05-29 19:58:17.513905 :9DB12DA2:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 19:58:17.513905 :9DB12DA3:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=235 time=1524458282 2025-05-29 19:58:17.513906 :9DB12DA4:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 19:58:17.513906 :9DB12DA5:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 19:58:17.513907 :9DB12DA6:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 19:58:17.513907 :9DB12DA7:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 19:58:17.513907 :9DB12DA8:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 19:58:17.514452 :9DB12DA9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 19:58:17.514499 :9DB12DB0:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 19:58:17.518479 :9DB12DD8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:58:17.518522 :9DB12DD9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:58:17.518858 :9DB12DDA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:58:17.518874 :9DB12DDB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:58:17.519083 :9DB12DDC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:58:17.519097 :9DB12DDD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:58:17.519304 :9DB12DDE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:58:17.519317 :9DB12DDF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:58:17.519533 :9DB12DE0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:58:17.519545 :9DB12DE1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:58:17.519753 :9DB12DE2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 19:58:17.519765 :9DB12DE3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 19:58:17.522056 :9DB12DE4:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-29 20:00:18.264208 :9DB15566:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-29 20:00:18.255 2025-05-29 20:00:18.264211 :9DB15567:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=14020 pso_num=28 pso_serial#=182 2025-05-29 20:00:18.264343 :9DB15568:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=14020 (legacy spawn) 2025-05-29 20:00:18.270864 :9DB15569:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:18.271224 :9DB15572:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 20:00:18.272021 :9DB15573:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-29 20:00:19.146324 :9DB155D3:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-29 20:00:19.146 2025-05-29 20:00:19.146326 :9DB155D4:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=10836 pso_num=28 pso_serial#=183 2025-05-29 20:00:19.146459 :9DB155D5:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=10836 osp_idx=26 osp_ver=155781 osp_pg=0 (spawn #232196) 2025-05-29 20:00:19.146460 :9DB155D6:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 20:00:19.146460 :9DB155D7:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=236 time=1524579907 2025-05-29 20:00:19.146460 :9DB155D8:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 20:00:19.146461 :9DB155D9:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 20:00:19.146461 :9DB155DA:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 20:00:19.146461 :9DB155DB:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 20:00:19.146462 :9DB155DC:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 20:00:19.146951 :9DB155DD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.146992 :9DB155E3:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 20:00:19.154169 :9DB155F1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.155239 :9DB155F9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.155793 :9DB15601:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.156320 :9DB15609:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.156758 :9DB15611:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.159187 :9DB15619:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.160366 :9DB15621:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.209552 :9DB15629:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.210446 :9DB15631:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.210683 :9DB15639:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.210892 :9DB15641:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 20:00:19.212537 :9DB15649:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-29 20:28:21.778667 :9DB387D7:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-29 20:28:21.765 2025-05-29 20:28:21.778669 :9DB387D8:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13548 pso_num=28 pso_serial#=184 2025-05-29 20:28:21.778803 :9DB387D9:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=13548 osp_idx=26 osp_ver=155782 osp_pg=0 (spawn #232260) 2025-05-29 20:28:21.778804 :9DB387DA:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 20:28:21.778804 :9DB387DB:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=237 time=1526262547 2025-05-29 20:28:21.778805 :9DB387DC:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 20:28:21.778805 :9DB387DD:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 20:28:21.778806 :9DB387DE:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 20:28:21.778806 :9DB387DF:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 20:28:21.778806 :9DB387E0:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 20:28:21.779310 :9DB387E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 20:28:21.779351 :9DB387E7:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 20:28:21.783473 :9DB38800:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 20:28:21.783517 :9DB38801:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 20:28:21.783762 :9DB38802:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 20:28:21.783778 :9DB38803:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 20:28:21.783984 :9DB38804:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 20:28:21.783997 :9DB38805:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 20:28:21.784197 :9DB38806:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 20:28:21.784209 :9DB38807:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 20:28:21.784470 :9DB38808:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 20:28:21.784489 :9DB38809:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 20:28:21.784699 :9DB3880A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-29 20:28:21.784712 :9DB3880B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-29 20:28:21.787134 :9DB3880C:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-29 22:00:01.645130 :9DBACA08:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-29 22:00:01.645 2025-05-29 22:00:01.645131 :9DBACA09:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=1880 pso_num=28 pso_serial#=185 2025-05-29 22:00:01.645265 :9DBACA0A:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=1880 osp_idx=26 osp_ver=155783 osp_pg=0 (spawn #232474) 2025-05-29 22:00:01.645266 :9DBACA0B:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-29 22:00:01.645266 :9DBACA0C:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=238 time=1531762407 2025-05-29 22:00:01.645266 :9DBACA0D:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-29 22:00:01.645267 :9DBACA0E:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-29 22:00:01.645267 :9DBACA0F:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-29 22:00:01.645267 :9DBACA10:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-29 22:00:01.645267 :9DBACA11:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-29 22:00:01.645709 :9DBACA1B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.650978 :9DBACA44:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.651009 :9DBACA47:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-05-29 22:00:01.662820 :9DBACADC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.667198 :9DBACAF1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.667981 :9DBACB16:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.673057 :9DBACB36:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.673222 :9DBACB45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.673872 :9DBACB4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.674030 :9DBACB55:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-05-29 22:00:01.675501 :9DBACB56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.675538 :9DBACB59:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-29 22:00:01.675595 :9DBACB66:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-29 22:00:01.770660 :9DBACEA7:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 28 (osid: 1880, J002)