Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250915220005\orcl_j002_19848_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:34716M/63366M, Ph+PgF:39306M/72582M 
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 28
Windows thread id: 19848, image: ORACLE.EXE (J002)


*** 2025-09-15 22:00:05.239
*** SESSION ID:(225.491) 2025-09-15 22:00:05.239
 

*** 2025-09-15 22:00:05.239
Process diagnostic dump for ORACLE.EXE (J002), OS id=19848,
pid: 28, proc_ser: 222, sid: 225, sess_ser: 491 
-------------------------------------------------------------------------------
current sql: <none>
client details:
  O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 19848
  machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002)
Current Wait Stack:
 0: waiting for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=10 seq_num=11 snap_id=1
    wait times: snap=0.097767 sec, exc=0.097767 sec, total=0.097767 sec
    wait times: max=0.500000 sec, heur=4.711131 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=9 seq_num=10 snap_id=1
    wait times: snap=0.499995 sec, exc=0.499995 sec, total=0.499995 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000009 sec of elapsed time
 1: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=8 seq_num=9 snap_id=1
    wait times: snap=0.510119 sec, exc=0.510119 sec, total=0.510119 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000008 sec of elapsed time
 2: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=7 seq_num=8 snap_id=1
    wait times: snap=0.500007 sec, exc=0.500007 sec, total=0.500007 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000008 sec of elapsed time
 3: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=6 seq_num=7 snap_id=1
    wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000010 sec of elapsed time
 4: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=5 seq_num=6 snap_id=1
    wait times: snap=0.510166 sec, exc=0.510166 sec, total=0.510166 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=4 seq_num=5 snap_id=1
    wait times: snap=0.499984 sec, exc=0.499984 sec, total=0.499984 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000015 sec of elapsed time
 6: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=3 seq_num=4 snap_id=1
    wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec
    wait times: max=0.500000 sec
    wait counts: calls=1 os=1
    occurred after 0.000008 sec of elapsed time
 7: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=2 seq_num=3 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.000007 sec of elapsed time
 8: waited for 'jobq slave wait'
    =0x0, =0x0, =0x0
    wait_id=1 seq_num=2 snap_id=1
    wait times: snap=0.499204 sec, exc=0.499204 sec, total=0.499204 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=0 seq_num=1 snap_id=1
    wait times: snap=0.093805 sec, exc=0.093805 sec, total=0.093805 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 225 serial 491
---------------------------------------------------
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:00 - 22:00:05]
    idle wait at each sample
  [session created at: 22:00:00]
-------------------------------------------------------------------------------
Process diagnostic dump actual duration=0.000000 sec
  (max dump time=30.000000 sec)

