Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250815220009\orcl_j002_10620_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:35467M/63366M, Ph+PgF:40797M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 10620, image: ORACLE.EXE (J002) *** 2025-08-15 22:00:10.064 *** SESSION ID:(225.63727) 2025-08-15 22:00:10.064 *** 2025-08-15 22:00:10.064 Process diagnostic dump for ORACLE.EXE (J002), OS id=10620, pid: 28, proc_ser: 25, sid: 225, sess_ser: 63727 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 10620 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=0.053352 sec, exc=0.053352 sec, total=0.053352 sec wait times: max=0.500000 sec, heur=7.979405 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=16 seq_num=17 snap_id=1 wait times: snap=0.499991 sec, exc=0.499991 sec, total=0.499991 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.500162 sec, exc=0.500162 sec, total=0.500162 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 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.000011 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 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.000010 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 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.000009 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.512785 sec, exc=0.512785 sec, total=0.512785 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000018 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.500029 sec, exc=0.500029 sec, total=0.500029 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=9 seq_num=10 snap_id=1 wait times: snap=0.510093 sec, exc=0.510093 sec, total=0.510093 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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.000013 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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.000013 sec of elapsed time Sampled Session History of session 225 serial 63727 --------------------------------------------------- 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, 22:00:02 - 22:00:10] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-15 22:00:10.064 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 10620, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-15 16:00:02.781735 :C01C8184:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-15 16:00:02.781735 :C01C8185:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=2 time=3954272079 2025-08-15 16:00:02.781736 :C01C8186:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-15 16:00:02.781736 :C01C8187:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-15 16:00:02.781736 :C01C8188:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-15 16:00:02.781736 :C01C8189:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-15 16:00:02.781737 :C01C818A:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-15 16:00:02.782250 :C01C818B: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-08-15 16:00:02.782300 :C01C8191: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-08-15 16:00:02.790299 :C01C81A0:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 16:00:14.294797 :C01C84C4:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 16:00:14.280 2025-08-15 16:00:14.294799 :C01C84C5:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=18048 pso_num=28 pso_serial#=15 2025-08-15 16:00:14.294940 :C01C84C6:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=18048 (legacy spawn) 2025-08-15 16:00:14.301484 :C01C84C7: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-08-15 16:00:14.301673 :C01C84D0: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-08-15 16:00:14.302463 :C01C84D1:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 16:00:14.311101 :C01C84D4:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 16:00:14.296 2025-08-15 16:00:14.311103 :C01C84D5:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=19892 pso_num=28 pso_serial#=16 2025-08-15 16:00:14.311233 :C01C84D6:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=19892 (legacy spawn) 2025-08-15 16:00:14.317749 :C01C84D7: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-08-15 16:00:14.317904 :C01C84E0: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-08-15 16:00:14.318715 :C01C84E1:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 16:00:14.523422 :C01C84F0:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 16:00:14.515 2025-08-15 16:00:14.523424 :C01C84F1:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21456 pso_num=28 pso_serial#=17 2025-08-15 16:00:14.523565 :C01C84F2:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=21456 (legacy spawn) 2025-08-15 16:00:14.530047 :C01C84F3: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-08-15 16:00:14.530229 :C01C8525: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-08-15 16:00:14.531027 :C01C852A:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 16:00:17.579880 :C01C8614:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 16:00:17.566 2025-08-15 16:00:17.579882 :C01C8615:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=18848 pso_num=28 pso_serial#=18 2025-08-15 16:00:17.580024 :C01C8616:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=18848 (legacy spawn) 2025-08-15 16:00:17.586848 :C01C8617: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-08-15 16:00:17.587043 :C01C861C: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-08-15 16:00:17.587967 :C01C8621:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 16:00:17.606566 :C01C8624:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 16:00:17.597 2025-08-15 16:00:17.606568 :C01C8625:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=19736 pso_num=28 pso_serial#=19 2025-08-15 16:00:17.606713 :C01C8626:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=19736 (legacy spawn) 2025-08-15 16:00:17.613760 :C01C8627: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-08-15 16:00:17.613936 :C01C862E: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-08-15 16:00:17.614875 :C01C8631:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 16:00:18.219048 :C01C868A:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 16:00:18.211 2025-08-15 16:00:18.219050 :C01C868B:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21284 pso_num=28 pso_serial#=20 2025-08-15 16:00:18.219186 :C01C868C:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=21284 (legacy spawn) 2025-08-15 16:00:18.225553 :C01C868D: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-08-15 16:00:18.225720 :C01C8696: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-08-15 16:00:18.226516 :C01C8697:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 16:00:20.825290 :C01C876E:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 16:00:20.820 2025-08-15 16:00:20.825292 :C01C876F:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21056 pso_num=28 pso_serial#=21 2025-08-15 16:00:20.825437 :C01C8770:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=21056 osp_idx=26 osp_ver=228294 osp_pg=0 (spawn #491639) 2025-08-15 16:00:20.825438 :C01C8771:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-15 16:00:20.825438 :C01C8772:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=3 time=3954290126 2025-08-15 16:00:20.825439 :C01C8773:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-15 16:00:20.825439 :C01C8774:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-15 16:00:20.825439 :C01C8775:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-15 16:00:20.825440 :C01C8776:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-15 16:00:20.825440 :C01C8777:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-15 16:00:20.825943 :C01C8778: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-08-15 16:00:20.825993 :C01C877E: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-08-15 16:00:20.830453 :C01C8791: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-08-15 16:00:20.856183 :C01C8799:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 4286498185 8469112) 2025-08-15 16:00:20.856191 :C01C879A: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-08-15 16:00:20.856242 :C01C87A5: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-08-15 16:00:20.856291 :C01C87B2: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-08-15 16:00:20.862655 :C01C87BA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=16 loc='ktm.h LINE:583 ID:ktmpsm' id1=0 id2=0 name= type=0 2025-08-15 16:00:20.862863 :C01C87C5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=16 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-08-15 16:00:20.865225 :C01C87D1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=16 loc='ktm.h LINE:583 ID:ktmpsm' id1=0 id2=0 name= type=0 2025-08-15 16:00:20.871629 :C01C87D2: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-08-15 16:00:20.903148 :C01C8852:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-08-15 16:00:20.903565 :C01C8864: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-08-15 16:00:20.907076 :C01C891E: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-08-15 16:00:20.910639 :C01C892E: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-08-15 16:00:20.914942 :C01C8936: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-08-15 16:00:20.915935 :C01C893E: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-08-15 16:00:20.952116 :C01C8946:db_trace:ktu.c@4871:ktuaex1r(): [10442:28:225] Extension usn 3, ext 2, nex 3 2025-08-15 16:00:20.952123 :C01C8947:db_trace:ktusm.c@2117:ktusmasp(): [10445:28:225] des1:tsn:1 rdba:0x008113bd where: kdiwh22: kdifind 2025-08-15 16:00:20.970613 :C01C8948:db_trace:ktu.c@4871:ktuaex1r(): [10442:28:225] Extension usn 3, ext 3, nex 4 2025-08-15 16:00:20.970621 :C01C8949:db_trace:ktusm.c@2117:ktusmasp(): [10445:28:225] des1:tsn:1 rdba:0x00813b10 where: kdiwh22: kdifind 2025-08-15 16:00:21.532346 :C01C8962:db_trace:ktu.c@4871:ktuaex1r(): [10442:28:225] Extension usn 3, ext 4, nex 5 2025-08-15 16:00:21.532354 :C01C8963:db_trace:ktusm.c@2117:ktusmasp(): [10445:28:225] des1:tsn:1 rdba:0x00813a59 where: kdiwh22: kdifind 2025-08-15 16:00:22.134243 :C01C8984: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-08-15 16:00:22.180309 :C01C898C: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-08-15 16:00:22.180668 :C01C8994: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-08-15 16:00:22.180948 :C01C899C: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-08-15 16:00:22.180965 :C01C899F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-15 16:00:22.181028 :C01C89AB: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-08-15 16:00:22.184993 :C01C89B9:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 17:54:51.000433 :C0255B0B:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 17:54:50.993 2025-08-15 17:54:51.000434 :C0255B0C:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=20536 pso_num=28 pso_serial#=22 2025-08-15 17:54:51.000556 :C0255B0D:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=20536 (legacy spawn) 2025-08-15 17:54:51.007120 :C0255B0E: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-08-15 17:54:51.007259 :C0255B17: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-08-15 17:54:51.008094 :C0255B18:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 20:00:53.910656 :C02F3DB8:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 20:00:53.905 2025-08-15 20:00:53.910658 :C02F3DB9:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21440 pso_num=28 pso_serial#=23 2025-08-15 20:00:53.910786 :C02F3DBA:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=21440 osp_idx=26 osp_ver=228296 osp_pg=0 (spawn #492196) 2025-08-15 20:00:53.910786 :C02F3DBB:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-15 20:00:53.910787 :C02F3DBC:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=4 time=3968723204 2025-08-15 20:00:53.910787 :C02F3DBD:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-15 20:00:53.910787 :C02F3DBE:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-15 20:00:53.910787 :C02F3DBF:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-15 20:00:53.910788 :C02F3DC0:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-15 20:00:53.910788 :C02F3DC1:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-15 20:00:53.911259 :C02F3DC2: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-08-15 20:00:53.911347 :C02F3DD5: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-08-15 20:00:53.918943 :C02F3DD6: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-08-15 20:00:53.920046 :C02F3DDE: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-08-15 20:00:53.920588 :C02F3DE6: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-08-15 20:00:53.921067 :C02F3DEE: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-08-15 20:00:53.921501 :C02F3DF6: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-08-15 20:00:53.923997 :C02F3DFE: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-08-15 20:00:53.925119 :C02F3E06: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-08-15 20:00:53.975687 :C02F3E0E: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-08-15 20:00:53.976539 :C02F3E16: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-08-15 20:00:53.976859 :C02F3E1E: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-08-15 20:00:53.977077 :C02F3E26: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-08-15 20:00:53.978958 :C02F3E2E:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 21:00:01.808333 :C033D441:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 21:00:01.807 2025-08-15 21:00:01.808335 :C033D442:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=16832 pso_num=28 pso_serial#=24 2025-08-15 21:00:01.808465 :C033D443:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=16832 osp_idx=26 osp_ver=228297 osp_pg=0 (spawn #492332) 2025-08-15 21:00:01.808466 :C033D444:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-15 21:00:01.808466 :C033D445:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=5 time=3972271095 2025-08-15 21:00:01.808467 :C033D446:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-15 21:00:01.808467 :C033D447:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-15 21:00:01.808468 :C033D448:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-15 21:00:01.808468 :C033D449:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-15 21:00:01.808468 :C033D44A:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-15 21:00:01.808966 :C033D44B: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-08-15 21:00:01.809008 :C033D451: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-08-15 21:00:01.816205 :C033D45F: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-08-15 21:00:01.817239 :C033D467: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-08-15 21:00:01.817891 :C033D46F: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-08-15 21:00:01.818367 :C033D477: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-08-15 21:00:01.818813 :C033D47F: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-08-15 21:00:01.821255 :C033D487: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-08-15 21:00:01.822445 :C033D48F: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-08-15 21:00:01.873014 :C033D497: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-08-15 21:00:01.873904 :C033D49F: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-08-15 21:00:01.874133 :C033D4A7: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-08-15 21:00:01.874343 :C033D4AF: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-08-15 21:00:01.876155 :C033D4B7:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-15 22:00:02.062657 :C0387E4B:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-15 22:00:02.062 2025-08-15 22:00:02.062658 :C0387E4C:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=10620 pso_num=28 pso_serial#=25 2025-08-15 22:00:02.062810 :C0387E54:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=10620 osp_idx=26 osp_ver=228298 osp_pg=0 (spawn #492472) 2025-08-15 22:00:02.062811 :C0387E55:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-15 22:00:02.062812 :C0387E56:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=6 time=3975871361 2025-08-15 22:00:02.062812 :C0387E57:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-15 22:00:02.062813 :C0387E58:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-15 22:00:02.062813 :C0387E59:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-15 22:00:02.062814 :C0387E5A:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-15 22:00:02.062814 :C0387E5B:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-15 22:00:02.063308 :C0387E5C: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-08-15 22:00:02.068319 :C0387E81: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-08-15 22:00:02.068358 :C0387E84:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-08-15 22:00:02.073063 :C0387EB1:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-15 22:00:02.073654 :C0387EB2:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 5583120000000000 2025-08-15 22:00:02.075287 :C0387EE3: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-08-15 22:00:02.075373 :C0387EF0: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-08-15 22:00:02.075382 :C0387EF6:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-08-15 22:00:02.075387 :C0387EF7: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-08-15 22:00:02.075418 :C0387F04: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-08-15 22:00:02.076094 :C0387F17:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 234541943) 2025-08-15 22:00:02.076100 :C0387F18: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-08-15 22:00:02.076124 :C0387F23: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-08-15 22:00:02.076134 :C0387F2F:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65564 1) 2025-08-15 22:00:02.076137 :C0387F30: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-08-15 22:00:02.076164 :C0387F3C: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-08-15 22:00:02.076168 :C0387F44:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65564) 2025-08-15 22:00:02.076170 :C0387F48: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-08-15 22:00:02.076224 :C0387F73: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-08-15 22:00:02.077349 :C0388040: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-08-15 22:00:02.077375 :C0388051:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-15 22:00:02.078249 :C0388052:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 5683120000000000 2025-08-15 22:00:02.078667 :C0388053:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 234541943) 2025-08-15 22:00:02.078674 :C0388054: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-08-15 22:00:02.078703 :C038805F: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-08-15 22:00:02.087702 :C03880C2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-08-15 22:00:02.089632 :C03880C3: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-08-15 22:00:02.089695 :C03880C6: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-08-15 22:00:02.089797 :C03880D3: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-08-15 22:00:02.187150 :C03881B3: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 2025-08-15 22:00:04.025629 :C0388580: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 2025-08-15 22:00:04.494493 :C03885FE: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: 10620, J002)