Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Usenet -> c.d.o.server -> Re: High elapsed/cpu ratio

Re: High elapsed/cpu ratio

From: Richard Foote <richard.foote_at_nospam.bigpond.com>
Date: Tue, 11 Sep 2007 13:38:11 GMT
Message-ID: <7TwFi.34089$4A1.34067@news-server.bigpond.net.au>


"Alberto Frosi" <alberto.frosi_at_gmail.com> wrote in message news:1189515886.196731.106620_at_r34g2000hsd.googlegroups.com...

> On 11 Set, 14:08, "Richard Foote" <richard.fo..._at_nospam.bigpond.com>
> wrote:

>> "R.Wang" <R.W..._at_oraclepoint.com> wrote in message
>>
>> news:1189482809.926373.101520_at_r34g2000hsd.googlegroups.com...
>>
>>
>>
>> > On Sep 10, 11:07 am, ebwri..._at_gmail.com wrote:
>> >> I'm working on tuning a particular query and have gotten the explain
>> >> plan as pretty as possible, low cost, etc. However, when running the
>> >> query (an insert into table select ... statement), I find the
>> >> following information in the tkprof trace file:
>>
>> >> call count cpu elapsed disk query
>> >> current rows
>> >> ------- ------ -------- ---------- ---------- ---------- ----------
>> >> ----------
>> >> Parse 1 0.02 0.02 0 0
>> >> 0 0
>> >> Execute 1 170.59 2289.34 870183 16953935
>> >> 49 5
>> >> Fetch 0 0.00 0.00 0 0
>> >> 0 0
>> >> ------- ------ -------- ---------- ---------- ---------- ----------
>> >> ----------
>> >> total 2 170.61 2289.37 870183 16953935
>> >> 49 5
>>
>> >> The cpu spent less than 3m executing the query, but it took nearly 40m
>> >> for results to be retrieved and inserted. This was done in a
>> >> development environment with little to no other users (so, no locking
>> >> issues), fresh statistics on tables and indexes, and an empty target
>> >> table that was truncated immediately before processing.
>>
>> >> The one issue I know that could cause problems is that the tables
>> >> being accessed are in a very large (~500 GB) tablespace. This is not
>> >> something that can be changed at this time.
>>
>> >> Thanks,
>> >> Eric
>>
>> > Hi Eric,
>>
>> > 1.The hit ratio is Good.
>>
>> > Logical Reads = query + current
>> > Logical Reads = 16953935+0 + 49+0
>> > Logical Reads = 16953935 + 49
>> > Logical Reads = 16953984
>>
>> > Hit Ratio = 1 - (Physical Reads / Logical Reads)
>> > Hit Ratio = 1 - ((870183+0) / 16953984)
>> > Hit Ratio = 1 - (0.05)
>> > Hit Ratio = 95%
>>
>> > Go follow other postings to trace event 10046.
>>
>> Hi R.Wang
>>
>> The problem with hit ratios of course is that even 5% of a real real lot
>> can
>> still equal a lot.
>>
>> Here we have 16,953,984 LIOs (which might well be considered a real real
>> lot) of which we still have 870,183 PIOs (which might well be considered
>> to
>> still be a lot).
>>
>> Perhaps, just perhaps, a fair proportion of the "unexplained" elapsed
>> time
>> might just be explained by the fact we have nearly 1 million PIOs
>> happening
>> here. That works out to be roughly 380 PIOs per sec which isn't too bad
>> (3ms
>> average per I/O).
>>
>> Now, absolutely look at the raw trace file and investigate the actual
>> wait
>> events but not because of yet another poor example of using a hit ratio
>> ...
>>
>> It also seems to be an awful lot of work just to insert 5 rows into a
>> table,
>> hope there's some aggregation happening ;)
>>
>> Cheers
>>
>> Richard
>
> Hi Richard,
> Great answer, but in this case there aren't system performance
> problems but the real problem it's the insert query then.
> we must to analyze a trace file for know the real problem, isn't it?

Hi Alberto

The insert query is performing 16 Million I/Os.

Explain the query, examine the execution plan and determine why the thing is so expensive.

Cheers

Richard Received on Tue Sep 11 2007 - 08:38:11 CDT

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US