*** 2025-09-15 22:00:05.239
 
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 28 (osid: 19848, J002)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
-------------------------------------------------------------------------------
2025-09-15 17:00:25.111673 :CDD35A52:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 17:00:25.111674 :CDD35A53:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 17:00:25.111674 :CDD35A54:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 17:00:25.111675 :CDD35A55:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 17:00:25.111676 :CDD35A56:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 17:00:25.112725 :CDD35A57: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-09-15 17:00:25.112780 :CDD35A5D: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-09-15 17:00:25.121434 :CDD35A6F:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 17:30:29.066474 :CDD5BE93:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 17:30:29.065
2025-09-15 17:30:29.066476 :CDD5BE94:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21476 pso_num=28 pso_serial#=215
2025-09-15 17:30:29.066623 :CDD5BE95:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=21476 osp_idx=26 osp_ver=327683 osp_pg=0 (spawn #595224)
2025-09-15 17:30:29.066624 :CDD5BE96:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 17:30:29.066624 :CDD5BE97:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=18 time=2343080362
2025-09-15 17:30:29.066625 :CDD5BE98:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 17:30:29.066625 :CDD5BE99:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 17:30:29.066625 :CDD5BE9A:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 17:30:29.066626 :CDD5BE9B:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 17:30:29.066626 :CDD5BE9C:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 17:30:29.067162 :CDD5BE9D: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-09-15 17:30:29.067206 :CDD5BEA3: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-09-15 17:30:29.071407 :CDD5BEBC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 17:30:29.071454 :CDD5BEBD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 17:30:29.071815 :CDD5BEBE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 17:30:29.071834 :CDD5BEBF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 17:30:29.072055 :CDD5BEC0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 17:30:29.072068 :CDD5BEC1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 17:30:29.072285 :CDD5BEC2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 17:30:29.072299 :CDD5BEC3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 17:30:29.072513 :CDD5BEC4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 17:30:29.072526 :CDD5BEC5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 17:30:29.072738 :CDD5BEC6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 17:30:29.072752 :CDD5BEC7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 17:30:29.075174 :CDD5BEC8:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 18:00:32.740873 :CDD81A83:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 18:00:32.731
2025-09-15 18:00:32.740874 :CDD81A84:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=25296 pso_num=28 pso_serial#=216
2025-09-15 18:00:32.741011 :CDD81A85:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=25296 osp_idx=26 osp_ver=327684 osp_pg=0 (spawn #595292)
2025-09-15 18:00:32.741012 :CDD81A86:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 18:00:32.741012 :CDD81A87:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=19 time=2344884033
2025-09-15 18:00:32.741013 :CDD81A88:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 18:00:32.741013 :CDD81A89:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 18:00:32.741014 :CDD81A8A:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 18:00:32.741015 :CDD81A8B:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 18:00:32.741015 :CDD81A8C:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 18:00:32.741517 :CDD81A90: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-09-15 18:00:32.741556 :CDD81A96: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-09-15 18:00:32.750748 :CDD81AA8:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 18:30:36.602724 :CDDA8573:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 18:30:36.590
2025-09-15 18:30:36.602726 :CDDA8574:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=25480 pso_num=28 pso_serial#=217
2025-09-15 18:30:36.602862 :CDDA8575:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=25480 osp_idx=26 osp_ver=327685 osp_pg=0 (spawn #595363)
2025-09-15 18:30:36.602863 :CDDA8576:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 18:30:36.602863 :CDDA8577:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=20 time=2346687893
2025-09-15 18:30:36.602863 :CDDA8578:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 18:30:36.602864 :CDDA8579:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 18:30:36.602864 :CDDA857A:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 18:30:36.602864 :CDDA857B:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 18:30:36.602865 :CDDA857C:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 18:30:36.603361 :CDDA857D: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-09-15 18:30:36.603401 :CDDA8583: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-09-15 18:30:36.607508 :CDDA859C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 18:30:36.607548 :CDDA859D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 18:30:36.607814 :CDDA859E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 18:30:36.607830 :CDDA859F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 18:30:36.608049 :CDDA85A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 18:30:36.608063 :CDDA85A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 18:30:36.608273 :CDDA85A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 18:30:36.608285 :CDDA85A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 18:30:36.608485 :CDDA85A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 18:30:36.608497 :CDDA85A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 18:30:36.608738 :CDDA85A6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 18:30:36.608758 :CDDA85A7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 18:30:36.611098 :CDDA85A8:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 19:00:40.374102 :CDDCE5AD:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 19:00:40.360
2025-09-15 19:00:40.374104 :CDDCE5AE:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=22352 pso_num=28 pso_serial#=218
2025-09-15 19:00:40.374307 :CDDCE5AF:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=22352 osp_idx=26 osp_ver=327686 osp_pg=0 (spawn #595430)
2025-09-15 19:00:40.374308 :CDDCE5B0:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 19:00:40.374309 :CDDCE5B1:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=21 time=2348491674
2025-09-15 19:00:40.374309 :CDDCE5B2:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 19:00:40.374309 :CDDCE5B3:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 19:00:40.374310 :CDDCE5B4:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 19:00:40.374310 :CDDCE5B5:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 19:00:40.374310 :CDDCE5B6:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 19:00:40.376306 :CDDCE5BE: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-09-15 19:00:40.376356 :CDDCE5C4: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-09-15 19:00:40.385620 :CDDCE5DB:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 19:30:44.393343 :CDDF5123:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 19:30:44.380
2025-09-15 19:30:44.393345 :CDDF5124:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=24864 pso_num=28 pso_serial#=219
2025-09-15 19:30:44.393479 :CDDF5125:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=24864 osp_idx=26 osp_ver=327687 osp_pg=0 (spawn #595499)
2025-09-15 19:30:44.393480 :CDDF5126:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 19:30:44.393480 :CDDF5127:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=22 time=2350295690
2025-09-15 19:30:44.393481 :CDDF5128:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 19:30:44.393481 :CDDF5129:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 19:30:44.393481 :CDDF512A:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 19:30:44.393481 :CDDF512B:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 19:30:44.393481 :CDDF512C:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 19:30:44.393985 :CDDF512D: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-09-15 19:30:44.394029 :CDDF5133: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-09-15 19:30:44.398181 :CDDF514C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 19:30:44.398224 :CDDF514D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 19:30:44.398476 :CDDF514E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 19:30:44.398492 :CDDF514F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 19:30:44.398707 :CDDF5150:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 19:30:44.398723 :CDDF5151:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 19:30:44.398934 :CDDF5152:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 19:30:44.398947 :CDDF5153:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 19:30:44.399146 :CDDF5154:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 19:30:44.399159 :CDDF5155:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 19:30:44.399399 :CDDF5156:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517
2025-09-15 19:30:44.399418 :CDDF5157:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517
2025-09-15 19:30:44.401795 :CDDF5158:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 20:00:48.506521 :CDE1AAEE:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 20:00:48.495
2025-09-15 20:00:48.506522 :CDE1AAEF:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=25256 pso_num=28 pso_serial#=220
2025-09-15 20:00:48.506669 :CDE1AAF0:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=25256 osp_idx=26 osp_ver=327688 osp_pg=0 (spawn #595569)
2025-09-15 20:00:48.506671 :CDE1AAF1:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 20:00:48.506671 :CDE1AAF2:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=23 time=2352099799
2025-09-15 20:00:48.506672 :CDE1AAF3:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 20:00:48.506673 :CDE1AAF4:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 20:00:48.506673 :CDE1AAF5:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 20:00:48.506675 :CDE1AAF6:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 20:00:48.506675 :CDE1AAF7:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 20:00:48.508217 :CDE1AAF8: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-09-15 20:00:48.508273 :CDE1AAFE: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-09-15 20:00:48.516849 :CDE1AB10:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 21:00:56.570794 :CDE67316:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 21:00:56.560
2025-09-15 21:00:56.570796 :CDE67317:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=23304 pso_num=28 pso_serial#=221
2025-09-15 21:00:56.570936 :CDE67318:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=23304 osp_idx=26 osp_ver=327689 osp_pg=0 (spawn #595708)
2025-09-15 21:00:56.570936 :CDE67319:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 21:00:56.570937 :CDE6731A:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=24 time=2355707877
2025-09-15 21:00:56.570937 :CDE6731B:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 21:00:56.570938 :CDE6731C:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 21:00:56.570938 :CDE6731D:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 21:00:56.570938 :CDE6731E:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 21:00:56.570939 :CDE6731F:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 21:00:56.571578 :CDE67323: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-09-15 21:00:56.571624 :CDE67329: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-09-15 21:00:56.581040 :CDE6733B:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted
2025-09-15 22:00:00.502179 :CDEB24E0:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-15 22:00:00.500
2025-09-15 22:00:00.502181 :CDEB24E1:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=19848 pso_num=28 pso_serial#=222
2025-09-15 22:00:00.502337 :CDEB24E3:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=19848 osp_idx=26 osp_ver=327690 osp_pg=0 (spawn #595846)
2025-09-15 22:00:00.502338 :CDEB24E4:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A
2025-09-15 22:00:00.502339 :CDEB24E5:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=25 time=2359251799
2025-09-15 22:00:00.502339 :CDEB24E6:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs
2025-09-15 22:00:00.502340 :CDEB24E7:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs
2025-09-15 22:00:00.502340 :CDEB24E8:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs
2025-09-15 22:00:00.502341 :CDEB24E9:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-09-15 22:00:00.502341 :CDEB24EA:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-09-15 22:00:00.502907 :CDEB24F3: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-09-15 22:00:00.507873 :CDEB2518: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-09-15 22:00:00.507912 :CDEB251B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203
2025-09-15 22:00:00.515920 :CDEB2580:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7
2025-09-15 22:00:00.516512 :CDEB2581:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 2dc1120000000000
2025-09-15 22:00:00.518121 :CDEB2582:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name=   type=0
2025-09-15 22:00:00.518218 :CDEB258F:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-09-15 22:00:00.518228 :CDEB2596:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1)
2025-09-15 22:00:00.518234 :CDEB2597:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-09-15 22:00:00.518266 :CDEB25A3:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-09-15 22:00:00.518973 :CDEB25AE:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 237626178)
2025-09-15 22:00:00.518977 :CDEB25AF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-09-15 22:00:00.519002 :CDEB25BA:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-09-15 22:00:00.519013 :CDEB25C7:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65564 1)
2025-09-15 22:00:00.519015 :CDEB25C8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-09-15 22:00:00.519047 :CDEB25D4:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-09-15 22:00:00.519050 :CDEB25DC:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65564)
2025-09-15 22:00:00.519053 :CDEB25E0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-09-15 22:00:00.519106 :CDEB2602:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-09-15 22:00:00.519929 :CDEB2681:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-09-15 22:00:00.519947 :CDEB2686:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7
2025-09-15 22:00:00.520764 :CDEB26DA:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 2ec1120000000000
2025-09-15 22:00:00.521165 :CDEB26DB:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 237626178)
2025-09-15 22:00:00.521171 :CDEB26DC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name=   type=0
2025-09-15 22:00:00.521196 :CDEB26E7:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
2025-09-15 22:00:00.530069 :CDEB2716:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203
2025-09-15 22:00:00.531844 :CDEB2727: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-09-15 22:00:00.531886 :CDEB272C: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-09-15 22:00:00.531970 :CDEB273A: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-09-15 22:00:00.626489 :CDEB2822: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: 19848, J002)