pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedConfusion and Questions about blocks read
6+ messages / 4 participants
[nested] [flat]
* Confusion and Questions about blocks read
@ 2006-09-22 15:34 Alex Turner <armtuk@gmail.com>
0 siblings, 1 reply; 6+ messages in thread
From: Alex Turner @ 2006-09-22 15:34 UTC (permalink / raw)
To: pgsql-performance
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.
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Confusion and Questions about blocks read
@ 2006-09-22 16:24 Tom Lane <tgl@sss.pgh.pa.us>
parent: Alex Turner <armtuk@gmail.com>
0 siblings, 2 replies; 6+ messages in thread
From: Tom Lane @ 2006-09-22 16:24 UTC (permalink / raw)
To: Alex Turner <armtuk@gmail.com>; +Cc: pgsql-performance
"Alex Turner" <armtuk@gmail.com> writes:
> 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?
You forgot to count the indexes. Also, the use of indexscans in the
mergejoins probably causes multiple re-reads of some table blocks,
depending on just what the physical ordering of the rows is.
regards, tom lane
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Confusion and Questions about blocks read
@ 2006-09-22 17:13 Alex Turner <armtuk@gmail.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
1 sibling, 1 reply; 6+ messages in thread
From: Alex Turner @ 2006-09-22 17:13 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance
ahh.... good point
Thanks
On 9/22/06, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> "Alex Turner" <armtuk@gmail.com> writes:
> > 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?
>
> You forgot to count the indexes. Also, the use of indexscans in the
> mergejoins probably causes multiple re-reads of some table blocks,
> depending on just what the physical ordering of the rows is.
>
> regards, tom lane
>
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Confusion and Questions about blocks read
@ 2006-09-22 21:38 Alex Turner <armtuk@gmail.com>
parent: Alex Turner <armtuk@gmail.com>
0 siblings, 0 replies; 6+ messages in thread
From: Alex Turner @ 2006-09-22 21:38 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance
Ok - so I have another mystery:
I insert virtually the same rows into two different tables:
trend=# insert into fish select 2, nextval('result_entry_order_seq'),
property_id from property;
INSERT 0 59913
trend=# insert into result_entry select 0,
nextval('result_entry_order_seq'), property_id from property;
INSERT 0 59913
trend=#
but the stats show one as having written 20x as many blocks:
LOG: statement: insert into fish select 2,
nextval('result_entry_order_seq'), property_id from property;
LOG: QUERY STATISTICS
DETAIL: ! system usage stats:
! 2.098067 elapsed 0.807877 user 1.098833 system sec
! [23.875370 user 27.789775 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/1 [5/62269] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 72/6 [18464/1126] voluntary/involuntary context switches
! buffer usage stats:
! Shared blocks: 79106 read, 420 written, buffer
hit rate = 79.39%
! Local blocks: 0 read, 0 written, buffer
hit rate = 0.00%
! Direct blocks: 0 read, 0 written
LOG: statement: insert into result_entry select 0,
nextval('result_entry_order_seq'), property_id from property;
LOG: QUERY STATISTICS
DETAIL: ! system usage stats:
! 16.963729 elapsed 3.533463 user 1.706740 system sec
! [27.408833 user 29.497515 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/1186 [5/63455] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 59/139 [18525/1265] voluntary/involuntary context switches
! buffer usage stats:
! Shared blocks: 100744 read, 7352 written, buffer hit rate
= 89.71%
! Local blocks: 0 read, 0 written, buffer hit rate
= 0.00%
! Direct blocks: 0 read, 0 written
I understand the read blocks difference, the second had to check indexes
matching the foreign keys.
The table definitions are given below:
trend=# \d fish
Table "public.fish"
Column | Type | Modifiers
--------------------+---------+-----------
result_id | bigint |
result_entry_order | bigint |
property_id | integer |
Indexes:
"fish_pkey" UNIQUE, btree (result_id, result_entry_order)
trend=# \d result_Entry
Table "public.result_entry"
Column | Type | Modifiers
--------------------+---------+-----------
result_id | bigint |
result_entry_order | bigint |
property_id | integer |
Indexes:
"fish_pkey" UNIQUE, btree (result_id, result_entry_order)
The explain analyzes are kind of interesting:
trend=# explain analyze insert into fish select 2,
nextval('result_entry_order_seq'), property_id from property;
QUERY
PLAN
-----------------------------------------------------------------------------------------------------------------
Seq Scan on property (cost=0.00..79295.70 rows=59913 width=8) (actual
time=0.275..1478.681 rows=59913 loops=1)
Total runtime: 2178.600 ms
(2 rows)
trend=# explain analyze insert into result_entry select 0,
nextval('result_entry_order_seq'), property_id from property;
QUERY
PLAN
-----------------------------------------------------------------------------------------------------------------
Seq Scan on property (cost=0.00..79295.70 rows=59913 width=8) (actual
time=0.118..1473.352 rows=59913 loops=1)
Trigger for constraint result_entry_result_fk: time=2037.351 calls=59913
Trigger for constraint result_entry_property_fk: time=8622.260 calls=59913
Total runtime: 12959.716 ms
(4 rows)
I don't understand the time for the FK check given the size of the tables
they are checking against (and I understand it's the indexes, not the tables
that the actualy check is made):
trend=# select count(*) from result_cache;
count
-------
8
(1 row)
trend=#
trend=# select count(*) from property;
count
-------
59913
(1 row)
trend=#
The database was just re-indexed, and no changes beyond this insert were
made in that time and result_entry has recently been vacuumed.
Any insight would be greatly appreciated
Alex
On 9/22/06, Alex Turner <armtuk@gmail.com> wrote:
>
> ahh.... good point
>
> Thanks
>
> On 9/22/06, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> >
> > "Alex Turner" <armtuk@gmail.com> writes:
> > > 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?
> >
> > You forgot to count the indexes. Also, the use of indexscans in the
> > mergejoins probably causes multiple re-reads of some table blocks,
> > depending on just what the physical ordering of the rows is.
> >
> > regards, tom lane
> >
>
>
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Confusion and Questions about blocks read
@ 2006-09-23 12:19 Markus Schaber <schabi@logix-tt.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
1 sibling, 1 reply; 6+ messages in thread
From: Markus Schaber @ 2006-09-23 12:19 UTC (permalink / raw)
To: pgsql-performance
Hi, Tom,
Tom Lane wrote:
> "Alex Turner" <armtuk@gmail.com> writes:
>> 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?
>
> You forgot to count the indexes. Also, the use of indexscans in the
> mergejoins probably causes multiple re-reads of some table blocks,
> depending on just what the physical ordering of the rows is.
As far as I understand, Index Bitmap Scans improve this behaviour, by
ensuring that every table block is read only once.
Btw, would it be feasible to enhance normal index scans by looking at
all rows in the current table block whether they meet the query
criteria, fetch them all, and blacklist the block for further revisiting
during the same index scan?
I think that, for non-sorted cases, this could improve index scans a
little, but I don't know whether it's worth the effort, given that
bitmap indidex scans exist.
Thanks,
Markus
--
Markus Schaber | Logical Tracking&Tracing International AG
Dipl. Inf. | Software Development GIS
Fight against software patents in Europe! www.ffii.org
www.nosoftwarepatents.org
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Confusion and Questions about blocks read
@ 2006-09-27 03:08 Jim Nasby <jim@nasby.net>
parent: Markus Schaber <schabi@logix-tt.com>
0 siblings, 0 replies; 6+ messages in thread
From: Jim Nasby @ 2006-09-27 03:08 UTC (permalink / raw)
To: Markus Schaber <schabi@logix-tt.com>; +Cc: pgsql-performance
On Sep 23, 2006, at 8:19 AM, Markus Schaber wrote:
> Btw, would it be feasible to enhance normal index scans by looking at
> all rows in the current table block whether they meet the query
> criteria, fetch them all, and blacklist the block for further
> revisiting
> during the same index scan?
>
> I think that, for non-sorted cases, this could improve index scans a
> little, but I don't know whether it's worth the effort, given that
> bitmap indidex scans exist.
The trade-off is you'd burn a lot more CPU on those pages. What might
be interesting would be collapsing bitmap scan data down to a page
level when certain conditions were met, such as if you're getting a
significant number of hits for a given page. There's probably other
criteria that could be used as well. One issue would be considering
the effects of other bitmap index operations; if you're ANDing a
bunch of scans together, you're likely to have far fewer tuples per
page coming out the backside, which means you probably wouldn't want
to burn the extra CPU to do full page scans.
BTW, I remember discussion at some point about ordering the results
of a bitmap scan by page/tuple ID, which would essentially do what
you're talking about. I don't know if it actually happened or not,
though.
If this is something that interests you, I recommend taking a look at
the code; it's generally not too hard to read through thanks to all
the comments.
--
Jim Nasby jimn@enterprisedb.com
EnterpriseDB http://enterprisedb.com 512.569.9461 (cell)
--
Jim Nasby jimn@enterprisedb.com
EnterpriseDB http://enterprisedb.com 512.569.9461 (cell)
^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2006-09-27 03:08 UTC | newest]
Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2006-09-22 15:34 Confusion and Questions about blocks read Alex Turner <armtuk@gmail.com>
2006-09-22 16:24 ` Tom Lane <tgl@sss.pgh.pa.us>
2006-09-22 17:13 ` Alex Turner <armtuk@gmail.com>
2006-09-22 21:38 ` Alex Turner <armtuk@gmail.com>
2006-09-23 12:19 ` Markus Schaber <schabi@logix-tt.com>
2006-09-27 03:08 ` Jim Nasby <jim@nasby.net>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox