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@xxxxxxxxx> 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@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 | | | | | | |
| | | | |
| |
==============================================================================================================================================================================================================================================
