Re: PGSQL 7.4 -> 8.1 migration & performance problem

"Philippe Lang" <philippe(dot)lang(at)attiksystem(dot)ch> writes:
> Here are both EXPLAIN ANALYSE results, plus the query itself:
> Postgresql 7.4.5: http://www.attiksystem.ch/explain_analyze_74.txt
> Postgresql 8.1.4: http://www.attiksystem.ch/explain_analyze_81.txt
> Query is here: http://www.attiksystem.ch/big_query.txt

My goodness, that is one big ugly query :-(

Trawling through the EXPLAIN ANALYZE results, it seems that the lossage
comes from the repeated occurrences of this pattern:

SELECT travaux_en_cours_mvu FROM lignes_workflows AS lw
INNER JOIN workflows AS w
ON lw.id_workflow = w.id
WHERE w.code_article = lignes_commandes.code_article
AND w.code_type_workflow = commandes.code_type_workflow
AND SUBSTRING(lw.code_etape FROM 1 FOR 3) = SUBSTRING(etapes_lignes_commandes.code_etape FROM 1 FOR 3)
AND lw.ordre = etapes_lignes_commandes.ordre

7.4 is doing this as

-> Nested Loop (cost=0.00..37.28 rows=1 width=8) (actual time=0.056..0.087 rows=1 loops=13653)
-> Index Scan using w_code_article on workflows w (cost=0.00..15.76 rows=1 width=4) (actual time=0.016..0.024 rows=1 loops=13653)
Index Cond: (code_article = $1)
Filter: (code_type_workflow = $2)
-> Index Scan using lw_id_workflow on lignes_workflows lw (cost=0.00..21.51 rows=1 width=12) (actual time=0.023..0.036 rows=1 loops=13651)
Index Cond: (lw.id_workflow = "outer".id)
Filter: (("substring"((code_etape)::text, 1, 3) = "substring"(($3)::text, 1, 3)) AND (ordre = $4))

8.1 is doing

-> Nested Loop (cost=18.93..26.84 rows=1 width=8) (actual time=0.431..0.434 rows=1 loops=13630)
-> Bitmap Heap Scan on workflows w (cost=6.63..10.51 rows=1 width=4) (actual time=0.107..0.107 rows=1 loops=13630)
Recheck Cond: ((code_article = $1) AND (code_type_workflow = $2))
-> BitmapAnd (cost=6.63..6.63 rows=1 width=0) (actual time=0.104..0.104 rows=0 loops=13630)
-> Bitmap Index Scan on w_code_article (cost=0.00..2.02 rows=5 width=0) (actual time=0.017..0.017 rows=5 loops=13630)
Index Cond: (code_article = $1)
-> Bitmap Index Scan on w_code_type_workflow (cost=0.00..4.36 rows=389 width=0) (actual time=0.083..0.083 rows=390 loops=13628)
Index Cond: (code_type_workflow = $2)
-> Bitmap Heap Scan on lignes_workflows lw (cost=12.30..16.31 rows=1 width=12) (actual time=0.312..0.313 rows=1 loops=13628)
Recheck Cond: ((lw.id_workflow = "outer".id) AND (lw.ordre = $4))
Filter: ("substring"((code_etape)::text, 1, 3) = "substring"(($3)::text, 1, 3))
-> BitmapAnd (cost=12.30..12.30 rows=1 width=0) (actual time=0.306..0.306 rows=0 loops=13628)
-> Bitmap Index Scan on lw_id_workflow (cost=0.00..2.02 rows=7 width=0) (actual time=0.009..0.009 rows=7 loops=13628)
Index Cond: (lw.id_workflow = "outer".id)
-> Bitmap Index Scan on lw_ordre (cost=0.00..10.03 rows=1437 width=0) (actual time=0.293..0.293 rows=1714 loops=13628)
Index Cond: (ordre = $4)

In the parts of the plan that do not depend on workflows/lignes_workflows
joins, 8.1 is consistently beating 7.4.

So basically 8.1 is being too optimistic about the value of ANDing
multiple indexes. If you try setting enable_bitmapscan off, you'll
probably find 8.1 beating 7.4 handily for this query. That's a really
blunt-instrument solution of course, and I wouldn't recommend it for
production because it'll probably kill performance elsewhere. What
might work better is to get rid of the indexes w_code_type_workflow and
lw_ordre --- do you have any queries where those are actually useful?

Meanwhile, I think I'm going to have to take another look at the bitmap
cost estimates ... it shouldn't be bothering to AND a 7-row result
with a 1437-row result, even if that does save six trips to the heap.

regards, tom lane