From: Steve Singer <ssinger@ca.afilias.info>
To: Jeff Janes <jeff.janes@gmail.com>
Cc: pgsql-performance@postgresql.org <pgsql-performance@postgresql.org>
Subject: Re: slow bitmap heap scans on pg 9.2
Date: Wed, 10 Apr 2013 19:54:09 -0400
Message-ID: <5165FBA1.90704@ca.afilias.info> (raw)
In-Reply-To: <CAMkU=1xQXQWBw8AngvhM70K9GOGby_WAGTR3YTDZ26apv9k9pw@mail.gmail.com>
References: <51656E03.7000701@ca.afilias.info>
<CAMkU=1xQXQWBw8AngvhM70K9GOGby_WAGTR3YTDZ26apv9k9pw@mail.gmail.com>
List-Unsubscribe: <mailto:majordomo@postgresql.org?body=unsub%20pgsql-performance>
On 13-04-10 02:06 PM, Jeff Janes wrote:
> On Wed, Apr 10, 2013 at 6:49 AM, Steve Singer <ssinger@ca.afilias.info
> <mailto:ssinger@ca.afilias.info>> wrote:
>
> I think the index recheck means your bitmap is overflowing (i.e. needing
> more space than work_mem) and so keeping only the pages which have at
> least one match, which means all rows in those pages need to be
> rechecked. How many rows does the table have? You might be essentially
> doing a seq scan, but with the additional overhead of the bitmap
> machinery. Could you do "explain (analyze,buffers)", preferably with
> track_io_timing set to on?
>
table_b has 1,530,710,469 rows
Attached is the output with track_io_timings and buffers.
> Cheers,
>
> Jeff
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performanceAttachments:hashjoin_buffers.txt (text/plain, 4.2K) download
HashAggregate (cost=11768301.08..11770515.08 rows=147600 width=51) (actual time=3518538.111..3518539.201 rows=36 loops=1)
Buffers: shared hit=8892878 read=4997334
I/O Timings: read=1935289.861
-> Hash Join (cost=1282646.06..11041507.43 rows=700524 width=51) (actual time=94631.716..2065378.607 rows=543671 loops=1)
Hash Cond: (a.product_operation = o.id)
Buffers: shared hit=3419 read=4626531
I/O Timings: read=1738580.922
-> Hash Right Join (cost=1282644.14..11031873.30 rows=700524 width=40) (actual time=94631.646..2064079.068 rows=543671 l
oops=1)
Hash Cond: (b.a_id = a.id)
Buffers: shared hit=3418 read=4626531
I/O Timings: read=1738580.922
-> Bitmap Heap Scan on public.table_b_2 b (cost=173185.49..9820205.86 rows=8462538 width=10) (actual ti
me=10044.901..1970005.160 rows=9749680 loops=1)
Recheck Cond: ((b.organization_id = 3) AND (b.year = 2013) AND (b.month = 3))
Rows Removed by Index Recheck: 313195667
Filter: (b.product_id = 2)
Buffers: shared hit=232 read=4606751
I/O Timings: read=1726380.478
-> Bitmap Index Scan on rec_rev_2_orgid_ym_unq (cost=0.00..171069.85 rows=8462538 width=0) (actual time=9410
.598..9410.598 rows=9749680 loops=1)
Index Cond: ((b.organization_id = 3) AND (b.year = 2013) AND (b.month = 3))
Buffers: shared read=37360
I/O Timings: read=3460.299
-> Hash (cost=1107975.15..1107975.15 rows=118680 width=34) (actual time=13732.784..13732.784 rows=543671 loops=1)
Buckets: 16384 Batches: 1 Memory Usage: 37388kB
Buffers: shared hit=3186 read=19780
I/O Timings: read=12200.444
-> Append (cost=0.00..1107975.15 rows=118680 width=34) (actual time=935.605..13395.517 rows=543671 loops=1)
Buffers: shared hit=3186 read=19780
I/O Timings: read=12200.444
-> Seq Scan on public.table_a a (cost=0.00..0.00 rows=1 width=60) (actual time=0.001..0.00
1 rows=0 loops=1)
Filter: ((a.twin_id IS NULL) AND (a.transaction_date >= '2009-09-01 00:00:00+00'::timestamp with t
ime zone) AND (a.transaction_date < '2009-10-01 00:00:00+00'::timestamp with time zone) AND (a.product_id = 2) AND ((a.trans_type_i
d = ANY ('{2,3,4}'::integer[])) OR (a.trans_type_id IS NULL)))
-> Bitmap Heap Scan on public.table_a_2 a (cost=13335.33..1107975.15 rows=118679 width=34)
(actual time=935.603..13301.854 rows=543671 loops=1)
Recheck Cond: ((a.transaction_date >= '2009-09-01 00:00:00+00'::timestamp with time zone) AND (a.t
ransaction_date < '2009-10-01 00:00:00+00'::timestamp with time zone))
Filter: ((a.twin_id IS NULL) AND (a.product_id = 2) AND ((a.trans_type_id = ANY ('{2,3,4}'::intege
r[])) OR (a.trans_type_id IS NULL)))
Rows Removed by Filter: 302939
Buffers: shared hit=3186 read=19780
I/O Timings: read=12200.444
-> Bitmap Index Scan on table_a_2_trans_date_idx (cost=0.00..13305.66 rows=858651 width=0)
(actual time=303.756..303.756 rows=846610 loops=1)
Index Cond: ((a.transaction_date >= '2009-09-01 00:00:00+00'::timestamp with time zone) AND
(a.transaction_date < '2009-10-01 00:00:00+00'::timestamp with time zone))
Buffers: shared read=2317
I/O Timings: read=170.564
-> Hash (cost=1.41..1.41 rows=41 width=19) (actual time=0.036..0.036 rows=41 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 3kB
Buffers: shared hit=1
-> Seq Scan on public.product_operations o (cost=0.00..1.41 rows=41 width=19) (actual time=0.009..0.018 rows=41 lo
ops=1)
Buffers: shared hit=1
Total runtime: 3518541.146 ms
(55 rows)
steve_test=#
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-performance@postgresql.org
Cc: ssinger@ca.afilias.info, jeff.janes@gmail.com
Subject: Re: slow bitmap heap scans on pg 9.2
In-Reply-To: <5165FBA1.90704@ca.afilias.info>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
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