Re: RE: Can this sql restarts by itself

  • From: "l.flatz@xxxxxxxxxx" <l.flatz@xxxxxxxxxx>
  • To: mwf@xxxxxxxx
  • Date: Fri, 15 Oct 2021 10:34:54 +0200 (CEST)

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
p.MsoNormal, li.MsoNormal, div.MsoNormal {
        margin: 0.0in;
        margin-bottom: 1.0E-4pt;
        font-size: 12.0pt;
        font-family: "Times New Roman" , serif;
}
a:link, span.MsoHyperlink {
        mso-style-priority: 99;
        color: blue;
        text-decoration: underline;
}
a:visited, span.MsoHyperlinkFollowed {
        mso-style-priority: 99;
        color: purple;
        text-decoration: underline;
}
p {
        mso-style-priority: 99;
        mso-margin-top-alt: auto;
        margin-right: 0.0in;
        mso-margin-bottom-alt: auto;
        margin-left: 0.0in;
        font-size: 12.0pt;
        font-family: "Times New Roman" , serif;
}
span.EmailStyle18 {
        mso-style-type: personal-reply;
        font-family: Calibri , sans-serif;
        color: rgb(31,73,125);
}
*.MsoChpDefault {
        mso-style-type: export-only;
        font-family: Calibri , sans-serif;
}
div.WordSection1 {
        page: WordSection1;
}
 
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 |           |        |       |          |       |       |       |   
    |     |      |          |                                     |          |
==============================================================================================================================================================================================================================================
   
 
            
          
         
        
       
      
     
    
   
  
 

Other related posts: