[Oracle-l] Awr waits over 100%

Hi Kenneth,

the time for log buffer space and log file parallel write might partly
be included in log file sync, especially when there are frequent
commits, so there is some double counting taking place.

Tony Hasler explained this in his 3 blog posts here:
http://tonyhasler.wordpress.com/2011/07/24/log-file-sync-and-log-file-parallel-write-part-1/

Cheers,
Marcus

2011/9/28 Kenneth Naim <kennethnaim@gmail.com>:

Another shot with a short answer, instead of just a link: While your
client session/process waits for "log file sync" when comitting, the
LGWR process does the work of writing out the log buffer to disk and
waits for "log file parallel write". "log file parallel write" wait
events happen during the "log file sync" wait event.

Cheers,
Marcus

2011/9/28 Marcus Mönnig <mm@marcusmoennig.de>:

(Resending due to overquoting...)

While your client session/process waits for "log file sync" when
comitting, the LGWR process does the work of writing out the log
buffer to disk and waits for "log file parallel write". "log file
parallel write" wait events happen during the "log file sync" wait
event, so there is some double counting taking place.

Tony Hasler explained this very nice in his three blog posts here:

http://tonyhasler.wordpress.com/2011/07/24/log-file-sync-and-log-file-parallel-write-part-1/

Cheers,
Marcus

I'd consider that "normal"
While a system has only a limited ( to the number of cpus/cores ) capacity for productive work, any system has an unlimited capacity to wait.
E.g. if one session holds a lock for 1 hour and 2 sessions wait for that lock fthen you may have up to 100% ( 1 hour in 1 hour ) cpu usage from that one session and 200% ( 2 hours in 1 hour ) waits from the other 2 sessions.
Regards
Wolfgang Breitling
Centrex Consulting Corporation
http://www.centrexcc.com

To add a bit more, on a busy system it is even possible that productive work ( CPU time ) "appears" to be > 100% according to AWR.

Regards
Wolfgang Breitling
Centrex Consulting Corporation
http://www.centrexcc.com

I understand that that due to the number of processors and waits that db
time will and should exceed the elapsed time in a busy system. I've it as
high as 3 times the processors time the elapsed time. But shouldn't the
waits + cpu time be divided by the db time so it can't never exceed 100%
unless it is double counting like Marcus said. If it were dividing by the
elapsed time then it would routinely go over 100% but that isn't the case in
hundreds of awr's I've looked at over the years. It begs the question isn't
the double counting a bug? I'd understand if it was minor to rounding but to
be off by such a high number makes the understanding the top 5 issues
deceptive as one doesn't know how off they are and if they are in the
correct order which leads to incorrect analysis and solutions.

Thanks.

Hi Kenneth,

2011/9/29 Kenneth Naim <kennethnaim@gmail.com>:
the "DB time" value used as the divisor for calculating "% Total Call
Time" value comes from Oracle's Time Model Statistics and is defined
as:

"Database time is calculated by aggregating the CPU time and wait time
of all user sessions not waiting for idle wait events (nonidle user
sessions)."

So, it's not the sum for all sessions, but only for user sessions. All
cpu and wait times for background sessions are in the numerator, but
not in the denominator. In your case, the times for "log file parallel
write" and possible parts of other wait events/CPU time refer to the
LGWR background process.

You can look at the "Background Wait Events" section in the AWR report
for all background wait events and "background cpu time" value in the
"Time Model System Stats" to get the CPU times for background
processes.

Cheers,
Marcus

Thanks, that's a very interesting distinction. I'll look into it.

-----Original Message-----
From: oracle-l-bounce@freelists.org
On Behalf Of Marcus Mönnig
Sent: Thursday, September 29, 2011 2:12 AM
To: ORACLE-L
Subject: Re: Awr waits over 100%

Hi Kenneth,

2011/9/29 Kenneth Naim <kennethnaim@gmail.com>:
the "DB time" value used as the divisor for calculating "% Total Call Time"
value comes from Oracle's Time Model Statistics and is defined
as:

"Database time is calculated by aggregating the CPU time and wait time of
all user sessions not waiting for idle wait events (nonidle user sessions)."

So, it's not the sum for all sessions, but only for user sessions. All cpu
and wait times for background sessions are in the numerator, but not in the
denominator. In your case, the times for "log file parallel write" and
possible parts of other wait events/CPU time refer to the LGWR background
process.

You can look at the "Background Wait Events" section in the AWR report for
all background wait events and "background cpu time" value in the "Time
Model System Stats" to get the CPU times for background processes.

Cheers,
Marcus

Hello,

We are running 11.2.0.2 Dataguard in fast_start failover mode and one of the applications we support in this configuration creates an after logon trigger to track who connects to the database. Whenever we do a controlled switchover (or unplanned failover), the Dataguard configuration gets messed up. From what I can tell the after logon trigger is causing ORA-00604 errors at some point in the rebuild process of the old primary.

Does anyone have any experience on working around an issue like this with DataGuard?

Thanks in advance