Path: dp-news.maxwell.syr.edu!spool.maxwell.syr.edu!drn.maxwell.syr.edu!news.maxwell.syr.edu!tiscali!newsfeed1.ip.tiscali.net!newsfeed00.sul.t-online.de!t-online.de!inka.de!rz.uni-karlsruhe.de!news.uni-stuttgart.de!carbon.eu.sun.com!btnet-feed5!btnet!news.btopenworld.com!not-for-mail From: "Jonathan Lewis" Newsgroups: comp.databases.oracle.server Subject: Re: Why Statistics doesn't match reponse time? Date: Fri, 9 Sep 2005 06:52:28 +0000 (UTC) Organization: BT Openworld Lines: 174 Message-ID: References: <1126223681.362757.321590@o13g2000cwo.googlegroups.com> NNTP-Posting-Host: host86-130-246-141.range86-130.btcentralplus.com X-Trace: nwrdmz01.dmz.ncs.ea.ibs-infra.bt.com 1126248748 18485 86.130.246.141 (9 Sep 2005 06:52:28 GMT) X-Complaints-To: news-complaints@lists.btinternet.com NNTP-Posting-Date: Fri, 9 Sep 2005 06:52:28 +0000 (UTC) X-RFC2646: Format=Flowed; Original X-Newsreader: Microsoft Outlook Express 6.00.2900.2180 X-MSMail-Priority: Normal X-Priority: 3 X-MimeOLE: Produced By Microsoft MimeOLE V6.00.2900.2180 Xref: dp-news.maxwell.syr.edu comp.databases.oracle.server:251126 wrote in message news:1126223681.362757.321590@o13g2000cwo.googlegroups.com... > Hi > > I test the following two queries in my 9.2.0.3 database. The response > time > is consistent. > > select /*+ index(cl Total_contributionlog_idx) */ jackpotpool_id, > max(contributionlog_id) as contributionlog_id, > max(cl.datecreated) as datecreated, > max(jackpotPoolCurrentTotal) as jackpotPoolCurrentTotal > from contributionlog cl, pool p > where cl.jackpotpool_id=p.pool_id > group by jackpotpool_id; > 8 rows selected. > Elapsed: 00:00:00.50 > > select jackpotpool_id, > max(contributionlog_id) as contributionlog_id, > max(cl.datecreated) as datecreated, > max(jackpotPoolCurrentTotal) as jackpotPoolCurrentTotal > from contributionlog cl, pool p > where cl.jackpotpool_id=p.pool_id > group by jackpotpool_id; > > 8 rows selected. > > Elapsed: 00:00:02.09 > > When I turn on the autotrace, this is the result. > > Hint: > Execution Plan > ---------------------------------------------------------- > 0 SELECT STATEMENT Optimizer=CHOOSE (Cost=2477 Card=1789 > Bytes=25046) > 1 0 SORT (GROUP BY) (Cost=2477 Card=1789 Bytes=25046) > 2 1 NESTED LOOPS (Cost=2461 Card=8351 Bytes=116914) > 3 2 INDEX (FULL SCAN) OF 'PK_POOL' (UNIQUE) (Cost=1 Card=8 > Bytes=32) > 4 2 TABLE ACCESS (BY INDEX ROWID) OF 'CONTRIBUTIONLOG' > (Cost=308 Card=1044 Bytes=10440) > 5 4 INDEX (RANGE SCAN) OF 'TOTAL_CONTRIBUTIONLOG_IDX' > (NON-UNIQUE) (Cost=1 Card=1044) > > Statistics > ---------------------------------------------------------- > 0 recursive calls > 0 db block gets > 137605 consistent gets > 0 physical reads > 0 redo size > 590 bytes sent via SQL*Net to client > 504 bytes received via SQL*Net from client > 2 SQL*Net roundtrips to/from client > 1 sorts (memory) > 0 sorts (disk) > 8 rows processed > No hint: > Execution Plan > ---------------------------------------------------------- > 0 SELECT STATEMENT Optimizer=CHOOSE (Cost=1505 Card=8 > Bytes=112) > 1 0 SORT (GROUP BY) (Cost=1505 Card=8 Bytes=112) > 2 1 NESTED LOOPS (Cost=1489 Card=8351 Bytes=116914) > 3 2 TABLE ACCESS (FULL) OF 'CONTRIBUTIONLOG' (Cost=1487 > Card=1867580 Bytes=18675800) > 4 2 INDEX (UNIQUE SCAN) OF 'PK_POOL' (UNIQUE) > > Statistics > ---------------------------------------------------------- > 0 recursive calls > 0 db block gets > 15462 consistent gets > 0 physical reads > 0 redo size > 590 bytes sent via SQL*Net to client > 504 bytes received via SQL*Net from client > 2 SQL*Net roundtrips to/from client > 1 sorts (memory) > 0 sorts (disk) > 8 rows processed > The index Total_contributionlog_idx is on > contributionlog(jackpotpool_id, > jackpotPoolCurrentTotal). > >>From Execution Plan and response time, I believe the first query is > better. > select count(*) > from (select distinct jackpotpool_id from contributionlog); > COUNT(*) > ---------- > 1789 > > select count(*) from pool; > COUNT(*) > ---------- > 9 > > However, I have two questions. > 1. Why CBO cannot find the better one, provided that both tables have > been analyzed? > 2. Why statistics of query 2 looks better than query 1? > query 1 with hint: 137605 consistent gets > query 2 withiout hint: 15462 consistent gets > > Kind Regards, > Bin > One of the reasons why the statistics don't match is that there are a couple of important numbers missing from the list. One, of course, is CPU used by the session; the other is "buffer is pinned count". A visit to a pinned buffer is an indication of work done, and is similar to a 'get' - but the important difference is that a 'pinned' buffer can be visited without hitting the cache buffers chains latch. Your index unique scan (unique) on pool is probably doing one consistent get on the one and only block, in the index (with 9 rows, I am assuming the index is just one block) and pinning it for the duration of the query. Consequently, assuming the cardinality in the execution plan is correct, you will probably see 1.8million 'buffer is pinned count'. That, plus the continuous comparison for the join, amounts to a lot of CPU. The PLAN gets chosen because Oracle has given a zero cost to visiting the index. (Partly because it's a unique index with a unique visit, partly because it's blevel = 0). Consequently, the total cost of the query fails to represent the cost of the index visit. If you enable cpu costing (there is an article of mine on OTN somewhere about this) then you will probably find that the plan you had to hint suddenly gets taken automatically - because the other plan becomes more expensive. Check the dbms_stats package for dbms_stats.gather_system_stats() -- Regards Jonathan Lewis http://www.jlcomp.demon.co.uk/cbo_book/ind_book.html Cost Based Oracle - Volume 1: Fundamentals On-shelf date: Nov 2005 http://www.jlcomp.demon.co.uk/faq/ind_faq.html The Co-operative Oracle Users' FAQ http://www.jlcomp.demon.co.uk/appearances.html Public Appearances - schedule updated 4th Sept 2005