Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250705060008\orcl_j002_18064_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:37534M/63366M, Ph+PgF:43420M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 27 Windows thread id: 18064, image: ORACLE.EXE (J002) *** 2025-07-05 06:00:08.318 *** SESSION ID:(219.59107) 2025-07-05 06:00:08.318 *** 2025-07-05 06:00:08.318 Process diagnostic dump for ORACLE.EXE (J002), OS id=18064, pid: 27, proc_ser: 3, sid: 219, sess_ser: 59107 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 18064 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.012982 sec, exc=0.012982 sec, total=0.012982 sec wait times: max=0.500000 sec, heur=7.009924 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=13 seq_num=14 snap_id=1 wait times: snap=0.499989 sec, exc=0.499989 sec, total=0.499989 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.500006 sec, exc=0.500006 sec, total=0.500006 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.499985 sec, exc=0.499985 sec, total=0.499985 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000015 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.499976 sec, exc=0.499976 sec, total=0.499976 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000016 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.500015 sec, exc=0.500015 sec, total=0.500015 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.502087 sec, exc=0.502087 sec, total=0.502087 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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=6 seq_num=7 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.000006 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 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.000007 sec of elapsed time 9: 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.000006 sec of elapsed time Sampled Session History of session 219 serial 59107 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [7 samples, 06:00:01 - 06:00:08] idle wait at each sample [session created at: 06:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-05 06:00:08.318 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 27 (osid: 18064, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-05 01:58:07.489936 :ADA672A9:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:58:07.490842 :ADA672AB:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 01:58:26.707826 :ADA6785F:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 01:58:26.699 2025-07-05 01:58:26.707828 :ADA67860:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=14940 pso_num=27 pso_serial#=240 2025-07-05 01:58:26.707964 :ADA67861:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=14940 (legacy spawn) 2025-07-05 01:58:26.714385 :ADA67862:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 01:58:26.714551 :ADA67867:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:58:26.715357 :ADA6786C:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 01:59:07.695299 :ADA685D8:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 01:59:07.681 2025-07-05 01:59:07.695301 :ADA685D9:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17932 pso_num=27 pso_serial#=241 2025-07-05 01:59:07.695434 :ADA685DA:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=17932 (legacy spawn) 2025-07-05 01:59:07.701818 :ADA685DB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 01:59:07.701995 :ADA685E1:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:59:07.702790 :ADA685E5:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 01:59:07.711511 :ADA685E8:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 01:59:07.696 2025-07-05 01:59:07.711513 :ADA685E9:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=5196 pso_num=27 pso_serial#=242 2025-07-05 01:59:07.711644 :ADA685EA:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=5196 (legacy spawn) 2025-07-05 01:59:07.718112 :ADA685EB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 01:59:07.718275 :ADA685F3:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:59:07.719104 :ADA685F5:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 01:59:11.108803 :ADA686DF:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 01:59:11.097 2025-07-05 01:59:11.108805 :ADA686E0:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16524 pso_num=27 pso_serial#=243 2025-07-05 01:59:11.108948 :ADA686E1:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=16524 (legacy spawn) 2025-07-05 01:59:11.115418 :ADA686E2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 01:59:11.115587 :ADA686E7:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:59:11.116379 :ADA686EC:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 01:59:11.124986 :ADA686EF:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 01:59:11.113 2025-07-05 01:59:11.124988 :ADA686F0:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16156 pso_num=27 pso_serial#=244 2025-07-05 01:59:11.125118 :ADA686F1:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=16156 (legacy spawn) 2025-07-05 01:59:11.131552 :ADA686F2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 01:59:11.131712 :ADA686FB:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:59:11.132499 :ADA686FC:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 01:59:15.438706 :ADA6887E:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 01:59:15.430 2025-07-05 01:59:15.438708 :ADA6887F:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=6728 pso_num=27 pso_serial#=245 2025-07-05 01:59:15.438842 :ADA68880:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=6728 (legacy spawn) 2025-07-05 01:59:15.445265 :ADA68881:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 01:59:15.445438 :ADA68886:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:59:15.446268 :ADA6888B:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 01:59:28.892471 :ADA68C84:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 01:59:28.884 2025-07-05 01:59:28.892473 :ADA68C85:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17796 pso_num=27 pso_serial#=246 2025-07-05 01:59:28.892612 :ADA68C86:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=17796 (legacy spawn) 2025-07-05 01:59:28.899063 :ADA68C87:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 01:59:28.899237 :ADA68C8C:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 01:59:28.900040 :ADA68C91:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 02:01:31.932929 :ADA6B896:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 02:01:31.933 2025-07-05 02:01:31.932931 :ADA6B897:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15584 pso_num=27 pso_serial#=247 2025-07-05 02:01:31.933131 :ADA6B898:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=15584 osp_idx=25 osp_ver=127755 osp_pg=0 (spawn #353055) 2025-07-05 02:01:31.933132 :ADA6B899:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 02:01:31.933132 :ADA6B89A:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=193 time=361667829 2025-07-05 02:01:31.933133 :ADA6B89B:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 02:01:31.933133 :ADA6B89C:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 02:01:31.933134 :ADA6B89D:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 02:01:31.933134 :ADA6B89E:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 02:01:31.933135 :ADA6B89F:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 02:01:31.933646 :ADA6B8A0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 02:01:31.933687 :ADA6B8A6:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 02:01:31.941683 :ADA6B8C8:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 03:01:39.572135 :ADAB5AD8:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 03:01:39.559 2025-07-05 03:01:39.572137 :ADAB5AD9:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16136 pso_num=27 pso_serial#=248 2025-07-05 03:01:39.572272 :ADAB5ADA:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=16136 osp_idx=25 osp_ver=127756 osp_pg=0 (spawn #353194) 2025-07-05 03:01:39.572273 :ADAB5ADB:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 03:01:39.572273 :ADAB5ADC:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=194 time=365275454 2025-07-05 03:01:39.572274 :ADAB5ADD:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 03:01:39.572275 :ADAB5ADE:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 03:01:39.572275 :ADAB5ADF:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 03:01:39.572276 :ADAB5AE0:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 03:01:39.572276 :ADAB5AE1:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 03:01:39.572814 :ADAB5AE2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 03:01:39.572860 :ADAB5AE8:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 03:01:39.581079 :ADAB5B09:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 03:37:21.697520 :ADAE1BC3:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 03:37:21.683 2025-07-05 03:37:21.697521 :ADAE1BC4:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17736 pso_num=27 pso_serial#=249 2025-07-05 03:37:21.697662 :ADAE1BC5:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=17736 (legacy spawn) 2025-07-05 03:37:21.704210 :ADAE1BC6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 03:37:21.704382 :ADAE1BCB:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 03:37:21.705222 :ADAE1BD0:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 03:37:21.714051 :ADAE1BDE:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 03:37:21.714 2025-07-05 03:37:21.714053 :ADAE1BDF:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16092 pso_num=27 pso_serial#=250 2025-07-05 03:37:21.714187 :ADAE1BE0:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=16092 (legacy spawn) 2025-07-05 03:37:21.720706 :ADAE1BE1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 03:37:21.720865 :ADAE1BEA:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 03:37:21.721648 :ADAE1BEB:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 03:37:24.819698 :ADAE1CE2:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 03:37:24.810 2025-07-05 03:37:24.819701 :ADAE1CE3:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=10784 pso_num=27 pso_serial#=251 2025-07-05 03:37:24.819843 :ADAE1CE4:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=10784 (legacy spawn) 2025-07-05 03:37:24.826502 :ADAE1CE5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 03:37:24.826676 :ADAE1CEA:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 03:37:24.827499 :ADAE1CEF:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 03:37:24.836406 :ADAE1CF2:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 03:37:24.826 2025-07-05 03:37:24.836408 :ADAE1CF3:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15264 pso_num=27 pso_serial#=252 2025-07-05 03:37:24.836545 :ADAE1CF4:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=15264 (legacy spawn) 2025-07-05 03:37:24.843064 :ADAE1CF5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 03:37:24.843223 :ADAE1CFE:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 03:37:24.844009 :ADAE1CFF:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 03:37:26.855932 :ADAE1D50:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 03:37:26.847 2025-07-05 03:37:26.855935 :ADAE1D51:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=18276 pso_num=27 pso_serial#=253 2025-07-05 03:37:26.856104 :ADAE1D52:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=18276 (legacy spawn) 2025-07-05 03:37:26.863073 :ADAE1D53:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 03:37:26.863268 :ADAE1D58:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 03:37:26.864129 :ADAE1D5D:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 03:37:36.251185 :ADAE2033:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 03:37:36.241 2025-07-05 03:37:36.251187 :ADAE2034:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=4884 pso_num=27 pso_serial#=254 2025-07-05 03:37:36.251322 :ADAE2035:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=4884 (legacy spawn) 2025-07-05 03:37:36.258129 :ADAE2036:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 03:37:36.258315 :ADAE203F:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 03:37:36.259142 :ADAE2040:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 04:01:47.254912 :ADAFFDC2:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 04:01:47.241 2025-07-05 04:01:47.254914 :ADAFFDC3:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=8508 pso_num=27 pso_serial#=255 2025-07-05 04:01:47.255060 :ADAFFDC4:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=8508 osp_idx=25 osp_ver=127763 osp_pg=0 (spawn #353333) 2025-07-05 04:01:47.255061 :ADAFFDC5:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 04:01:47.255061 :ADAFFDC6:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=195 time=368883142 2025-07-05 04:01:47.255062 :ADAFFDC7:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 04:01:47.255062 :ADAFFDC8:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 04:01:47.255063 :ADAFFDC9:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 04:01:47.255063 :ADAFFDCA:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 04:01:47.255064 :ADAFFDCB:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 04:01:47.255654 :ADAFFDCC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 04:01:47.255694 :ADAFFDD2:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 04:01:47.264101 :ADAFFDE4:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 04:58:47.156012 :ADB47839:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 04:58:47.147 2025-07-05 04:58:47.156014 :ADB4783A:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15528 pso_num=27 pso_serial#=1 2025-07-05 04:58:47.156154 :ADB4783B:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=15528 (legacy spawn) 2025-07-05 04:58:47.642275 :ADB478A6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 04:58:47.689998 :ADB478BA:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 04:58:47.691036 :ADB478CF:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 05:00:24.169264 :ADB49B3F:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 05:00:24.165 2025-07-05 05:00:24.169266 :ADB49B40:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17656 pso_num=27 pso_serial#=2 2025-07-05 05:00:24.169399 :ADB49B41:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=17656 osp_idx=25 osp_ver=127765 osp_pg=0 (spawn #353469) 2025-07-05 05:00:24.169400 :ADB49B42:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 05:00:24.169400 :ADB49B43:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=196 time=372400048 2025-07-05 05:00:24.169401 :ADB49B44:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 05:00:24.169401 :ADB49B45:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 05:00:24.169402 :ADB49B46:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 05:00:24.169402 :ADB49B47:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 05:00:24.169403 :ADB49B48:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 05:00:24.169960 :ADB49B49:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 05:00:24.174528 :ADB49B66:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 05:00:24.182019 :ADB49B67:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 05:00:24.374790 :ADB49B6F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 05:00:24.376625 :ADB49B8C:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-07-05 05:00:24.378090 :ADB49B8D:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-07-05 06:00:01.207275 :ADB968B6:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 07-05 06:00:01.205 2025-07-05 06:00:01.207277 :ADB968B7:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=18064 pso_num=27 pso_serial#=3 2025-07-05 06:00:01.207406 :ADB968BC:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=18064 osp_idx=25 osp_ver=127766 osp_pg=0 (spawn #353608) 2025-07-05 06:00:01.207407 :ADB968BD:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 06:00:01.207408 :ADB968BE:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=197 time=375977095 2025-07-05 06:00:01.207408 :ADB968BF:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 06:00:01.207409 :ADB968C0:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 06:00:01.207409 :ADB968C1:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 06:00:01.207410 :ADB968C2:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 06:00:01.207411 :ADB968C3:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 06:00:01.207976 :ADB968C9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.213208 :ADB968E6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.213245 :ADB968E9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-07-05 06:00:01.263399 :ADB96A61:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-05 06:00:01.263990 :ADB96A62:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 5830120000000000 2025-07-05 06:00:01.269949 :ADB96A63:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.270031 :ADB96A70:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-05 06:00:01.270040 :ADB96A77:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-07-05 06:00:01.270045 :ADB96A78:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.270073 :ADB96A84:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-05 06:00:01.270967 :ADB96A98:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 230412150) 2025-07-05 06:00:01.270974 :ADB96A99:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.271002 :ADB96AA4:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-05 06:00:01.271011 :ADB96AB1:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65563 1) 2025-07-05 06:00:01.271014 :ADB96AB2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.271045 :ADB96AC2:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-05 06:00:01.271051 :ADB96ACA:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65563) 2025-07-05 06:00:01.271055 :ADB96ACB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.271122 :ADB96AED:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-05 06:00:01.272108 :ADB96C0A:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-05 06:00:01.272127 :ADB96C0B:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-05 06:00:01.272985 :ADB96C12:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 5930120000000000 2025-07-05 06:00:01.273384 :ADB96C13:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 230412150) 2025-07-05 06:00:01.273390 :ADB96C14:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.273413 :ADB96C1D:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-05 06:00:01.318393 :ADB96C4F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-07-05 06:00:01.320282 :ADB96C50:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.320341 :ADB96C53:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-05 06:00:01.320458 :ADB96C63:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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 27 (osid: 18064, J002)