SEO

Hi All,

I have a very slow left outer join that speeds up by more then 1000
times when I turn set enable_seqscan=off. This is not the query I
actually do in my application, but is a simplified one that singles out
the part that is really slow. All of the columns involved in the query
have indexes on them, but unless I set enable_seqscan=off the planner is
doing a sequential scan instead of using the indexes. I'm hoping there
is something simple I am doing wrong that someone can point out to me.
I am using version 8.1.5.

So here is the explain analyze output first with enable_seqscan=on, and
the second with enable_seqscan=off:

mdsdb=# explain analyze select backupobjects.record_id from
backupobjects left outer join backup_location using(record_id) where
backup_id = 1071;

QUERY PLAN

------------------------------------------------------------------------
------------------------------------------------------------------------
-----
Hash Join (cost=361299.50..1054312.92 rows=34805 width=8) (actual
time=1446.861..368723.597 rows=2789 loops=1)
Hash Cond: ("outer".record_id = "inner".record_id)
-> Seq Scan on backupobjects (cost=0.00..429929.79 rows=13136779
width=8) (actual time=5.165..359168.216 rows=13136779 loops=1)
-> Hash (cost=360207.21..360207.21 rows=436915 width=8) (actual
time=820.979..820.979 rows=2789 loops=1)
-> Bitmap Heap Scan on backup_location
(cost=3831.20..360207.21 rows=436915 width=8) (actual
time=797.463..818.269 rows=2789 loops=1)
Recheck Cond: (backup_id = 1071)
-> Bitmap Index Scan on backup_location_bid
(cost=0.00..3831.20 rows=436915 width=0) (actual time=59.592..59.592
rows=2789 loops=1)
Index Cond: (backup_id = 1071)
Total runtime: 368725.122 ms
(9 rows)

mdsdb=# explain analyze select backupobjects.record_id from
backupobjects left outer join backup_location using(record_id) where
backup_id = 1071;
QUERY
PLAN

------------------------------------------------------------------------
-----------------------------------------------------------------------
Nested Loop (cost=3833.21..1682311.27 rows=34805 width=8) (actual
time=103.132..201.808 rows=2789 loops=1)
-> Bitmap Heap Scan on backup_location (cost=3831.20..360207.21
rows=436915 width=8) (actual time=94.375..97.688 rows=2789 loops=1)
Recheck Cond: (backup_id = 1071)
-> Bitmap Index Scan on backup_location_bid
(cost=0.00..3831.20 rows=436915 width=0) (actual time=84.239..84.239
rows=2789 loops=1)
Index Cond: (backup_id = 1071)
-> Bitmap Heap Scan on backupobjects (cost=2.00..3.01 rows=1
width=8) (actual time=0.033..0.034 rows=1 loops=2789)
Recheck Cond: (backupobjects.record_id = "outer".record_id)
-> Bitmap Index Scan on backupobjects_pkey (cost=0.00..2.00
rows=1 width=0) (actual time=0.021..0.021 rows=1 loops=2789)
Index Cond: (backupobjects.record_id = "outer".record_id)
Total runtime: 203.378 ms
(10 rows)

Here are the two tables in the query:

mdsdb=# \d backup_location
Table "public.backup_location"
Column | Type | Modifiers
-----------+---------+-----------
record_id | bigint | not null
backup_id | integer | not null
Indexes:
"backup_location_pkey" PRIMARY KEY, btree (record_id, backup_id)
"backup_location_bid" btree (backup_id)
"backup_location_rid" btree (record_id)
Foreign-key constraints:
"backup_location_bfk" FOREIGN KEY (backup_id) REFERENCES
backups(backup_id) ON DELETE CASCADE

mdsdb=# \d backupobjects
Table "public.backupobjects"
Column | Type | Modifiers
----------------+-----------------------------+-----------
record_id | bigint | not null
dir_record_id | integer |
name | text |
extension | character varying(64) |
hash | character(40) |
mtime | timestamp without time zone |
size | bigint |
user_id | integer |
group_id | integer |
meta_data_hash | character(40) |
Indexes:
"backupobjects_pkey" PRIMARY KEY, btree (record_id)
"backupobjects_meta_data_hash_key" UNIQUE, btree (meta_data_hash)
"backupobjects_extension" btree (extension)
"backupobjects_hash" btree (hash)
"backupobjects_mtime" btree (mtime)
"backupobjects_size" btree (size)

Thanks,
Ed

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend

On May 29, 2007, at 19:16 , Tyrrill, Ed wrote:

> -----
> Hash Join (cost=361299.50..1054312.92 rows=34805 width=8) (actual
> time=1446.861..368723.597 rows=2789 loops=1)
> Hash Cond: ("outer".record_id = "inner".record_id)
> -> Seq Scan on backupobjects (cost=0.00..429929.79 rows=13136779
> width=8) (actual time=5.165..359168.216 rows=13136779 loops=1)
> -> Hash (cost=360207.21..360207.21 rows=436915 width=8) (actual
> time=820.979..820.979 rows=2789 loops=1)
> -> Bitmap Heap Scan on backup_location
> (cost=3831.20..360207.21 rows=436915 width=8) (actual
> time=797.463..818.269 rows=2789 loops=1)
> Recheck Cond: (backup_id = 1071)
> -> Bitmap Index Scan on backup_location_bid
> (cost=0.00..3831.20 rows=436915 width=0) (actual time=59.592..59.592
> rows=2789 loops=1)

Off the cuff, when was the last time you vacuumed or ran ANALYZE?
Your row estimates look off by a couple orders of magnitude. With up-
to-date statistics the planner might do a better job.

