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: Alberto Frosi <alberto.frosi_at_gmail.com>
Date: Tue, 11 Sep 2007 13:04:46 -0000
Message-ID: <1189515886.196731.106620@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? Regards
Alberto Received on Tue Sep 11 2007 - 08:04:46 CDT

Original text of this message

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