Re: RE: Can this sql restarts by itself
Date: Fri, 15 Oct 2021 21:01:20 +0530
Message-ID: <CAEjw_fha-xVxDhDRAhrNA055sRzpuZ9POPwMZvmYOmjJz1zUqA_at_mail.gmail.com>
I query those columns from dba_hist_active_sess_history as below for that sql_id, and I am seeing the MAIN_PROC which is coming in all of those executions for all of those different sql_exec_ids. I hope this is the correct way of querying the plsql_entry_object_id column. So if it's correct then, it's confirmed that it has been called from within the PROC2 which is called inside from the MAIN_PROC only but not from any other procedure/packages. And as i said, that main proc has only been invoked once during that whole issue period. And i have captured sql_monitor that wrapper plsql/main_proc too.
( SELECT object_name FROM dba_procedures WHERE object_id = plsql_entry_object_id AND subprogram_id = 0) AS plsql_object
, ( SELECT procedure_name FROM dba_procedures WHERE object_id = plsql_entry_object_id AND subprogram_id = plsql_entry_subprogram_id) AS plsql_subprogram
On Fri, Oct 15, 2021 at 2:04 PM l.flatz_at_bluewin.ch <l.flatz_at_bluewin.ch> wrote:
> Hi,
>
> dba_hist_active_session_history will hold a top_level_sql_id and a
> PLSQL_entry_id and some similar information.
> Maybe that will help to shed some light on the case.
>
> Regards
>
> Lothar
>
> ----Ursprüngliche Nachricht----
> Von : mwf_at_rsiz.com
> Datum : 14/10/2021 - 17:27 (MS)
> An : oracle.developer35_at_gmail.com, andysayer_at_gmail.com
> Cc : loknath.73_at_gmail.com, oracle-l_at_freelists.org
> Betreff : RE: Can this sql restarts by itself
>
> Now you need to look for everything that calls that procedure, and the
> odds on favorite is that when it catches a failure status return, it
> (silently?) retries it.
>
>
>
> *From:* oracle-l-bounce_at_freelists.org [mailto:
> oracle-l-bounce_at_freelists.org] *On Behalf Of *Pap
> *Sent:* Thursday, October 14, 2021 5:17 AM
> *To:* Andy Sayer
> *Cc:* Lok P; Oracle L
> *Subject:* Re: Can this sql restarts by itself
>
>
>
> Thank You Andy. Unfortunately that session has been killed now and I was
> monitoring during run time but was not aware that the sql monitor can be
> fetched based on sql_exec_id and considering its 11.2 that is no sql
> monitor history also available. But i got your point , that in case this
> must be failing and retriggering ten the execution count in the
> v$sql/dba_hist_sqlstat won't increase.
>
>
>
> I am not sure if this will make any difference but this INSERT was getting
> executed by the "execute immediate" statement from the plsql proc. But i
> was trying to see, just in case this insert is failing after a few times
> (say 10+minutes) it should throw the error to the 'when others' block which
> is outside the loop. No exception handling is done inside the loop. And
> also I was able to see the sql_monitor report of the main_proc which was
> showing a single execution running over 6hrs+ span duration, which means
> the main_proc was definitely just called once only. And the PROC2 call is
> not inside any loop.
>
>
>
> Below is the basic block, i have removed detail logic from it. But from
> this exception handling , it/PROC2 should not rerun automatically in case
> of failure of the Insert query which is called within it.
>
>
>
> procedure PROC2(.......)
> is
> rsql Varchar2(4000) := 'select .........';
> myrec sys_refcursor;
> insertSqlprefix varchar2(2000) := 'insert into TAB1 ......';
> BEGIN
> open myrec for rsql using IN_DATE;
> LOOP
> FETCH myrec into .......;
> EXIT WHEN myrec%NOTFOUND;
> rerunFlag := null;
> raiseExcpFlag := 'N';
> .........
> ...........
> addsql := ' select .......' ;
> execute immediate insertSqlprefix || addsql using id, cby;
> COMMIT;
> end if;
> end loop;
> EXCEPTION
> when OTHERS then
> PKG1.updatelog(logid, 'FAIL');
> raise_application_error (-20002,'An error has occurred running
> PROC2: '||SQLCODE||' -ERROR- '||SQLERRM);
> END PROC2;
> /
>
>
>
> procedure MAIN_PROC(...... )
> is
> ....................
> BEGIN
> ...............
>
> IF lrtyp !='XXX' THEN
> PROC2(IN_DATE, logid, IN_DATE, lctyp, lrtyp);
> END IF;
> commit;
> Exception
> when others then
> dbms_output.put_line ('Oracle error code : ' ||
> to_char(sqlcode));
> dbms_output.put_line ('Oracle error message : ' ||
> substr(sqlerrm,1,200));
> ROLLBACK;
> updateRunLogEntry(logid, FAIL);
> raise_application_error (-20002,'An error has occurred runing
> MAIN_PROC: '||SQLCODE||' -ERROR- '||SQLERRM);
> END MAIN_PROC;
>
> /
>
>
>
>
>
>
>
> On Thu, Oct 14, 2021 at 1:15 PM Andy Sayer <andysayer_at_gmail.com> wrote:
>
> Hi,
>
>
>
> Different sql_exec_id means that it’s being called multiple times, this
> isn’t traditional SQL restarts but most likely being called again by the
> user code.
>
>
>
> You should be able to pull out the previous executions of the SQL by
> providing their sql_exec_id to your SQL monitor query. Are they completing
> or are they failing?
>
>
>
> Your SQL is being executed from plsql, would be worth looking at that
> code. My guess is something in the exception clause causing it to retry
> itself.
>
>
>
> Thanks,
>
> Andy
>
>
>
>
>
>
>
> On Thu, 14 Oct 2021 at 06:09, Lok P <loknath.73_at_gmail.com> wrote:
>
> I have experienced a similar situation and also it's well noted in
> Jonathan's blog below regarding how a UPDATE having a full scan in its
> execution path can restart itself. But if i remember correctly the sql
> monitor used to be the same just that the Execs column used to increase
> pointing to increase in number of tablescans. But here in your case , you
> have noted a whole new set of sql_exec_ids(which mean new sql monitors
> altogether), so I am not sure if an INSERT can show symptoms when
> its historical partitions are being dropped . In an ideal scenario a
> partition with all local indexes should not cause any issue for other DMLS
> which are happening on other partitions even at the same time. But yes the
> executions count should have been increased to more than 1, in gv$sql and
> dba_hst_sqlstat considering your query ran for 10+ minutes each
> time/iteration before it changes the sql_exec_id. From your plan it seems
> INSERT as a SELECT query, and that to operate in parallel, so not sure if
> that can cause such a thing. Others can comment.
>
>
>
> https://jonathanlewis.wordpress.com/2019/09/10/update-restarts/
>
>
>
> Regards
>
> Lok
>
>
>
> On Thu, Oct 14, 2021 at 1:26 AM Pap <oracle.developer35_at_gmail.com> wrote:
>
> Hello Listers, We have a 11.2.0.4 customer database executing plsql
> procedure. And below INSERT seems to keep coming with new sql_exec_id and
> sql_exec_start whereas it's not inside any looping kind of logic. So we
> were wondering why the same sqls execute so many times. As per
> dba_hist_active_sess_history it has already completed ~25+ executions as we
> see ~25different different sql_exec_id and sql_exec_start for all of those
> executions, each running for ~10minutes+ sequentially one after other,
> without any gap. But then I noticed the v$sql showing executions as 0 and
> even dba_hist_sqlstat also showing as 1 for this same sql_id. We do have a
> session running in parallel, dropping historical partitions from the same
> table to which this below query inserting data into, but this insert is
> happening into the live partition. So are we hitting any related bugs here?
> And if it's the same, sql is restarting and not really moving , is there
> any other way to confirm?
>
>
>
> The sql monitor looks something like below
>
>
>
> Global Information
> ------------------------------
> Status : EXECUTING
> Instance ID : 1
> SQL Execution ID : 16777240
> Execution Started : 10/13/2021 11:55:14
> First Refresh Time : 10/13/2021 11:55:17
> Last Refresh Time : 10/13/2021 11:59:13
> Duration : 241s
> PLSQL Entry Ids (Object/Subprogram) : 161298,9
> PLSQL Current Ids (Object/Subprogram) : 161298,15
>
> Global Stats
>
> =========================================================================================================================
> | Elapsed | Cpu | IO | Application | Concurrency | PL/SQL |
> Buffer | Read | Read | Write | Write | Cell |
> | Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Time(s) |
> Gets | Reqs | Bytes | Reqs | Bytes | Offload |
>
> =========================================================================================================================
> | 243 | 53 | 190 | 0.08 | 0.00 | 0.36 |
> 5M | 42591 | 39GB | 163 | 19MB | |
>
> =========================================================================================================================
>
> SQL Plan Monitoring Details (Plan Hash Value=3677945390)
>
> ==============================================================================================================================================================================================================================================
> | Id | Operation | Name
> | Rows | Cost | Time | Start | Execs | Rows | Read | Read |
> Write | Write | Mem | Temp | Activity | Activity Detail
> | Progress |
> | | |
> | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes |
> Reqs | Bytes | | | (%) | (# samples)
> | |
>
> ==============================================================================================================================================================================================================================================
> | 0 | INSERT STATEMENT |
> | | | | | 1 | | | |
> | | | | |
> | |
> | 1 | LOAD TABLE CONVENTIONAL |
> | | | | | 1 | | | |
> | | | | |
> | |
> | 2 | SEQUENCE | TAB1_SEQ
> | | | | | 1 | | | |
> | | | | |
> | |
> | 3 | PX COORDINATOR FORCED SERIAL |
> | | | | | 1 | | | |
> | | | | |
> | |
> | 4 | PX SEND QC (RANDOM) | :TQ10001
> | 3314 | 110K | | | 1 | | | |
> | | | | |
> | |
> | 5 | HASH JOIN |
> | 3314 | 110K | 231 | +7 | 1 | 0 | | |
> 154 | 18MB | 2M | 21M | |
> | |
> | 6 | PX BLOCK ITERATOR |
> | 8262 | 110K | 231 | +7 | 1 | 158K | | |
> | | | | |
> | |
> | -> 7 | TABLE ACCESS STORAGE FULL | TAB2
> | 8262 | 110K | 239 | +2 | 13 | 158K | 39391 | 38GB |
> | | | | 99.58 | Cpu (42)
> | 100% |
> | | |
> | | | | | | | | |
> | | | | | cell multiblock physical read (196)
> | |
> | 8 | BUFFER SORT |
> | | | | | | | | |
> | | | | |
> | |
> | 9 | PX RECEIVE |
> | 60 | 1 | | | | | | |
> | | | | |
> | |
> | 10 | PX SEND BROADCAST | :TQ10000
> | 60 | 1 | | | | | | |
> | | | | |
> | |
> | 11 | INDEX SKIP SCAN | IDX_TAB3
> | 60 | 1 | | | | | | |
> | | | | |
> | |
> ==============================================================================================================================================================================================================================================
>
>
>
>
>
>
-- http://www.freelists.org/webpage/oracle-lReceived on Fri Oct 15 2021 - 17:31:20 CEST