This is classic case when same Update runs from multiple Instance in RAC at same time and Execution plan is worst of all. this will create Heavy block contention.
These wait events used to be "buffer busy" in 10g but in 11g It has splited and granual at detail level.
we first analyzed AWR from all 3 Nodes for same Time frame and we found that "GC buffer busy acquire" and " Read by another session"
ON INSTANCE 1
ON INSTANCE 2
ON INSTANCE 3
So I ran few queries which can tell us more about what happen during this time-frame.
You may also find this query at
Daily Performance Report.
SELECT sql_id,
text,
elapsed_time,
CPU_TIME,
EXECUTIONS,
round(elapsed_time/Executions,0) avg_elp_time,
PX_SERVERS,
DISK_READ_BYTES,
DISK_WRITE_BYTES,
IO_INTERCONNECT_BYTES,
OFFLOAD_ELIGIBLE_BYTES,
CELL_SMART_SCAN_ONLY_BYTES,
FLASH_CACHE_READS,
ROWS_PROCESSED
FROM (SELECT x.sql_id,
SUBSTR ( dhst.sql_text, 1, 30) text,
ROUND ( x.elapsed_time / 1000000,0) elapsed_time,
ROUND ( x.cpu_time / 1000000,0) CPU_TIME,
x.executions_delta EXECUTIONS,
ROUND (X.DISK_READ_BYTES/1048576,0) DISK_READ_BYTES,
ROUND (X.DISK_WRITE_BYTES/1048576,0) DISK_WRITE_BYTES,
ROUND (X.IO_INTERCONNECT_BYTES/1048576,0) IO_INTERCONNECT_BYTES,
ROUND (X.OFFLOAD_ELIGIBLE_BYTES/1048576,0) OFFLOAD_ELIGIBLE_BYTES,
X.FLASH_CACHE_READS FLASH_CACHE_READS,
ROUND (X.cell_smart_scan_only_BYTES/1048576,0) CELL_SMART_SCAN_ONLY_BYTES,
(x.ROWS_PROCESSED) ROWS_PROCESSED,
(X.PX_SERVERS) PX_SERVERS,
row_number () OVER (PARTITION BY x.sql_id ORDER BY 0) rn
FROM dba_hist_sqltext dhst,
(SELECT dhss.sql_id sql_id,
SUM (dhss.cpu_time_delta) cpu_time,
SUM (dhss.elapsed_time_delta) elapsed_time,
SUM (dhss.executions_delta) executions_delta,
SUM (dhss.PHYSICAL_READ_BYTES_DELTA) DISK_READ_BYTES,
SUM (dhss.PHYSICAL_WRITE_BYTES_DELTA) DISK_WRITE_BYTES,
SUM (dhss.IO_INTERCONNECT_BYTES_DELTA) IO_INTERCONNECT_BYTES,
SUM (dhss.IO_OFFLOAD_ELIG_BYTES_DELTA) OFFLOAD_ELIGIBLE_BYTES,
SUM (dhss.OPTIMIZED_PHYSICAL_READS_DELTA) FLASH_CACHE_READS,
SUM (dhss.IO_OFFLOAD_RETURN_BYTES_DELTA) cell_smart_scan_only_BYTES,
SUM (dhss.ROWS_PROCESSED_DELTA) ROWS_PROCESSED,
SUM (dhss.PX_SERVERS_EXECS_DELTA) PX_SERVERS
FROM dba_hist_sqlstat dhss
WHERE dhss.snap_id IN
(SELECT snap_id
FROM dba_hist_snapshot
-----change snap_id here.
WHERE SNAP_ID > 31822 AND SNAP_ID<= 31826)
GROUP BY dhss.sql_id) x
WHERE x.sql_id = dhst.sql_id
AND ROUND ( x.elapsed_time / 1000000, 3) > 3600)
WHERE rn = 1 and EXECUTIONS> 0
ORDER BY ELAPSED_TIME DESC;
---output
SQL_ID TEXT ELAPSED_TIME CPU_TIME EXECUTIONS AVG_ELP_TIME PX_SERVERS DISK_READ_BYTES DISK_WRITE_BYTES IO_INTERCONNECT_BYTES OFFLOAD_ELIGIBLE_BYTES CELL_SMART_SCAN_ONLY_BYTES FLASH_CACHE_READS ROWS_PROCESSED
------------- ------------------------------ ------------- --------- ----------- ------------ ------------ ---------------- ---------------- --------------------- ---------------------- -------------------------- -------------------- --------------
6vbxrnpxwc1mz BEGIN Sp_XYZ_DUMMY_Reversa 53686 830 98 548 0 344717 0 344824 0 107 0 98
g25x6rr6x4yv7 UPDATE ABC_DUMMY_XYZACTION 44306 571 88 503 0 30440 0 30426 0 -14 0 88
74d8zqzh802xq SELECT MAX (BUSINESS_DATE || B 42335 186 14930 3 0 8293 0 8293 0 0 0 14921
g75678tr0ddmw BEGIN SP_PASSIVEPERIOD_CALC(:1 30266 150 10679 3 0 5567 0 5567 0 0 0 10678
cpz2fp6466vus SELECT CPT_TOTALHOLD_AMT FROM 9040 255 211 43 0 314231 0 314231 0 0 0 209
7d4xjr17waxy7 BEGIN SP_CARD_ISSUENCE_SRT_TO_ 4701 533 107 44 0 164865 0 164865 0 0 0 103
c8hgnxkkr7jvz SELECT abc_ROW_ID, abc_SSNFAIL 4685 532 103 45 0 164861 0 164861 0 0 0 103
For Top Hot object by Physical Read. (Hot Object)
SELECT * FROM (
SELECT do.OWNER||'.'||do.OBJECT_NAME||'..['||do.OBJECT_TYPE||']' AS OBJECTS,
DHSS.INSTANCE_NUMBER AS INST,
SUM(DHSS.LOGICAL_READS_DELTA) LOGICAL_READ,
SUM(DHSS.PHYSICAL_READS_DELTA) PHY_READ,
SUM(DHSS.PHYSICAL_WRITES_DELTA) PHY_WRIT,
SUM(DHSS.ITL_WAITS_DELTA) ITL_WT,
SUM(DHSS.ROW_LOCK_WAITS_DELTA) ROW_LCK_WT
from dba_hist_seg_stat DHSS, DBA_OBJECTS DO
WHERE SNAP_ID > 31822 AND SNAP_ID<= 31826
--WHERE DHSS.SNAP_ID > 20135 AND DHSS.SNAP_ID<= 20183
AND DHSS.OBJ#=DO.OBJECT_ID
group by do.OWNER||'.'||do.OBJECT_NAME||'..['||do.OBJECT_TYPE||']',DHSS.INSTANCE_NUMBER
order BY PHY_READ DESC
) WHERE ROWNUM <=40;
OBJECTS INST LOGICAL_READ PHY_READ PHY_WRIT ITL_WT ROW_LCK_WT
-------------------------------------------------- ----- -------------------- -------------------- ----------- -------- ----------
corpABC.ABC_DUMMY_XYZACTION..[TABLE] 2 22388144 16357126 1797 0 0
corpABC.ABC_DUMMY_XYZACTION..[TABLE] 1 19444032 14708504 2055 0 0
corpABC.ABC_DUMMY_XYZACTION..[TABLE] 3 16945392 12908672 1367 0 0
corpABC.ABC_CAF_INFO_ENTRY..[TABLE] 1 7789840 7788316 98 0 0
corpABC.ABC_CAF_INFO_ENTRY..[TABLE] 2 6969952 6968505 97 0 0
corpABC.ABC_CAF_INFO_ENTRY..[TABLE] 3 6354976 6353643 104 0 0
corpABC.ABC_APPL_PAN..[TABLE] 3 1149808 1069323 227 0 0
corpABC.ABC_APPL_PAN..[TABLE] 2 903440 803870 256 0 0
corpABC.XYZACTIONLOG..[TABLE] 3 1867424 629380 689 0 0
corpABC.XYZACTIONLOG..[TABLE] 1 1197310176 436078 723 0 0
corpABC.XYZACTIONLOG..[TABLE] 2 1909632 372565 1255 0 0
SQL_ID affected by "gc buffer busy acquire"
SQL> SELECT INSTANCE_NUMBER,SQL_ID,COUNT(EVENT) FROM DBA_HIST_ACTIVE_SESS_HISTORY WHERE SNAP_ID > 31822 AND SNAP_ID<= 31826 AND EVENT LIKE '%busy acquire%' group by sql_id,INSTANCE_NUMBER order by 2 desc;
INSTANCE_NUMBER SQL_ID COUNT(EVENT)
------------- ------------- --------------------
3 g25x6rr6x4yv7 619
2 g25x6rr6x4yv7 548
1 g25x6rr6x4yv7 192
SQL_ID affected by "read by other session"
SQL> SELECT SQL_ID,COUNT(EVENT) FROM DBA_HIST_ACTIVE_SESS_HISTORY WHERE SNAP_ID > 31822 AND SNAP_ID<= 31826 AND EVENT LIKE '%read by%' group by sql_id order by 2 desc;
INSTANCE_NUMBER SQL_ID COUNT(EVENT)
------------- ------------- --------------------
3 g25x6rr6x4yv7 764
2 g25x6rr6x4yv7 658
1 g25x6rr6x4yv7 169
Now lets see what is plan of Most affected SQL_ID '
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_AWR('g25x6rr6x4yv7'));
--------------------
UPDATE ABC_DUMMY_XYZACTION SET ABC_TOTALHOLD_AMT = TRIM(TO_CHAR(:B4, '77777777777')), ABC_DUMMY_VALIDFLAG = 'N',
ABC_XYZACTION_FLAG = 'R' WHERE ABC_RRN = :B3 AND ABC_TXN_DATE = :B2 AND ABC_INST_CODE = :B1
Plan hash value: 4161612620
----------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------------
| 0 | UPDATE STATEMENT | | | | 12704 (100)| |
| 1 | UPDATE | ABC_DUMMY_XYZACTION | | | | |
| 2 | TABLE ACCESS FULL| ABC_DUMMY_XYZACTION | 1 | 106 | 12704 (1)| 00:02:33 |
----------------------------------------------------------------------------------------------
And Of-course it will generate GC wait event. As you see "corp.ABC.ABC_DUMMY_XYZACTION" is top Objects for Physical Reads. We created index on few columns which solved issue.
