2011/5/31 Robert Haas <robertmhaas@xxxxxxxxx>: > On Thu, May 26, 2011 at 8:33 AM, panam <panam@xxxxxxx> 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
diff --git a/src/backend/executor/nodeHashjoin.c b/src/backend/executor/nodeHashjoin.c index 26da3b2..09c56f9 100644 --- a/src/backend/executor/nodeHashjoin.c +++ b/src/backend/executor/nodeHashjoin.c @@ -14,6 +14,7 @@ */ #include "postgres.h" +#include "miscadmin.h" #include "executor/executor.h" #include "executor/hashjoin.h" @@ -108,6 +109,7 @@ ExecHashJoin(HashJoinState *node) */ for (;;) { + CHECK_FOR_INTERRUPTS(); switch (node->hj_JoinState) { case HJ_BUILD_HASHTABLE:
-- Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance