X-Original-To: pgsql-performance-postgresql.org@postgresql.org Received: from localhost (mx1.hub.org [200.46.208.251]) by postgresql.org (Postfix) with ESMTP id 3A6C89FB332 for ; Fri, 22 Sep 2006 12:35:10 -0300 (ADT) Received: from postgresql.org ([200.46.204.71]) by localhost (mx1.hub.org [200.46.208.251]) (amavisd-new, port 10024) with ESMTP id 83965-01 for ; Fri, 22 Sep 2006 12:34:59 -0300 (ADT) X-Greylist: domain auto-whitelisted by SQLgrey- Received: from wx-out-0506.google.com (wx-out-0506.google.com [66.249.82.230]) by postgresql.org (Postfix) with ESMTP id 7CECF9FB2F2 for ; Fri, 22 Sep 2006 12:34:59 -0300 (ADT) Received: by wx-out-0506.google.com with SMTP id t13so1100858wxc for ; Fri, 22 Sep 2006 08:34:58 -0700 (PDT) DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=beta; d=gmail.com; h=received:message-id:date:from:to:subject:mime-version:content-type; b=qEHc9HjBklGN5IWLMOwprP7d0z0D/EaI8gGDdD8gmYOpp4KOmNXZraqjVQ3anzTwnfY8YGgECsmJZcZFb0UiVwAixzUQBw2sWUrlSLx1Eg9ksyTR6TWGhtl5APEyWOwPFsWZWm3EpxUsba+lOs7PpRXtEnQ7GIsSAF2Ciri/rmU= Received: by 10.90.94.2 with SMTP id r2mr423259agb; Fri, 22 Sep 2006 08:34:58 -0700 (PDT) Received: by 10.90.49.6 with HTTP; Fri, 22 Sep 2006 08:34:58 -0700 (PDT) Message-ID: <33c6269f0609220834x6c10db9xa40d6121825dfd14@mail.gmail.com> Date: Fri, 22 Sep 2006 11:34:58 -0400 From: "Alex Turner" To: "Pgsql-Performance ((E-mail))" Subject: Confusion and Questions about blocks read MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_Part_12350_10062726.1158939298592" X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=0.334 tagged_above=0 required=5 tests=DNS_FROM_RFC_ABUSE, HTML_50_60, HTML_MESSAGE, SPF_PASS X-Spam-Level: X-Archive-Number: 200609/302 X-Sequence-Number: 20988 ------=_Part_12350_10062726.1158939298592 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Content-Disposition: inline The query expain analyze looks like this: click-counter=# explain analyze select count(*) as count, to_char(date_trunc('day',c.datestamp),'DD-Mon') as day from impression c, url u, handle h where c.url_id=u.url_id and c.handle_id=h.handle_id and h.handle like '10000.19%' group by date_trunc('day',c.datestamp) order by date_trunc('day',c.datestamp); QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ Sort (cost=530282.76..530283.04 rows=113 width=8) (actual time= 191887.059..191887.131 rows=114 loops=1) Sort Key: date_trunc('day'::text, c.datestamp) -> HashAggregate (cost=530276.65..530278.91 rows=113 width=8) (actual time=191886.081..191886.509 rows=114 loops=1) -> Hash Join (cost=128.41..518482.04 rows=2358921 width=8) (actual time=17353.281..190568.890 rows=625212 loops=1) Hash Cond: ("outer".handle_id = "inner".handle_id) -> Merge Join (cost=0.00..444641.52 rows=5896746 width=12) (actual time=34.582..183154.561 rows=5896746 loops=1) Merge Cond: ("outer".url_id = "inner".url_id) -> Index Scan using url_pkey on url u (cost= 0.00..106821.10 rows=692556 width=8) (actual time=0.078..83432.380rows=692646 loops=1) -> Index Scan using impression_url_i on impression c (cost=0.00..262546.95 rows=5896746 width=16) (actual time=34.473..86701.410rows=5896746 loops=1) -> Hash (cost=123.13..123.13 rows=2115 width=4) (actual time=40.159..40.159 rows=2706 loops=1) -> Bitmap Heap Scan on handle h (cost=24.69..123.13rows=2115 width=4) (actual time= 20.362..36.819 rows=2706 loops=1) Filter: (handle ~~ '10000.19%'::text) -> Bitmap Index Scan on handles_i (cost= 0.00..24.69 rows=2115 width=0) (actual time=20.264..20.264 rows=2706 loops=1) Index Cond: ((handle >= '10000.19'::text) AND (handle < '10000.1:'::text)) Total runtime: 191901.868 ms (looks like it sped up a bit the second time I did it) When I query relpages for the tables involved: click-counter=# select relpages from pg_class where relname='impression'; relpages ---------- 56869 (1 row) click-counter=# select relpages from pg_class where relname='url'; relpages ---------- 66027 (1 row) click-counter=# select relpages from pg_class where relname='handle'; relpages ---------- 72 (1 row) click-counter=# they only total 122968. Home come the query statistics showed that 229066 blocks where read given that all the blocks in all the tables put together only total 122968? LOG: QUERY STATISTICS DETAIL: ! system usage stats: ! 218.630786 elapsed 24.160000 user 13.930000 system sec ! [261.000000 user 85.610000 sys total] ! 0/0 [0/0] filesystem blocks in/out ! 65/47 [20176/99752] page faults/reclaims, 0 [0] swaps ! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent ! 0/0 [0/0] voluntary/involuntary context switches ! buffer usage stats: ! Shared blocks: 229066 read, 2 written, buffer hit rate = 55.61% ! Local blocks: 0 read, 0 written, buffer hit rate = 0.00% ! Direct blocks: 0 read, 0 written Alex. ------=_Part_12350_10062726.1158939298592 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Content-Disposition: inline The query expain analyze looks like this:

