In AWR analysis, what appears to be the root cause of the issue, can easily turn out to be just a symptom. Last week, Rajat sent me an AWR report which is a perfect illustration of this (thanks Rajat), I posted the key sections from this report below (sorry for less than perfect formatting — I had to manually re-format the HTML version of the report into text).
WORKLOAD REPOSITORY report for
DB Name DB Id Instance Inst num Release RAC Host
DSS 37220993 dss 1 10.2.0.4.0 NO dssdbnz
Snap Id Snap Time Sessions Cursors/Session
Begin Snap: 18471 12-Oct-12 08:30:28 131 1.5
End Snap: 18477 12-Oct-12 14:30:24 108 1.8
Elapsed: 359.93 (mins)
DB Time: 25,730.14 (mins)
Load Profile
Per Second Per Transaction
Redo size: 325,282.85 103,923.02
Logical reads: 33,390.52 10,667.77
Block changes: 1,307.95 417.87
Physical reads: 1,927.33 615.75
Physical writes: 244.65 78.16
User calls: 391.34 125.03
Parses: 68.14 21.77
Hard parses: 3.33 1.06
Sorts: 47.86 15.29
Logons: 3.15 1.01
Executes: 234.32 74.86
Transactions: 3.13
% Blocks changed per Read: 3.92 Recursive Call %: 61.11
Rollback per transaction %: 24.71 Rows per Sort: 3325.52
Top 5 Timed Events
Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class
free buffer waits 10,726,838 344,377 32 22.3 Configuration
db file sequential read 6,122,262 335,366 55 21.7 User I/O
db file scattered read 3,597,607 305,576 85 19.8 User I/O
CPU time 161,491 10.5
read by other session 2,572,875 156,821 61 10.2 User I/O
Operating System Statistics
Statistic Total
AVG_BUSY_TIME 2,093,109
AVG_IDLE_TIME 63,212
AVG_IOWAIT_TIME 18,463
AVG_SYS_TIME 87,749
AVG_USER_TIME 2,004,722
BUSY_TIME 16,749,988
IDLE_TIME 510,692
IOWAIT_TIME 152,594
SYS_TIME 707,137
USER_TIME 16,042,851
LOAD 4
OS_CPU_WAIT_TIME ###############
RSRC_MGR_CPU_WAIT_TIME 0
VM_IN_BYTES 5,503,492,096
VM_OUT_BYTES 2,054,414,336
PHYSICAL_MEMORY_BYTES 34,288,209,920
NUM_CPUS 8
NUM_CPU_SOCKETS 8
Continue reading “CPU starvation disguised as an I/O issue (yet another AWR case study)”
Oracle Diagnostician 