Re: High CPU usage

From: Gerry Miller <gerry_at_millerandbowman.com>
Date: Tue, 19 Jun 2012 16:07:49 +1000
Message-ID: <4FE01735.5080001_at_millerandbowman.com>



Hi Jonathan

It is quite a lightweight query of sys.all_tab_cols and obj$ but the reason I chose it was that it had exactly the same buffer gets in both files and the same type and number of waits events. I was trying to avoid any red herrings. It was just an example of what hundreds of other queries were doing, most of them application related.

I have been taking STATSPACK snapshots every 5 minutes and neither STATS$MUTEX_SLEEP or STATS$LATCH show much activity at all over the periods when I was encountering the issue. I have also been tracing everything and again neither latch nor mutex waits are prevalent. Resource Profiles taken over problem periods consistently report CPU and db file waits as accounting for around 97% of resource usage, with occasional latch waits and no mutex waits at all.

Am I correct in assuming that any such latch or mutex problem activity would manifest itself as a session wait event?

Thanks and Regards

Gerry Miller

Jonathan Lewis wrote:
> Your example show you using 32 CPU seconds in the execution line with NO
> buffer visits.
> Either
> a) your CPU problem appears before you start to execute the statement
> or
> b) the buffer visits associated with this query have not been reported
> properly.
>
> The query itself looks, according to the Fetch stats, looks like a trivial,
> lightweight
> query - it would have been nice to see how simple it really was - since you
> get 50
> row in only 55 buffer visits.
>
> Assuming the simplest interpretation - i.e. tkprof is reporting
> truthfully - we could guess
> that your problem is in the library cache access required to pin and
> execute the statement.
> It's possible you have a latch or mutex spin problem. Since you haven't
> said anything about
> latch sleeps and mutex sleeps, and given the version of Oracle, I'd go for
> a mutex spin
> issue.
>
> Things to do:
> Try a few runs taking snapshots of v$mystat to see if any other big
> numbers show up
> Try a few runs taking snapshots of v$latch, or using Tanel's latchprofx
> script
> Try a few runs taking snapshots of the v$mutex_XXXX views
>
>
> Regards
>
> Jonathan Lewis
> http://jonathanlewis.wordpress.com/all_postings
>
> Author: Oracle Core (Apress 2011)
> http://www.apress.com/9781430239543
>
> ----- Original Message -----
> From: "Gerry Miller" <gerry_at_millerandbowman.com>
> To: <oracle-l_at_freelists.org>
> Sent: Wednesday, June 13, 2012 5:10 AM
> Subject: High CPU usage
>
>
> Furthermore, in comparing my regression test results I have found that
> CPU
> usage is consistently and significantly higher in one result set than
> others. For example, consider this one tkprof output:
> First Run: call count cpu elapsed disk query
> current rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.00 0.00 0 0 0
> 0
> Execute 1 0.00 0.00 0 0 0
> 0
> Fetch 5 0.00 0.00 0 55 0
> 50
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 7 0.00 0.00 0 55 0
> 50
>
> Second Run: call count cpu elapsed disk query
> current rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.00 0.00 0 0 0
> 0
> Execute 1 32.74 31.98 0 0 0
> 0
> Fetch 5 0.00 0.00 0 55 0
> 50
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 7 32.74 31.99 0 55 0
> 50
>
>
> --
> http://www.freelists.org/webpage/oracle-l
>
>
>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Tue Jun 19 2012 - 01:07:49 CDT

Original text of this message