Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250427060009\orcl_j002_4696_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:37599M/63366M, Ph+PgF:45282M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 27 Windows thread id: 4696, image: ORACLE.EXE (J002) *** 2025-04-27 06:00:09.738 *** SESSION ID:(219.56349) 2025-04-27 06:00:09.738 *** 2025-04-27 06:00:09.738 Process diagnostic dump for ORACLE.EXE (J002), OS id=4696, pid: 27, proc_ser: 97, sid: 219, sess_ser: 56349 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 4696 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.063906 sec, exc=0.063906 sec, total=0.063906 sec wait times: max=0.500000 sec, heur=7.584354 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=14 seq_num=15 snap_id=1 wait times: snap=0.510101 sec, exc=0.510101 sec, total=0.510101 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=13 seq_num=14 snap_id=1 wait times: snap=0.500000 sec, exc=0.500000 sec, total=0.500000 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 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.000011 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 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.000012 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 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 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.499992 sec, exc=0.499992 sec, total=0.499992 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.510102 sec, exc=0.510102 sec, total=0.510102 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=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.000009 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time Sampled Session History of session 219 serial 56349 --------------------------------------------------- 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 --------------------------------------------------- [8 samples, 06:00:02 - 06:00:09] idle wait at each sample [session created at: 06:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-27 06:00:09.738 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 27 (osid: 4696, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-27 01:58:34.018443 :8F42A226: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-04-27 01:58:34.019310 :8F42A227:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:58:41.915144 :8F42A4B6:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:58:41.906 2025-04-27 01:58:41.915145 :8F42A4B7:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=10248 pso_num=27 pso_serial#=85 2025-04-27 01:58:41.915282 :8F42A4B8:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=10248 (legacy spawn) 2025-04-27 01:58:41.921819 :8F42A4B9: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-04-27 01:58:41.922010 :8F42A4BE: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-04-27 01:58:41.922886 :8F42A4C3:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:59:19.694298 :8F42B17B:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:59:19.686 2025-04-27 01:59:19.694300 :8F42B17C:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=9540 pso_num=27 pso_serial#=86 2025-04-27 01:59:19.694438 :8F42B17D:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=9540 (legacy spawn) 2025-04-27 01:59:19.700794 :8F42B17E: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-04-27 01:59:19.700970 :8F42B183: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-04-27 01:59:19.701800 :8F42B188:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:59:23.211084 :8F42B322:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:59:23.202 2025-04-27 01:59:23.211087 :8F42B323:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=6488 pso_num=27 pso_serial#=87 2025-04-27 01:59:23.211218 :8F42B324:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=6488 (legacy spawn) 2025-04-27 01:59:23.217641 :8F42B325: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-04-27 01:59:23.217816 :8F42B32A: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-04-27 01:59:23.218640 :8F42B32F:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:59:23.227254 :8F42B332:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:59:23.217 2025-04-27 01:59:23.227256 :8F42B333:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=9076 pso_num=27 pso_serial#=88 2025-04-27 01:59:23.227388 :8F42B334:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=9076 (legacy spawn) 2025-04-27 01:59:23.233838 :8F42B335: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-04-27 01:59:23.233996 :8F42B33E: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-04-27 01:59:23.234800 :8F42B33F:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:59:43.889469 :8F42B9CD:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:59:43.875 2025-04-27 01:59:43.889472 :8F42B9CE:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=7588 pso_num=27 pso_serial#=89 2025-04-27 01:59:43.889612 :8F42B9CF:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=7588 (legacy spawn) 2025-04-27 01:59:43.896107 :8F42B9D0: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-04-27 01:59:43.896280 :8F42B9D5: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-04-27 01:59:43.897116 :8F42B9DA:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:59:43.914705 :8F42B9DD:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:59:43.906 2025-04-27 01:59:43.914707 :8F42B9DE:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=8432 pso_num=27 pso_serial#=90 2025-04-27 01:59:43.914847 :8F42B9DF:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=8432 (legacy spawn) 2025-04-27 01:59:43.921271 :8F42B9E0: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-04-27 01:59:43.921433 :8F42B9E9: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-04-27 01:59:43.922349 :8F42B9EA:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:59:47.178573 :8F42BAD2:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:59:47.176 2025-04-27 01:59:47.178575 :8F42BAD3:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=10904 pso_num=27 pso_serial#=91 2025-04-27 01:59:47.178712 :8F42BAD4:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=10904 (legacy spawn) 2025-04-27 01:59:47.185470 :8F42BAD5: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-04-27 01:59:47.185654 :8F42BADA: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-04-27 01:59:47.186530 :8F42BADF:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 01:59:47.195727 :8F42BAE2:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 01:59:47.191 2025-04-27 01:59:47.195729 :8F42BAE3:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=11216 pso_num=27 pso_serial#=92 2025-04-27 01:59:47.195885 :8F42BAE4:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=11216 (legacy spawn) 2025-04-27 01:59:47.202748 :8F42BAE5: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-04-27 01:59:47.202915 :8F42BAEE: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-04-27 01:59:47.203750 :8F42BAEF:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 03:14:54.078680 :8F48CB7C:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 03:14:54.073 2025-04-27 03:14:54.078682 :8F48CB7D:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=9112 pso_num=27 pso_serial#=93 2025-04-27 03:14:54.078840 :8F48CB7E:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=9112 osp_idx=25 osp_ver=28142 osp_pg=0 (spawn #122351) 2025-04-27 03:14:54.078840 :8F48CB7F:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 03:14:54.078840 :8F48CB80:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=2 time=2994495875 2025-04-27 03:14:54.078841 :8F48CB81:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 03:14:54.078843 :8F48CB82:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 03:14:54.078843 :8F48CB83:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 03:14:54.078844 :8F48CB84:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 03:14:54.078844 :8F48CB85:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 03:14:54.079373 :8F48CB86: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-04-27 03:14:54.079417 :8F48CB8E: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-04-27 03:14:54.085817 :8F48CB9A:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 04:14:55.473727 :8F4D95F0:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 04:14:55.468 2025-04-27 04:14:55.473729 :8F4D95F1:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=8232 pso_num=27 pso_serial#=94 2025-04-27 04:14:55.473857 :8F4D95F2:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=8232 osp_idx=25 osp_ver=28143 osp_pg=0 (spawn #122492) 2025-04-27 04:14:55.473858 :8F4D95F3:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 04:14:55.473858 :8F4D95F4:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=3 time=2998097265 2025-04-27 04:14:55.473859 :8F4D95F5:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 04:14:55.473859 :8F4D95F6:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 04:14:55.473860 :8F4D95F7:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 04:14:55.473860 :8F4D95F8:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 04:14:55.473860 :8F4D95F9:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 04:14:55.474352 :8F4D95FA: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-04-27 04:14:55.474396 :8F4D9601: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-04-27 04:14:55.480768 :8F4D960E:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 05:14:56.910677 :8F525C9C:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 05:14:56.905 2025-04-27 05:14:56.910679 :8F525C9D:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=11040 pso_num=27 pso_serial#=95 2025-04-27 05:14:56.910812 :8F525C9E:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=11040 osp_idx=25 osp_ver=28144 osp_pg=0 (spawn #122635) 2025-04-27 05:14:56.910813 :8F525C9F:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 05:14:56.910813 :8F525CA0:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=4 time=3001698703 2025-04-27 05:14:56.910813 :8F525CA1:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 05:14:56.910814 :8F525CA2:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 05:14:56.910814 :8F525CA3:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 05:14:56.910814 :8F525CA4:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 05:14:56.910815 :8F525CA5:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 05:14:56.911328 :8F525CA6: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-04-27 05:14:56.911376 :8F525CAF: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-04-27 05:14:56.917706 :8F525CBA:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 06:00:00.031305 :8F55ECFF:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 06:00:00.023 2025-04-27 06:00:00.031307 :8F55ED00:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=11204 pso_num=27 pso_serial#=96 2025-04-27 06:00:00.031438 :8F55ED01:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=11204 osp_idx=25 osp_ver=28145 osp_pg=0 (spawn #122739) 2025-04-27 06:00:00.031438 :8F55ED02:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 06:00:00.031439 :8F55ED03:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=5 time=3004401828 2025-04-27 06:00:00.031439 :8F55ED04:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 06:00:00.031440 :8F55ED05:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 06:00:00.031440 :8F55ED06:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 06:00:00.031441 :8F55ED07:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 06:00:00.031441 :8F55ED08:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 06:00:00.031939 :8F55ED09: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-04-27 06:00:00.031984 :8F55ED0F: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-04-27 06:00:00.032058 :8F55ED23:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-04-27 06:00:00.035973 :8F55ED32: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-04-27 06:00:00.037220 :8F55ED3A: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-04-27 06:00:00.037244 :8F55ED3D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-04-27 06:00:00.037280 :8F55ED48:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-27 06:00:00.039107 :8F55ED53: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-04-27 06:00:00.039138 :8F55ED56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-04-27 06:00:00.039183 :8F55ED61:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-27 06:00:00.039646 :8F55ED6C: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-04-27 06:00:00.042103 :8F55ED74: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-04-27 06:00:00.047439 :8F55ED7C: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-04-27 06:00:00.048500 :8F55ED84: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-04-27 06:00:00.053276 :8F55ED8C: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-04-27 06:00:00.054753 :8F55ED94: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-04-27 06:00:00.057621 :8F55ED9C: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-04-27 06:00:00.058966 :8F55EDA4: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-04-27 06:00:00.061832 :8F55EDAC: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-04-27 06:00:00.065760 :8F55EDB4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-04-27 06:00:00.066087 :8F55EDC3: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-04-27 06:00:00.066136 :8F55EDC6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-04-27 06:00:00.066151 :8F55EDC7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-04-27 06:00:00.068913 :8F55EDCD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-04-27 06:00:00.069219 :8F55EDDC: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-04-27 06:00:00.069271 :8F55EDDF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-04-27 06:00:00.069285 :8F55EDE0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-04-27 06:00:00.072105 :8F55EDE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-04-27 06:00:00.072372 :8F55EDF5: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-04-27 06:00:00.072420 :8F55EDF8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:ktcc.c:879 2025-04-27 06:00:00.072433 :8F55EDF9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:ktcc.c:879 2025-04-27 06:00:00.072613 :8F55EDFF: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-04-27 06:00:00.072626 :8F55EE02:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-04-27 06:00:00.072651 :8F55EE0E:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-27 06:00:00.074149 :8F55EE18:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-04-27 06:00:02.040585 :8F55EECB:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 04-27 06:00:02.035 2025-04-27 06:00:02.040587 :8F55EECC:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=4696 pso_num=27 pso_serial#=97 2025-04-27 06:00:02.040718 :8F55EED1:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=4696 osp_idx=25 osp_ver=28146 osp_pg=0 (spawn #122740) 2025-04-27 06:00:02.040719 :8F55EED2:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-27 06:00:02.040719 :8F55EED3:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=6 time=3004403843 2025-04-27 06:00:02.040720 :8F55EED4:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-04-27 06:00:02.040720 :8F55EED5:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-04-27 06:00:02.040720 :8F55EED6:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-04-27 06:00:02.040721 :8F55EED7:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-27 06:00:02.040721 :8F55EED8:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-27 06:00:02.041231 :8F55EEDF: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-04-27 06:00:02.046268 :8F55EF04: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-04-27 06:00:02.046307 :8F55EF09:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-04-27 06:00:02.064819 :8F55EFA8:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-04-27 06:00:02.065416 :8F55EFB2:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 cca6110000000000 2025-04-27 06:00:02.067166 :8F55EFC4: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-04-27 06:00:02.067221 :8F55EFD1: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-04-27 06:00:02.067230 :8F55EFD8:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-04-27 06:00:02.067234 :8F55EFD9: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-04-27 06:00:02.067259 :8F55EFE5: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-04-27 06:00:02.067975 :8F55EFF1:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 223556420) 2025-04-27 06:00:02.067980 :8F55EFF2: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-04-27 06:00:02.068001 :8F55EFFF: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-04-27 06:00:02.068008 :8F55F00A:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65563 1) 2025-04-27 06:00:02.068010 :8F55F00B: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-04-27 06:00:02.068035 :8F55F017: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-04-27 06:00:02.068038 :8F55F022:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65563) 2025-04-27 06:00:02.068040 :8F55F024: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-04-27 06:00:02.068092 :8F55F046: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-04-27 06:00:02.068828 :8F55F0F1: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-04-27 06:00:02.068855 :8F55F0FC:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-04-27 06:00:02.069860 :8F55F120:db_trace:kcc.c@13684:kccwbp(): [10021:27:219:1] 0115000000000000 0115000000000000 cda6110000000000 2025-04-27 06:00:02.070238 :8F55F136:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 223556420) 2025-04-27 06:00:02.070244 :8F55F137: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-04-27 06:00:02.070269 :8F55F142: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-04-27 06:00:02.089341 :8F55F1EE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-04-27 06:00:02.090924 :8F55F1EF: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-04-27 06:00:02.090974 :8F55F1F4: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-04-27 06:00:02.091116 :8F55F201: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-04-27 06:00:02.145093 :8F55F219:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-27 06:00:02.147265 :8F55F21B: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-04-27 06:00:02.147307 :8F55F21E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-04-27 06:00:02.149953 :8F55F224:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-04-27 06:00:02.153318 :8F55F225: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-04-27 06:00:02.153412 :8F55F228: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-04-27 06:00:02.153494 :8F55F235: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: 4696, J002)