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@xxxxxxxxxx <l.flatz@xxxxxxxxxx>
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@xxxxxxxx
Datum : 14/10/2021 - 17:27 (MS)
An : oracle.developer35@xxxxxxxxx, andysayer@xxxxxxxxx
Cc : loknath.73@xxxxxxxxx, oracle-l@xxxxxxxxxxxxx
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@xxxxxxxxxxxxx [mailto:
oracle-l-bounce@xxxxxxxxxxxxx] *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@xxxxxxxxx> 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@xxxxxxxxx> 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@xxxxxxxxx> 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 | | | | | | |
| | | | |
| |
==============================================================================================================================================================================================================================================
