Re: Hash Anti Join performance degradation - Mailing list pgsql-performance

2011/5/31 Robert Haas <robertmhaas@gmail.com>:
> On Thu, May 26, 2011 at 8:33 AM, panam <panam@gmx.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.

Yes, while here I noticed that the query was long to be killed.
I added a CHECK_FOR_INTERRUPT() in the for(;;) loop in nodeHashjoin.c.
It fixes the delay when trying to kill but I don't know about
performance impact this can have in this place of the code.

--
Cédric Villemain               2ndQuadrant
http://2ndQuadrant.fr/     PostgreSQL : Expertise, Formation et Support