Re: Stranger than fiction - EXPLAIN results

I'm sorry that I did not send the EXPLAIN results along with my original email,
I had no idea this command existed (I'm a first-week rookie with postgres!)

Also, I did not know about vacuum, and apparently, that was the culprit! After
vacuum'ing, times went from .433 sec/query to .001. Holy moly! I read up on
vacuum in the Postgres book we have, and I guess since I've been doing so much
testing, I've been really updating a LOT of rows in the table, because here's
what the vacuum results looked like:

010502.11:13:46.469 [3029] StartTransactionCommand
010502.11:13:46.469 [3029] query: vacuum status;
010502.11:13:46.469 [3029] ProcessUtility: vacuum status;
010502.11:13:46.470 [3029] DEBUG: --Relation status--
010502.11:13:46.978 [3029] DEBUG: Pages 5700: Changed 0, reaped 5700, Empty
0, New 0; Tup 224: Vac 364719, Keep/VTL 0/0, Crash 0, UnUsed 0, MinLen 100,
MaxLen 208; Re-using: Free/Avail. Space 45161576/45149008; EndEmpty/Avail.
Pages 1/5698. CPU 0.25s/0.25u sec.
010502.11:13:46.980 [3029] DEBUG: Index status_5_column_index: Pages 4;
Tuples 224: Deleted 0. CPU 0.01s/0.00u sec.
010502.11:13:50.641 [3029] DEBUG: Index status_site_id_key: Pages 920; Tuples
224: Deleted 364719. CPU 0.24s/3.36u sec.
010502.11:13:54.335 [3029] DEBUG: Index status_host_id_key: Pages 930; Tuples
224: Deleted 364719. CPU 0.17s/3.46u sec.
010502.11:13:55.252 [3029] DEBUG: Rel status: Pages: 5700 --> 4; Tuple(s)
moved: 224. CPU 0.78s/0.14u sec.
010502.11:13:55.256 [3029] DEBUG: Index status_5_column_index: Pages 6;
Tuples 224: Deleted 224. CPU 0.00s/0.00u sec.
010502.11:13:55.307 [3029] DEBUG: Index status_site_id_key: Pages 920; Tuples
224: Deleted 224. CPU 0.05s/0.00u sec.
010502.11:13:55.358 [3029] DEBUG: Index status_host_id_key: Pages 930; Tuples
224: Deleted 224. CPU 0.05s/0.00u sec.
010502.11:13:55.385 [3029] CommitTransactionCommand

Can someone explain to me these results? What does it mean when it says
Deleted 364719 of Index status_site_id_key, for example? And then later on it
goes back to that index and deletes another 224. What is going on internally?

Also, after vacuuming the table, I reran my select query....

010502.11:22:57.579 [3029] StartTransactionCommand
010502.11:22:57.579 [3029] query: select * from status s where s.site_id = 18
and s.host_id = 49
and s.product = 'BETA' and s.class = 'APPS' and s.subclass = 'MONITOR' ;
010502.11:22:57.581 [3029] ProcessQuery
010502.11:22:57.582 [3029] CommitTransactionCommand

As you can see, .001s execution time! However - EXPLAIN still shows:

010502.11:24:05.001 [3029] StartTransactionCommand
010502.11:24:05.002 [3029] query: explain select * from status s where
s.site_id = 18 and s.host_id = 49
and s.product = 'BETA' and s.class = 'APPS' and s.subclass = 'MONITOR' ;
010502.11:24:05.002 [3029] ProcessUtility: explain select * from status s
where s.site_id = 18 and s.host_id = 49
and s.product = 'BETA' and s.class = 'APPS' and s.subclass = 'MONITOR' ;
010502.11:24:05.003 [3029] NOTICE: QUERY PLAN:

Seq Scan on status s (cost=0.00..9.04 rows=1 width=84)

010502.11:24:05.003 [3029] CommitTransactionCommand

Which is incorrect because it should be using my index, shouldn't it? Here is
how I created my index:

monitoring=# create index status_5_column_index on status (site_id, host_id,
product, class, subclass);

And a desc. of the table shows the index is there:

monitoring=# \d status
Table "status"
Attribute | Type | Modifier
-----------+-----------+----------
site_id | bigint | not null
host_id | bigint | not null
product | varchar() | not null
class | varchar() | not null
subclass | varchar() | not null
status | varchar() | not null
msg | varchar() |
tstamp | timestamp |
Indices: status_5_column_index,
status_host_id_key,
status_site_id_key

monitoring=#

So it's puzzling me why it's still doing a Seq. Scan vs. an Index Scan. Any
ideas?

Thanks,
Fran