Re: Can this sql restarts by itself

From: Pap <oracle.developer35_at_gmail.com>
Date: Fri, 15 Oct 2021 20:49:07 +0530
Message-ID: <CAEjw_fiX85eTkz3DCGLHKrr+1+vwfxBg6jPY+JO91iTK2+W=Lw_at_mail.gmail.com>



  Thank you so much Maxim.

We have already killed the running session and also killed the session which was doing the drop historical partition ( and it was moving data to the archive table and compressing that too) , behind the scenes. So in short the drop historical partition script was taking time for each of the partitions to be dropped. And also during collecting details from v$sql i didn't look into the invalidation count, so at present i don't have any runtime statistics rather the historical stats available with me from AWR views. So I just had a look into dba_hist_active_sess_history for that sql_id, but not seeing any such column which will say about the number of cursor invalidation and will prove that we have hit the bug. But it's clear from that , we have hot ~65+ times the same sql executed that day as it has all different sql_exec_ids.

But then I saw the dba_hist_sqlstat for that sql_id, and I see there are a total ~18 AWR snaps captured in that and Only one entry shows the execution_total and execution_delta column value as '1' and others showing '0'. However if i sum up the sum(loads_total) column value for all those ~18 snaps its coming as ~424 and SUM(INVALIDATION_TOTAL) coming as ~420 , sum(INVALIDATION_DELTA ) coming as ~18, sum(loads_delta) coming as '0' (not sure why). Is it sufficient evidence to prove that we were hitting the bug which you pointed out to? And in our case the cursor invalidation was happening because of the drop historical partition DDL script which kept doing the cleanup for 1000+ partitions one by one in parallel.

Regards
Pap

On Fri, Oct 15, 2021 at 1:06 PM Maxim <mdemenko_at_gmail.com> wrote:

> Hi,
> we hit the situation similar to what you described once ago on 11.2.0.4
> either. I found the description of the problem by Randolf Geist
>
>
> https://oracle-randolf.blogspot.com/2016/01/dml-operations-on-partitioned-tables.html
>
> - shortly - yes , the dml operations can (at least - could on 11.2.0.4 ,
> haven't tested it on recent versions) restart, if their target is
> partitioned table and the cursor gets invalidated (for any reason, e.g. -
> statistic gathering can be one of the reasons).
>
> Regards
>
> Maxim
>
> On Wed, Oct 13, 2021 at 9:56 PM 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-l
Received on Fri Oct 15 2021 - 17:19:07 CEST

Original text of this message