click-counter=3D# explain = analyze select count(*) as count, to_char(date_trunc('day',c.datestamp),'DD= -Mon') as day from impression c, url u, handle h where c.url_id=3Du.url_id = and=20 c.handle_id=3Dh.handle_id and h.handle like '10000.19%' group by date_trunc= ('day',c.datestamp) order by date_trunc('day',c.datestamp);
  =             &nb= sp;            =             &nb= sp;            =             &nb= sp;            =      QUERY PLAN      &nbs= p;            &= nbsp;           &nbs= p;            &= nbsp;           &nbs= p;          =20
-----------------------------------------------------------------------= ---------------------------------------------------------------------------= ----------------------------
 Sort  (cost=3D530282.76..530283.= 04 rows=3D113 width=3D8) (actual time=3D 191887.059..191887.131 rows=3D114 loops=3D1)
   Sort Key: date= _trunc('day'::text, c.datestamp)
   ->  HashAggregate&= nbsp; (cost=3D530276.65..530278.91 rows=3D113 width=3D8) (actual time=3D191= 886.081..191886.509 rows=3D114 loops=3D1)
         ->  Hash Join = ; (cost=3D128.41..518482.04 rows=3D2358921 width=3D8) (actual time=3D17353.= 281..190568.890 rows=3D625212 loops=3D1)
     &= nbsp;         Hash Cond: ("out= er".handle_id =3D "inner".handle_id)
            &nb= sp;  ->  Merge Join  (cost=3D0.00..444641.52 rows=3D58967= 46 width=3D12) (actual time=3D34.582..183154.561 rows=3D5896746 loops=3D1)<= br>            =          Merge Cond: ("outer&q= uot;.url_id =3D "inner".url_id)
            = ;         ->  Index Scan us= ing url_pkey on url u  (cost=3D0.00..106821.10 rows=3D692556 width=3D8= ) (actual time=3D0.078..83432.380 rows=3D692646 loops=3D1)
  &= nbsp;           &nbs= p;      ->  Index Scan using impression_ur= l_i on impression c  (cost=3D 0.00..262546.95 rows=3D5896746 width=3D16) (actual time=3D34.473..86701.410= rows=3D5896746 loops=3D1)
       &nb= sp;       ->  Hash  (cost=3D123.= 13..123.13 rows=3D2115 width=3D4) (actual time=3D40.159..40.159 rows=3D2706= loops=3D1)
          =            ->  Bi= tmap Heap Scan on handle h  (cost=3D 24.69..123.13 rows=3D2115 width=3D4) (actual time=3D20.362..36.819 rows=3D2= 706 loops=3D1)
         &nb= sp;            =      Filter: (handle ~~ '10000.19%'::text)
 &nb= sp;            =              -&= gt;  Bitmap Index Scan on handles_i  (cost=3D 0.00..24.69 rows=3D2115 width=3D0) (actual time=3D20.264..20.264 rows=3D270= 6 loops=3D1)
          = ;            &n= bsp;          Index Cond: ((ha= ndle >=3D '10000.19'::text) AND (handle < '10000.1:'::text))
 = ;Total runtime: 191901.868 ms

(looks like it sped up a bit the second time I did it)

Wh= en I query relpages for the tables involved:

click-counter=3D# selec= t relpages from pg_class where relname=3D'impression';
 relpages----------
    56869
(1 row)

click-counter=3D# select rel= pages from pg_class where relname=3D'url';
 relpages
----------<= br>    66027
(1 row)

click-counter=3D# select relp= ages from pg_class where relname=3D'handle';
 relpages
----------
       72=
(1 row)

click-counter=3D#

they only total 122968.

= Home come the query statistics showed that 229066 blocks where read given t= hat all the blocks in all the tables put together only total 122968?

LOG:  QUERY STATISTICS
DETAIL:  ! system usage stats:<= br>        !    &nbs= p;  218.630786 elapsed 24.160000 user 13.930000 system sec
 &n= bsp;      !       [2= 61.000000 user 85.610000 sys total]
      =   !       0/0 [0/0] filesystem blocks in= /out
        !    &nb= sp;  65/47 [20176/99752] page faults/reclaims, 0 [0] swaps
 &n= bsp;      !       0 = [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
    &= nbsp;   !       0/0 [0/0] voluntary= /involuntary context switches
       = ! buffer usage stats:
        !    &nb= sp;  Shared blocks:     229066 read,  &n= bsp;       2 written, buffer hit rate =3D 55.= 61%
        !    =    Local  blocks:       &= nbsp;  0 read,          0= written, buffer hit rate =3D 0.00%
      =   !       Direct blocks:  &nbs= p;       0 read,     = ;     0 written


Alex.
------=_Part_12350_10062726.1158939298592--