I am using version- 11.2.0.4 of oracle.
I have a query running and its getting slow down during specific time period of the day(10PM to 9AM) which i can also verify from the data present in DBA_HIST_SQLSTAT. The number of rows processed getting decreased from ~25million to ~15k during those snap duartion(we have ~1hrs snap duration).So i wanted to understand what must be causing this? Is the database getting I/O bound during that period and that is the reason query startin to crawl? on 24th it started and also ran sucessfully ending on 25th but on 28th it started again and failed due to less throughput for specific duration.
I have verified the overall wait event pattern for the database from AWR views for the whole duration but i am not seeing anything(any specific wait event) matching with the slowness pattern.
Below is the details from the DBA_HIST_SQLSTAT which i have fetched.
MSEC_EXEC=SUM (ELAPSED_TIME_delta) / GREATEST (SUM (executions_delta))/1000000/60
Below is the part of the real time monitoring plan for the failed query(snashot too old error) after running long hours, which shows considerable amount of time its just waiting for I/O. Now i digged down to the waitevents from AWR views but not getting matched with the attern.
Global Information
------------------------------
Status : DONE (ERROR)
Execution Started : 12/28/2016 16:25:32
First Refresh Time : 12/28/2016 16:26:06
Last Refresh Time : 12/29/2016 10:38:39
Duration : 65587s
Fetch Calls : 419280
Global Stats
==============================================================================
| Elapsed | Cpu | IO | Concurrency | Fetch | Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes |
==============================================================================
| 64469 | 5052 | 59415 | 1.47 | 419K | 54M | 41M | 311GB |
==============================================================================
===============================================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | (Max) | (%) | (# samples) |
===============================================================================================================================================================================================================
| 0 | SELECT STATEMENT | | | | 65191 | +34 | 1 | 101M | | | | 0.41 | Cpu (24) |
| | | | | | | | | | | | | | SQL*Net more data to client (7) |
| 1 | TABLE ACCESS BY LOCAL INDEX ROWID | A | 1 | 1356 | 65191 | +34 | 1 | 101M | 18M | 135GB | | 35.58 | Cpu (194) |
| | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | db file sequential read (2523) |
| | | | | | | | | | | | | | read by other session (1) |
| 2 | NESTED LOOPS | | 1 | 24175 | 65191 | +34 | 1 | 219M | | | | 0.08 | Cpu (6) |
| 3 | MERGE JOIN CARTESIAN | | 6 | 16310 | 63151 | +34 | 1 | 11123 | | | | | |
| 4 | MERGE JOIN CARTESIAN | | 179 | 15952 | 63151 | +34 | 1 | 11123 | | | | | |
| 5 | MERGE JOIN CARTESIAN | | 1 | 5 | 1 | +34 | 1 | 1 | | | | | |
| 6 | NESTED LOOPS | | 1 | 3 | 1 | +34 | 1 | 1 | | | | | |
| 7 | TABLE ACCESS BY INDEX ROWID | B | 1 | 1 | 1 | +34 | 1 | 1 | | | | | |
| 8 | INDEX UNIQUE SCAN | B_PK | 1 | | 65554 | +34 | 1 | 1 | | | | | |
| 9 | SORT UNIQUE | | 1 | 2 | 1 | +34 | 1 | 1 | | | | | |
| 10 | TABLE ACCESS BY INDEX ROWID | C | 1 | 2 | 1 | +34 | 1 | 1 | | | | | |
| 11 | INDEX RANGE SCAN | C_PK | 1 | 1 | 1 | +34 | 1 | 1 | | | | | |
| 12 | BUFFER SORT | | 1 | 3 | 1 | +34 | 1 | 1 | | | | | |
| 13 | SORT UNIQUE | | 1 | 2 | 1 | +34 | 1 | 1 | | | | | |
| 14 | TABLE ACCESS BY INDEX ROWID | C | 1 | 2 | 1 | +34 | 1 | 1 | | | | | |
| 15 | INDEX RANGE SCAN | C_PK | 1 | 1 | 1 | +34 | 1 | 1 | | | | | |
| 16 | BUFFER SORT | | 149K | 15950 | 63151 | +34 | 1 | 11123 | | | 2M | | |
| 17 | TABLE ACCESS BY INDEX ROWID | D | 149K | 15947 | 1 | +34 | 1 | 27920 | | | | | |
| 18 | INDEX RANGE SCAN | D_IX1 | 596K | 2017 | 1 | +34 | 1 | 30115 | | | | | |
| 19 | BUFFER SORT | | 1 | 363 | 63151 | +34 | 11123 | 11123 | | | | | |
| 20 | SORT UNIQUE | | 1 | 2 | 1 | +34 | 1 | 1 | | | 2048 | | |
| 21 | TABLE ACCESS BY INDEX ROWID | C | 1 | 2 | 1 | +34 | 1 | 1 | | | | | |
| 22 | INDEX RANGE SCAN | C_PK | 1 | 1 | 1 | +34 | 1 | 1 | | | | | |
| 23 | PARTITION RANGE ITERATOR | | 707 | 1302 | 65191 | +34 | 11123 | 219M | | | | 0.03 | Cpu (2) |
| 24 | INDEX RANGE SCAN | A_KEY1 | 707 | 1302 | 65554 | +34 | 11123 | 219M | 23M | 175GB | | 63.91 | latch: cache buffers chains (1) |
| | | | | | | | | | | | | | Cpu (288) |
| | | | | | | | | | | | | | db file sequential read (4488) |
| | | | | | | | | | | | | | read by other session (107) |
===============================================================================================================================================================================================================