Re: 8.1 -- very slow query time because of "BETWEEN" (dbmail)

Ahhh. I knew troubleshooting this would lead to cool new discoveries and troubleshooting tools. I apologize if Yahoo jacks the formatting up:

EXPLAIN ANALYZE
SELECT message_idnr,headername,headervalue
FROM dbmail_headervalue v JOIN dbmail_messages m ON v.physmessage_id=m.physmessage_id
JOIN dbmail_headername n ON v.headername_id=n.id
WHERE m.mailbox_idnr = 417 AND message_idnr BETWEEN 253775 AND 253775 AND lower(headername)
IN ('from','to','cc','subject','date','message-id','priority','x-priority','references','newsgroups','in-reply-to','content-type');

"Hash Join (cost=166.74..46797.70 rows=1310 width=258) (actual time=4060.356..4142.813 rows=6 loops=1)"
" Hash Cond: ("outer".headername_id = "inner".id)"
" -> Hash Join (cost=22.27..46528.32 rows=22360 width=48) (actual time=4006.255..4088.688 rows=17 loops=1)"
" Hash Cond: ("outer".physmessage_id = "inner".physmessage_id)"
" -> Seq Scan on dbmail_headervalue v (cost=0.00..38828.97 rows=1490697 width=48) (actual time=0.085..2628.264 rows=1474315 loops=1)"
" -> Hash (cost=22.26..22.26 rows=3 width=16) (actual time=0.198..0.198 rows=1 loops=1)"
" -> Bitmap Heap Scan on dbmail_messages m (cost=10.54..22.26 rows=3 width=16) (actual time=0.170..0.172 rows=1 loops=1)"
" Recheck Cond: ((message_idnr >= 253775) AND (message_idnr <= 253775) AND (mailbox_idnr = 417))"
" -> Bitmap Index Scan on dbmail_messages_bwn (cost=0.00..10.54 rows=3 width=0) (actual time=0.103..0.103 rows=1 loops=1)"
" Index Cond: ((message_idnr >= 253775) AND (message_idnr <= 253775) AND (mailbox_idnr = 417))"
" -> Hash (cost=144.20..144.20 rows=109 width=226) (actual time=53.976..53.976 rows=30 loops=1)"
" -> Seq Scan on dbmail_headername n (cost=0.00..144.20 rows=109 width=226) (actual time=0.223..53.864 rows=30 loops=1)"
" Filter: ((lower((headername)::text) = 'from'::text) OR (lower((headername)::text) = 'to'::text) OR (lower((headername)::text) = 'cc'::text) OR (lower((headername)::text) = 'subject'::text) OR (lower((headername)::text) = 'date'::text) OR (lower((headername)::text) = 'message-id'::text) OR (lower((headername)::text) = 'priority'::text) OR (lower((headername)::text) = 'x-priority'::text) OR (lower((headername)::text) = 'references'::text) OR (lower((headername)::text) = 'newsgroups'::text) OR (lower((headername)::text) = 'in-reply-to'::text) OR (lower((headername)::text) = 'content-type'::text))"
"Total runtime: 4143.164 ms"

EXPLAIN ANALYZE
SELECT message_idnr,headername,headervalue
FROM dbmail_headervalue v JOIN dbmail_messages m ON v.physmessage_id=m.physmessage_id
JOIN dbmail_headername n ON v.headername_id=n.id
WHERE m.mailbox_idnr = 417 AND message_idnr = 253775 AND lower(headername)
IN ('from','to','cc','subject','date','message-id','priority','x-priority','references','newsgroups','in-reply-to','content-type');

"Hash Join (cost=228.56..16195.32 rows=437 width=258) (actual time=68.418..68.512 rows=6 loops=1)"
" Hash Cond: ("outer".headername_id = "inner".id)"
" -> Nested Loop (cost=84.09..16009.20 rows=7454 width=48) (actual time=13.905..13.973 rows=17 loops=1)"
" -> Index Scan using dbmail_messages_bwn on dbmail_messages m (cost=0.00..6.02 rows=1 width=16) (actual time=0.235..0.248 rows=1 loops=1)"
" Index Cond: ((message_idnr = 253775) AND (mailbox_idnr = 417))"
" -> 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)"
" -> Hash (cost=144.20..144.20 rows=109 width=226) (actual time=54.464..54.464 rows=30 loops=1)"
" -> Seq Scan on dbmail_headername n (cost=0.00..144.20 rows=109 width=226) (actual time=0.127..54.381 rows=30 loops=1)"
" Filter: ((lower((headername)::text) = 'from'::text) OR (lower((headername)::text) = 'to'::text) OR (lower((headername)::text) = 'cc'::text) OR (lower((headername)::text) = 'subject'::text) OR (lower((headername)::text) = 'date'::text) OR (lower((headername)::text) = 'message-id'::text) OR (lower((headername)::text) = 'priority'::text) OR (lower((headername)::text) = 'x-priority'::text) OR (lower((headername)::text) = 'references'::text) OR (lower((headername)::text) = 'newsgroups'::text) OR (lower((headername)::text) = 'in-reply-to'::text) OR (lower((headername)::text) = 'content-type'::text))"
"Total runtime: 68.796 ms"

Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote: Brian Neu
writes:
> The strange part is that if you change the "BETWEEN" to just an "= 253775" . . . the query takes around 70ms.

Please show EXPLAIN ANALYZE output for both cases. I suppose it's
changing plans but it's not clear why.

> Is my answer to just upgrade to 8.2 ? Is this a known problem in 8.1 ?

8.1.which?

regards, tom lane