As for any other improvements, I'll leave that to those that know
more than I.

Michael Glaesemann
grzm seespotcode net



---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

On Tue, 29 May 2007 17:16:57 -0700, "Tyrrill, Ed" <tyrrill_ed@emc.com> wrote:
> mdsdb=# explain analyze select backupobjects.record_id from
> backupobjects left outer join backup_location using(record_id) where
> backup_id = 1071;
[...]
>
> Here are the two tables in the query:
>
> mdsdb=# \d backup_location
> Table "public.backup_location"
> Column | Type | Modifiers
> -----------+---------+-----------
> record_id | bigint | not null
> backup_id | integer | not null
[...]
>
> mdsdb=# \d backupobjects
> Table "public.backupobjects"
> Column | Type | Modifiers
> ----------------+-----------------------------+-----------
> record_id | bigint | not null
> dir_record_id | integer |
> name | text |
> extension | character varying(64) |
> hash | character(40) |
> mtime | timestamp without time zone |
> size | bigint |
> user_id | integer |
> group_id | integer |
> meta_data_hash | character(40) |

Why are you using left join?

The where condition is going to force the row to exist.

klint.

+---------------------------------------+-----------------+
: Klint Gore : "Non rhyming :
: EMail : kg@kgb.une.edu.au : slang - the :
: Snail : A.B.R.I. : possibilities :
: Mail University of New England : are useless" :
: Armidale NSW 2351 Australia : L.J.J. :
: Fax : +61 2 6772 5376 : :
+---------------------------------------+-----------------+

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings

Klint Gore <kg@kgb.une.edu.au> writes:
> On Tue, 29 May 2007 17:16:57 -0700, "Tyrrill, Ed" <tyrrill_ed@emc.com> wrote:
>> mdsdb=# explain analyze select backupobjects.record_id from
>> backupobjects left outer join backup_location using(record_id) where
>> backup_id = 1071;

> Why are you using left join?
> The where condition is going to force the row to exist.

Which indeed the planner figured out (note the lack of any mention of
left join in the EXPLAIN result). Michael put his finger on the problem
though: there's something way off about the rowcount estimate here:

> -> Bitmap Heap Scan on backup_location (cost=3831.20..360207.21
> rows=436915 width=8) (actual time=94.375..97.688 rows=2789 loops=1)
> Recheck Cond: (backup_id = 1071)
> -> Bitmap Index Scan on backup_location_bid
> (cost=0.00..3831.20 rows=436915 width=0) (actual time=84.239..84.239
> rows=2789 loops=1)
> Index Cond: (backup_id = 1071)

With such a simple index condition the planner really ought to be able
to come close to the right rowcount estimate. Check for vacuuming
problems, check for lack of ANALYZE, consider whether you need to bump
up the statistics target ...

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend

Michael Glaesemann <grzm@seespotcode.net> writes:
> Off the cuff, when was the last time you vacuumed or ran ANALYZE?
> Your row estimates look off by a couple orders of magnitude. With up-
> to-date statistics the planner might do a better job.
>
> As for any other improvements, I'll leave that to those that know
> more than I.
>
> Michael Glaesemann
> grzm seespotcode net

The script that imports data into these tables runs a vacuum analyze at
the end so there has been no new data added to the tables since the last
time vacuum analyze was run.


---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

Tom Lane <tgl@sss.pgh.pa.us> writes:
> Klint Gore <kg@kgb.une.edu.au> writes:
>> On Tue, 29 May 2007 17:16:57 -0700, "Tyrrill, Ed"
<tyrrill_ed@emc.com> wrote:
>>> mdsdb=# explain analyze select backupobjects.record_id from
>>> backupobjects left outer join backup_location using(record_id) where
>>> backup_id = 1071;
>
>> Why are you using left join?
>> The where condition is going to force the row to exist.

This select is a simplified version of what I am really doing that still
exhibits the problem I am having. I know this small query doesn't
really make sense, but I thought it would be easier to evaluate
something small rather then the entire query.

>
> Which indeed the planner figured out (note the lack of any mention of
> left join in the EXPLAIN result). Michael put his finger on the
problem
> though: there's something way off about the rowcount estimate here:
>
>> -> Bitmap Heap Scan on backup_location (cost=3831.20..360207.21
>> rows=436915 width=8) (actual time=94.375..97.688 rows=2789 loops=1)
>> Recheck Cond: (backup_id = 1071)
>> -> Bitmap Index Scan on backup_location_bid
>> (cost=0.00..3831.20 rows=436915 width=0) (actual time=84.239..84.239
>> rows=2789 loops=1)
>> Index Cond: (backup_id = 1071)
>
> With such a simple index condition the planner really ought to be able
> to come close to the right rowcount estimate. Check for vacuuming
> problems, check for lack of ANALYZE, consider whether you need to bump
> up the statistics target ...
>
> regards, tom lane

I did a vacuum analyze after inserting all the data. Is there possibly
a bug in analyze in 8.1.5-6? I know it says rows=436915, but the last
time the backup_location table has had that little data in it was a
couple months ago, and analyze has been run many times since then.
Currently it has over 160 million rows.

Thanks,
Ed

---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

"Tyrrill, Ed" <tyrrill_ed@emc.com> writes:
> I did a vacuum analyze after inserting all the data. Is there possibly
> a bug in analyze in 8.1.5-6? I know it says rows=3D436915, but the last
> time the backup_location table has had that little data in it was a
> couple months ago, and analyze has been run many times since then.
> Currently it has over 160 million rows.

Possibly you need a larger statistics target for that table.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend