It's amazing sometimes how overlooking a "-z" can cost you 4 days of troubleshooting when you start looking in all the wrong places.
Tom, you nailed it. While this server gets vacuum'd, it had never been ANALYZE'd. I just plain missed this when setting up maintenance. I hang my head in IT administrator shame.
Thank you much for your help.
Tom Lane <tgl@sss.pgh.pa.us> wrote:
Brian Neu writes:
> Ahhh. I knew troubleshooting this would lead to cool new discoveries and troubleshooting tools. I apologize if Yahoo jacks the formatting up:
It's still readable ... seems the core of the problem is here:
> " -> Bitmap Heap Scan on dbmail_headervalue v (cost=84.09..15910.01 rows=7454 width=48) (actual time=13.653..13.678 rows=17 loops=1)"
> " Recheck Cond: (v.physmessage_id = "outer".physmessage_id)"
> " -> Bitmap Index Scan on dbmail_headervalue_1 (cost=0.00..84.09 rows=7454 width=0) (actual time=13.589..13.589 rows=17 loops=1)"
> " Index Cond: (v.physmessage_id = "outer".physmessage_id)"
In the slow case, the planner estimates it would have to do this scan 3
times not just once, when once is correct. (This is because range
estimation is a bit fuzzier than equality estimation. Estimating 3
matching rows instead of 1 is still well within reasonable error
though.) The problem is that it's estimating 7454 matching
dbmail_headervalue rows per outer row, when the truth is only 17; and
that results in a large overestimate of the cost of doing this scan,
which convinces it that it doesn't want to do it more than once.
So basically the trick here is to get that 7454 number closer to
reality. Has this table been ANALYZEd lately? If so, could we
see the pg_stats entry for the physmessage_id column?
regards, tom lane
---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend
