Re: Hash Anti Join performance degradation

On Thu, May 26, 2011 at 8:33 AM, panam <panam(at)gmx(dot)net> wrote:
> Any third party confirmation?

Yeah, it definitely looks like there is some kind of bug here. Or if
not a bug, then a very surprising feature. EXPLAIN ANALYZE outputs
from your proposed test attached. Here's a unified diff of the two
outputs:

QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------
- Seq Scan on box b (cost=0.00..3669095.76 rows=128 width=8) (actual
time=0.147..431517.693 rows=128 loops=1)
+ Seq Scan on box b (cost=0.00..3669095.76 rows=128 width=8) (actual
time=0.047..6938.165 rows=128 loops=1)
SubPlan 1
- -> Hash Anti Join (cost=14742.77..28664.79 rows=19239 width=8)
(actual time=2960.176..3370.425 rows=1 loops=128)
+ -> Hash Anti Join (cost=14742.77..28664.79 rows=19239 width=8)
(actual time=48.385..53.361 rows=1 loops=128)
Hash Cond: (m1.box_id = m2.box_id)
Join Filter: (m1.id < m2.id)
- -> Bitmap Heap Scan on message m1 (cost=544.16..13696.88
rows=28858 width=16) (actual time=2.320..6.204 rows=18487 loops=128)
+ -> Bitmap Heap Scan on message m1 (cost=544.16..13696.88
rows=28858 width=16) (actual time=1.928..5.502 rows=17875 loops=128)
Recheck Cond: (box_id = b.id)
- -> Bitmap Index Scan on "message_box_Idx"
(cost=0.00..536.94 rows=28858 width=0) (actual time=2.251..2.251
rows=18487 loops=128)
+ -> Bitmap Index Scan on "message_box_Idx"
(cost=0.00..536.94 rows=28858 width=0) (actual time=1.797..1.797
rows=18487 loops=128)
Index Cond: (box_id = b.id)
- -> Hash (cost=13696.88..13696.88 rows=28858 width=16)
(actual time=12.632..12.632 rows=19720 loops=120)
- Buckets: 4096 Batches: 4 (originally 2) Memory Usage: 1787kB
- -> Bitmap Heap Scan on message m2
(cost=544.16..13696.88 rows=28858 width=16) (actual time=1.668..6.619
rows=19720 loops=120)
+ -> Hash (cost=13696.88..13696.88 rows=28858 width=16)
(actual time=11.603..11.603 rows=20248 loops=113)
+ Buckets: 4096 Batches: 4 (originally 2) Memory Usage: 1423kB
+ -> Bitmap Heap Scan on message m2
(cost=544.16..13696.88 rows=28858 width=16) (actual time=1.838..6.886
rows=20248 loops=113)
Recheck Cond: (box_id = b.id)
- -> Bitmap Index Scan on "message_box_Idx"
(cost=0.00..536.94 rows=28858 width=0) (actual time=1.602..1.602
rows=19720 loops=120)
+ -> Bitmap Index Scan on "message_box_Idx"
(cost=0.00..536.94 rows=28858 width=0) (actual time=1.743..1.743
rows=20903 loops=113)
Index Cond: (box_id = b.id)
- Total runtime: 431520.186 ms
+ Total runtime: 6940.369 ms

That's pretty odd.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company