Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250512080006\orcl_j000_10512_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:37421M/63366M, Ph+PgF:44736M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 10512, image: ORACLE.EXE (J000) *** 2025-05-12 08:00:06.565 *** SESSION ID:(193.6353) 2025-05-12 08:00:06.565 *** 2025-05-12 08:00:06.565 Process diagnostic dump for ORACLE.EXE (J000), OS id=10512, pid: 24, proc_ser: 145, sid: 193, sess_ser: 6353 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 10512 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=0.201840 sec, exc=0.201840 sec, total=0.201840 sec wait times: max=0.500000 sec, heur=11.745628 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=22 seq_num=23 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.000010 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=21 seq_num=22 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.000015 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=20 seq_num=21 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 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=19 seq_num=20 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 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=0.504586 sec, exc=0.504586 sec, total=0.504586 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=17 seq_num=18 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=16 seq_num=17 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.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 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.000013 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.510110 sec, exc=0.510110 sec, total=0.510110 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.499990 sec, exc=0.499990 sec, total=0.499990 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time Sampled Session History of session 193 serial 6353 --------------------------------------------------- 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 --------------------------------------------------- [12 samples, 07:59:54 - 08:00:06] idle wait at each sample [session created at: 07:59:54] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-12 08:00:06.565 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 10512, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-12 07:56:37.526665 :96013318:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:56:37.526835 :9601331E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:56:37.527665 :96013322:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:56:51.163310 :96013744:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:56:51.150 2025-05-12 07:56:51.163312 :96013745:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12352 pso_num=24 pso_serial#=125 2025-05-12 07:56:51.163448 :96013746:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12352 (legacy spawn) 2025-05-12 07:56:51.169815 :96013747:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:56:51.170007 :9601374C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:56:51.170803 :96013751:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:56:54.568099 :96013880:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:56:54.562 2025-05-12 07:56:54.568101 :96013881:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11988 pso_num=24 pso_serial#=126 2025-05-12 07:56:54.568235 :96013882:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=11988 osp_idx=22 osp_ver=257675 osp_pg=0 (spawn #173869) 2025-05-12 07:56:54.568236 :96013883:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-12 07:56:54.568237 :96013884:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=157 time=12424438 2025-05-12 07:56:54.568239 :96013885:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-12 07:56:54.568239 :96013886:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-12 07:56:54.568239 :96013887:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-12 07:56:54.568240 :96013888:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-12 07:56:54.568240 :96013889:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-12 07:56:54.568718 :9601388A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-12 07:56:54.569441 :9601389F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:56:54.580372 :960138BB:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-12 07:56:54.580883 :960138BC:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-12 07:56:54.583192 :960138BD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-05-12 07:56:54.583523 :960138BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:56:54.583557 :960138C1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-05-12 07:56:54.584409 :960138C7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:56:54.584531 :960138D0:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:57:24.670183 :9601421C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:57:25.431622 :9601423F:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:57:25.419 2025-05-12 07:57:25.431624 :96014240:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8180 pso_num=24 pso_serial#=127 2025-05-12 07:57:25.431763 :96014241:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=8180 (legacy spawn) 2025-05-12 07:57:25.438236 :96014242:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:25.438416 :9601424A:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:57:25.439229 :9601424C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:57:39.680932 :96014696:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:57:39.673 2025-05-12 07:57:39.680934 :96014697:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12176 pso_num=24 pso_serial#=128 2025-05-12 07:57:39.681072 :96014698:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12176 (legacy spawn) 2025-05-12 07:57:39.687529 :96014699:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:39.687703 :9601469E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:57:39.688508 :960146A3:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:57:45.611883 :96014875:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:57:45.604 2025-05-12 07:57:45.611885 :96014876:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11852 pso_num=24 pso_serial#=129 2025-05-12 07:57:45.612018 :96014877:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11852 (legacy spawn) 2025-05-12 07:57:45.618492 :96014878:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:45.618675 :9601487D:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:57:45.619515 :96014882:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:57:45.628176 :96014885:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:57:45.619 2025-05-12 07:57:45.628177 :96014886:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12528 pso_num=24 pso_serial#=130 2025-05-12 07:57:45.628323 :96014887:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12528 (legacy spawn) 2025-05-12 07:57:45.634792 :96014888:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:45.635028 :96014891:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:57:45.635854 :96014892:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:57:48.849881 :96014984:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:57:48.848 2025-05-12 07:57:48.849883 :96014985:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12292 pso_num=24 pso_serial#=131 2025-05-12 07:57:48.850014 :96014986:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12292 (legacy spawn) 2025-05-12 07:57:48.856366 :96014987:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:48.856540 :9601498C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:57:48.857315 :96014991:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:57:48.865897 :96014994:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:57:48.864 2025-05-12 07:57:48.865899 :96014995:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12084 pso_num=24 pso_serial#=132 2025-05-12 07:57:48.866040 :96014996:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12084 (legacy spawn) 2025-05-12 07:57:48.872502 :96014997:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:48.872670 :9601499F:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:57:48.873490 :960149A1:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:57:54.636353 :96014B7E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:57:54.630 2025-05-12 07:57:54.636355 :96014B7F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11236 pso_num=24 pso_serial#=133 2025-05-12 07:57:54.636494 :96014B80:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=11236 osp_idx=22 osp_ver=257682 osp_pg=0 (spawn #173871) 2025-05-12 07:57:54.636495 :96014B81:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-12 07:57:54.636495 :96014B82:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=158 time=12484500 2025-05-12 07:57:54.636496 :96014B83:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-12 07:57:54.636496 :96014B84:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-12 07:57:54.636497 :96014B85:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-12 07:57:54.636497 :96014B86:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-12 07:57:54.636497 :96014B87:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-12 07:57:54.637000 :96014B88:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-12 07:57:54.637704 :96014B9D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:54.645126 :96014BBA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-05-12 07:57:54.645480 :96014BBB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:54.645517 :96014BBE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-05-12 07:57:54.646482 :96014BC4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:57:54.646616 :96014BCD:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:58:24.749751 :960155A2:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:58:25.225676 :960155B1:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:58:25.213 2025-05-12 07:58:25.225678 :960155B2:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=3236 pso_num=24 pso_serial#=134 2025-05-12 07:58:25.225815 :960155B3:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=3236 (legacy spawn) 2025-05-12 07:58:25.232305 :960155B4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:58:25.232468 :960155B9:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:58:25.233297 :960155BE:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:58:25.241916 :960155C1:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:58:25.228 2025-05-12 07:58:25.241917 :960155C2:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12868 pso_num=24 pso_serial#=135 2025-05-12 07:58:25.242054 :960155C3:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12868 (legacy spawn) 2025-05-12 07:58:25.248523 :960155C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:58:25.248701 :960155CC:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:58:25.249481 :960155CE:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:58:33.686316 :9601586D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:58:33.677 2025-05-12 07:58:33.686318 :9601586E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9288 pso_num=24 pso_serial#=136 2025-05-12 07:58:33.686497 :9601586F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9288 (legacy spawn) 2025-05-12 07:58:33.692903 :96015870:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:58:33.693073 :96015875:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:58:33.693914 :9601587A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:58:41.930591 :96015A78:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:58:41.922 2025-05-12 07:58:41.930593 :96015A79:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10952 pso_num=24 pso_serial#=137 2025-05-12 07:58:41.930727 :96015A7A:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=10952 (legacy spawn) 2025-05-12 07:58:41.937175 :96015A7B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:58:41.937354 :96015A80:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:58:41.938185 :96015A91:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:58:54.720171 :96015ED5:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:58:54.714 2025-05-12 07:58:54.720173 :96015ED6:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=13076 pso_num=24 pso_serial#=138 2025-05-12 07:58:54.720311 :96015ED7:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=13076 osp_idx=22 osp_ver=257687 osp_pg=0 (spawn #173873) 2025-05-12 07:58:54.720312 :96015ED8:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-12 07:58:54.720312 :96015ED9:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=159 time=12544594 2025-05-12 07:58:54.720313 :96015EDA:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-12 07:58:54.720313 :96015EDB:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-12 07:58:54.720313 :96015EDC:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-12 07:58:54.720314 :96015EDD:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-12 07:58:54.720314 :96015EDE:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-12 07:58:54.720799 :96015EDF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-12 07:58:54.721498 :96015EF4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:58:54.732574 :96015F10:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-12 07:58:54.733045 :96015F11:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-12 07:58:54.735450 :96015F12:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-05-12 07:58:54.735787 :96015F13:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:58:54.735822 :96015F16:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-05-12 07:58:54.736677 :96015F1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:58:54.736805 :96015F24:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:59:24.836243 :96016897:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:59:34.713400 :96016B4F:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:59:34.699 2025-05-12 07:59:34.713402 :96016B50:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9208 pso_num=24 pso_serial#=139 2025-05-12 07:59:34.713549 :96016B51:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9208 (legacy spawn) 2025-05-12 07:59:34.720060 :96016B52:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:34.720246 :96016B5B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:59:34.721080 :96016B5C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:59:34.729951 :96016B5F:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:59:34.714 2025-05-12 07:59:34.729953 :96016B60:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11040 pso_num=24 pso_serial#=140 2025-05-12 07:59:34.730100 :96016B61:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11040 (legacy spawn) 2025-05-12 07:59:34.736788 :96016B62:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:34.736960 :96016B6B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:59:34.737816 :96016B6C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:59:37.831702 :96016C60:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:59:37.818 2025-05-12 07:59:37.831704 :96016C61:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11648 pso_num=24 pso_serial#=141 2025-05-12 07:59:37.831841 :96016C62:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11648 (legacy spawn) 2025-05-12 07:59:37.838289 :96016C63:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:37.838455 :96016C6C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:59:37.839239 :96016C6D:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:59:37.847860 :96016C70:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:59:37.834 2025-05-12 07:59:37.847862 :96016C71:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=3836 pso_num=24 pso_serial#=142 2025-05-12 07:59:37.847998 :96016C72:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=3836 (legacy spawn) 2025-05-12 07:59:37.854428 :96016C73:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:37.854593 :96016C7C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:59:37.855385 :96016C7D:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:59:41.775126 :96016D86:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:59:41.763 2025-05-12 07:59:41.775128 :96016D87:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11908 pso_num=24 pso_serial#=143 2025-05-12 07:59:41.775265 :96016D88:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11908 (legacy spawn) 2025-05-12 07:59:41.781885 :96016D89:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:41.782066 :96016D8F:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:59:41.782883 :96016D93:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:59:44.165573 :96016E73:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:59:44.157 2025-05-12 07:59:44.165575 :96016E74:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10872 pso_num=24 pso_serial#=144 2025-05-12 07:59:44.165712 :96016E75:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=10872 (legacy spawn) 2025-05-12 07:59:44.172204 :96016E76:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:44.172382 :96016E7F:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-12 07:59:44.173200 :96016E80:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-12 07:59:54.822224 :9601723A:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-12 07:59:54.816 2025-05-12 07:59:54.822226 :9601723B:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10512 pso_num=24 pso_serial#=145 2025-05-12 07:59:54.822361 :9601723C:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=10512 osp_idx=22 osp_ver=257694 osp_pg=0 (spawn #173876) 2025-05-12 07:59:54.822362 :9601723D:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-12 07:59:54.822362 :9601723E:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=160 time=12604688 2025-05-12 07:59:54.822363 :9601723F:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-12 07:59:54.822363 :96017240:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-12 07:59:54.822363 :96017241:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-12 07:59:54.822364 :96017242:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-12 07:59:54.822364 :96017243:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-12 07:59:54.822844 :96017244:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-12 07:59:54.823487 :96017259:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:54.831050 :96017275:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-05-12 07:59:54.831410 :96017276:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:54.831445 :96017279:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-05-12 07:59:54.832362 :9601727F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-12 07:59:54.832496 :96017288:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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 24 (osid: 10512, J000)