Dear Readers,
In this blog, we are going to look at the possibilities of reporting the foreground and background wait class metrics. Oracle in the AWR doesnt report the foreground and background wait class metrics separately, it only reports the foreground metrics by wait class; but not the background.
So I wrote a sql analytic query based on dba_hist_system_event view to report the metrics...
Query:
with t as
(
select /*+ materialize */ snap_id
,wait_class
,sum(total_waits) totwts
,sum(time_waited_micro) tmwt
,sum(total_waits_fg) totwtsfg
,sum(time_Waited_micro_fg) tmwtfg
,(sum(total_waits)-sum(total_waits_fg)) totwtsbg
,(sum(time_waited_micro)-sum(time_waited_micro_fg)) tmwtbg
from dba_hist_system_event
group by snap_id
,wait_class
)
select t.wait_class
,(t.totwts-a.totwts) total_waits
,(t.tmwt-a.tmwt) total_time_waited_us
,(t.totwtsfg-a.totwtsfg) total_waits_fg
,(t.tmwtfg-a.tmwtfg) time_waited_fg_us
,(t.totwtsbg-a.totwtsbg) total_waits_bg
,(t.tmwtbg-a.tmwtbg) time_waited_bg_us
from
t ,t a
where t.snap_id=18
and a.snap_id=(t.snap_id-1)
and a.wait_Class=t.wait_class
order by 1,2;
Result:
WAIT_CLASS ,TOTAL_WAITS,TOTAL_TIME_WAITED_US,TOTAL_WAITS_FG,TIME_WAITED_FG_US,TOTAL_WAITS_BG,TIME_WAITED_BG_US
------------------------------,-----------,--------------------,--------------,-----------------,--------------,-----------------
Administrative , 32, 189, 32, 189, 0, 0
Application , 17, 24645, 17, 24645, 0, 0
Commit , 26770, 84755489, 26759, 84639135, 11, 116354
Concurrency , 2, 25996, 0, 0, 2, 25996
Configuration , 13, 922471, 13, 922471, 0, 0
Idle , 168764, 1.1192E+11, 105007, 5855698235, 63757, 1.0606E+11
Network , 120130, 1099890, 120024, 1099821, 106, 69
Other , 6035, 76421612, 4793, 696732, 1242, 75724880
Scheduler , 0, 0, 0, 0, 0, 0
System I/O , 40147, 119983483, 1009, 93039, 39138, 119890444
User I/O , 5086, 5884585, 4479, 2866115, 607, 3018470
11 rows selected.
So you can see above the breakup of the wait class information by foreground and background processes.
AWR report sample (Showing the total waits and time waited information in total - not classified by fg or bg process):
Wait Classes by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Avg Avg
Total Wait Wait % DB Active
Wait Class Waits Time (sec) Time time Sessions
---------------- ---------------- ---------------- ---------- ------ --------
System I/O 40,147 120 2.99ms 90.7 0.1
Commit 26,770 85 3.17ms 64.1 0.0
Other 6,035 76 12.66ms 57.8 0.0
DB CPU 42 31.7 0.0
User I/O 5,086 6 1.16ms 4.4 0.0
Network 120,130 1 9.16us .8 0.0
Configuration 13 1 70.96ms .7 0.0
Concurrency 2 0 13.00ms .0 0.0
Application 17 0 1.45ms .0 0.0
Administrative 32 0 5.91us .0 0.0
AWR report sample (Showing the total waits and time waited information in total - only for fg):
Foreground Wait Class DB/Inst: ORA19C01/ORA19C01 Snaps: 17-18
-> s - second, ms - millisecond, us - microsecond, ns - nanosecond
-> ordered by wait time desc, waits desc
-> %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0
-> Captured Time accounts for 100.0% of Total DB time 132.30 (s)
-> Total FG Wait Time: 90.34 (s) DB CPU time: 42.00 (s)
%Time Total Wait
Wait Class Waits -outs Time (s) Avg wait %DB time
-------------------- --------------- ----- --------------- ---------- ---------
Commit 26,759 0 85 3.16ms 64.0
DB CPU 42 31.7
User I/O 4,479 0 3 639.90us 2.2
Network 120,024 0 1 9.16us 0.8
Configuration 13 0 1 70.96ms 0.7
Other 4,793 0 1 145.36us 0.5
System I/O 1,009 0 0 92.21us 0.1
Application 17 0 0 1.45ms 0.0
Administrative 32 0 0 5.91us 0.0
Concurrency 0 0 0.0
------------------------------------------------------
If you read the line "-> Captured Time accounts for 100.0% of Total DB time 132.30 (s)". Oracle AWR doesnt account for bg process times in the db time metrics, the same applies for DB CPU metric as well. Background process spends are measured separately.
Then why would some one be interested in the background process wait_class metric information.
In my DB during a hammerDB load test, the system was chocked with system I/O class of wait events aka "log file parallel write & Redo Transport Attach", since my machine had archivelog & standby enabled. Also @ the os end I saw a lot of system and IO waits, I didnt store vmstat result, but you can see below the sar report (averaged out!!!) over 10 mins time showing a significant increase in system cpu usage.
Total
%Time Wait Waits % bg
Event Waits -outs Time (s) Avg wait /txn time
-------------------------- ----------- ----- -------- --------- -------- ------
log file parallel write 28,790 0 90 3.13ms 1.1 39.1
Redo Transport Attach 6 0 72 12.03 s 0.0 31.3
02:20:01 AM CPU %user %nice %system %iowait %steal %idle
02:30:01 AM all 0.27 0.00 4.53 0.17 0.00 95.04 <<< this is the window the test ran
02:40:01 AM all 0.04 0.00 0.66 0.13 0.00 99.17
Hope this helps!
Thank you!
