New AWR Report Format: Oracle 11.2.0.4 and 12c
July 23, 2014 2 Comments
This is a post about Oracle Automatic Workload Repository (AWR) Reports. If you are an Oracle professional you doubtless know what these are – and if you have to perform any sort of performance tuning as part of your day job it’s likely you spend a lot of time immersed in them. Goodness knows I do – a few weeks ago I had to analyse 2,304 of them in one (long) day. But for anyone else, they are (huge) reports containing all sorts of information about activities that happened between two points of time on an Oracle instance. If that doesn’t excite you now, please move along – there is nothing further for you here.
AWR Reports have been with us since the introduction of the Automatic Workload Repository back in 10g and can be considered a replacement for the venerable Statspack tool. Through each major incremental release the amount of information contained in an AWR Report has grown; for instance, the 10g reports didn’t even show the type of operating system, but 11g reports do. More information is of course a good thing, but sometimes it feels like there is so much data now it’s hard to find the truth hidden among all the distractions.
I recently commented in another post about the change in AWR report format introduced in 11.2.0.4. This came as a surprise to me because I cannot previously remember report formatting changing mid-release, especially given the scale of the change. Not only that, but I’m sure I’ve seen reports from 11.2.0.3 in the new format too (implying it was added via a patch set update), although I can’t find the evidence now so am forced to concede I may have imagined it. The same new format also continues into 12.1.0.1 incidentally.
The 11.2.0.4 New Features document doesn’t mention anything about a new report format. I can’t find anything about it on My Oracle Support (but then I can never find anything about anything I’m looking for on MOS these days). So I’m taking it upon myself to document the new format and the changes introduced – as well as point out a nasty little issue that’s caught me out a couple of times already.
Comparing Old and New Formats
From what I can tell, all of the major changes except one have taken place in the Report Summary section at the start of the AWR report. Oracle appears to have re-ordered the subsections and added a couple of new ones:
- Wait Classes by Total Wait Time
- IO Profile
The new Wait Classes section is interesting because there is already a section called Foreground Wait Class down in the Wait Event Statistics section of the Main Report, but the additional section appears to include background waits as well. The IO Profile section is especially useful for people like me who work with storage – and I’ve already blogged about it here.
In addition, the long-serving Top 5 Timed Foreground Events section has been renamed and extended to become Top 10 Foreground Events by Total Wait Time.
Here are the changes in tabular format:
|
Old Format |
New Format |
|
Cache Sizes Load Profile Instance Efficiency Percentages Shared Pool Statistics Top 5 Timed Foreground Events Host CPU Instance CPU Memory Statistics – – Time Model Statistics |
Load Profile Instance Efficiency Percentages Top 10 Foreground Events by Total Wait Time Wait Classes by Total Wait Time Host CPU Instance CPU IO Profile Memory Statistics Cache Sizes Shared Pool Statistics Time Model Statistics |
I also said there was one further change outside of the Report Summary section. It’s the long-standing Instance Activity Stats section, which has now been divided into two:
|
Old Format |
New Format |
|
Instance Activity Stats – |
Key Instance Activity Stats Other Instance Activity Stats |
I don’t really understand the point of that change, nor why a select few statistics are deemed to be more “key” than others. But hey, that’s the mystery of Oracle, right?
Tablespace / Filesystem IO Stats
Another, more minor change, is the addition of some cryptic-looking “1-bk” columns to the two sections Tablespace IO Stats and File IO Stats:
Tablespace
------------------------------
Av Av Av 1-bk Av 1-bk Writes Buffer Av Buf
Reads Rds/s Rd(ms) Blks/Rd Rds/s Rd(ms) Writes avg/s Waits Wt(ms)
------- ------- ------- ------- ------- ------- ------- ------- -------- -------
UNDOTBS1
8.4E+05 29 0.7 1.0 6.3E+06 29.2 1 220 1,054 4.2
SYSAUX
95,054 3 0.8 1.0 11,893 3.3 1 0 1 60.0
SYSTEM
745 0 0.0 1.0 1,055 0.0 0 0 13 0.8
USERS
715 0 0.0 1.0 715 0.0 0 0 0 0.0
TEMP
0 0 0.0 N/A 7 0.0 0 0 0 0.0
I have to confess it took me a while to figure out what they meant – in the end I had to consult the documentation for the view DBA_HIST_FILESTATXS:
| Column | Datatype | NULL | Description |
|---|---|---|---|
SINGLEBLKRDS |
NUMBER |
Number of single block reads | |
SINGLEBLKRDTIM |
NUMBER |
Cumulative single block read time (in hundredths of a second) |
Aha! So the AWR report is now giving us the number of single block reads (SINGLEBLKRDS) and the average read time for them (SINGLEBLKRDTIM / SINGLEBLKRDS). That’s actually pretty useful information for testing storage, since single block reads tell no lies. [If you want to know what I mean by that, visit Frits Hoogland’s blog and download his white paper on multiblock reads…]
Top 10: Don’t Believe The Stats
One thing you might want to be wary about is the new Top 10 section… Here are the first two lines from mine after running a SLOB test:
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Tota Wait % DB
Event Waits Time Avg(ms) time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
db file sequential read 3.379077E+09 2527 1 91.4 User I/O
DB CPU 318. 11.5
Now, normally when I run SLOB and inspect the post-run awr.txt file I work out the average wait time for db file sequential read so I can work out the latency. Since AWR reports do not have enough decimal places for the sort of storage I use (the wait shows simply as 0 or 1), I have to divide the total wait time by the number of waits. But in the report above, the total wait time of 2,527 divided by 3,379,077,000 waits gives me an average of 0.000747 microseconds. Huh? Looking back at the numbers above it’s clear that the Total Time column has been truncated and some of the digits are missing. That’s bad news for me, as I regularly use scripts to strip this information out and parse it.
This is pretty poor in my opinion, because there is no warning and the number is just wrong. I assume this is an edge case because the number of waits contains so many digits, but for extended SLOB tests that’s not unlikely. Back in the good old Top 5 days it looked like this, which worked fine:
Top 5 Timed Foreground Events
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Avg
wait % DB
Event Waits Time(s) (ms) time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
db file sequential read 119,835,425 50,938 0 84.0 User I/O
latch: cache buffers lru chain 20,051,266 6,221 0 10.3 Other
Unfortunately, in the new 11.2.0.4 and above Top 10 report, the Total Time column simply isn’t wide enough. Instead, I have to scan down to the Foreground Wait Events section to get my true data:
Avg
%Time Total Wait wait Waits % DB
Event Waits -outs Time (s) (ms) /txn time
-------------------------- ------------ ----- ---------- ------- -------- ------
db file sequential read 3.379077E+09 0 2,527,552 1 11.3 91.4
This is something worth looking out for, especially if you also use scripts to fetch data from AWR files. Of course, the HTML reports don’t suffer from this problem, which just makes it even more annoying as I can’t parse HTML reports automatically (and thus I despise them immensely).
12.1.0.2 AWR Reports
One final thing to mention is the AWR report format of 12.1.0.2 (which was just released at the time of writing). There aren’t many changes from 12.1.0.1 but just a few extra lines have crept in, which I’ll highlight here. In the main, they are related to the new In Memory Database option.
Load Profile Per Second Per Transaction Per Exec Per Call
~~~~~~~~~~~~~~~ --------------- --------------- --------- ---------
DB Time(s): 0.3 4.8 0.00 0.02
DB CPU(s): 0.1 1.2 0.00 0.00
Background CPU(s): 0.0 0.1 0.00 0.00
Redo size (bytes): 50,171.6 971,322.7
Logical read (blocks): 558.6 10,814.3
Block changes: 152.2 2,947.0
Physical read (blocks): 15.1 292.0
Physical write (blocks): 0.2 4.7
Read IO requests: 15.1 292.0
Write IO requests: 0.2 3.3
Read IO (MB): 0.1 2.3
Write IO (MB): 0.0 0.0
IM scan rows: 0.0 0.0
Session Logical Read IM:
User calls: 16.1 312.0
Parses (SQL): 34.0 658.0
Hard parses (SQL): 4.6 88.0
SQL Work Area (MB): 0.9 17.2
Logons: 0.1 1.7
Executes (SQL): 95.4 1,846.0
Rollbacks: 0.0 0.0
Transactions: 0.1
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 97.55 Redo NoWait %: 100.00
Buffer Hit %: 97.30 In-memory Sort %: 100.00
Library Hit %: 81.75 Soft Parse %: 86.63
Execute to Parse %: 64.36 Latch Hit %: 96.54
Parse CPU to Parse Elapsd %: 19.45 % Non-Parse CPU: 31.02
Flash Cache Hit %: 0.00
<snip!>
Cache Sizes Begin End
~~~~~~~~~~~ ---------- ----------
Buffer Cache: 960M 960M Std Block Size: 8K
Shared Pool Size: 4,096M 4,096M Log Buffer: 139,980K
In-Memory Area: 0M 0M
One other thing of note is that the Top 10 section now (finally) displays average wait times to two decimal places. This took a surprising amount of time to arrive, but it’s most welcome:
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Total Wait Wait % DB Wait
Event Waits Time (sec) Avg(ms) time Class
------------------------------ ----------- ---------- ---------- ------ --------
db file parallel read 63,157 828.6 13.12 86.1 User I/O
DB CPU 234.2 24.3
db file sequential read 113,786 67.8 0.60 7.0 User I/O
flashdba 