Thread: select off of a view going slowly
I have a view called error_log. Most selects off of this view will
return 0 rows and in fact almost always, the error_log will be
completely empty. It's taking almost .2 seconds to run a 'select count
from error_log where site_id=1 and host_id=2'.
Creating an index on a view would seem counterintuitive, but I tried
anyway. Surprisingly, it did create something (\d error_log_index
showed the index) but a subsequent \d on the error_log view and on the
table it is created from did not show an associated index, and nothing
got faster anyway.
I've included the EXPLAIN results below, I'm not real good at
interpreting them yet, so I'm not real sure what I am looking for.
Any ideas?
Thanks,
Fran
monitoring=# \d error_log
View "error_log"
Attribute | Type | Modifier
-----------+---------+----------
count | integer |
site_id | bigint |
host_id | bigint |
View definition: SELECT count(*) AS count, log.site_id, log.host_id FROM
log WHE
RE (((log.status = 'CRIT'::"varchar") OR (log.status =
'EMERG'::"varchar")) AND
(log.tstamp > (now() - '1 00:00'::"interval"))) GROUP BY log.site_id,
log.host_i
d;
monitoring=# explain select count from error_log where site_id=24 and
host_id=67
;
NOTICE: QUERY PLAN:
Aggregate (cost=18398.08..18398.09 rows=0 width=16)
-> Group (cost=18398.08..18398.09 rows=1 width=16)
-> Sort (cost=18398.08..18398.08 rows=1 width=16)
-> Seq Scan on log (cost=0.00..18398.07 rows=1 width=16)
EXPLAIN
monitoring=# select count from error_log where site_id=24 and
host_id=67;
count
-------
(0 rows)
monitoring=#
010507.11:03:11.320 [6801] StartTransactionCommand
010507.11:03:11.321 [6801] query: select count from error_log where
site_id=24 and host_id=67;
010507.11:03:11.321 [6801] ProcessQuery
010507.11:03:12.495 [6801] CommitTransactionCommand
Fran Fabrizio <ffabrizio@exchange.webmd.net> writes:
> Creating an index on a view would seem counterintuitive, but I tried
> anyway.
The system should not have let you do this (and 7.1 doesn't).
> View definition: SELECT count(*) AS count, log.site_id, log.host_id FROM
> log WHERE (((log.status = 'CRIT'::"varchar") OR (log.status =
> 'EMERG'::"varchar")) AND
> (log.tstamp > (now() - '1 00:00'::"interval"))) GROUP BY log.site_id,
> log.host_id;
Hm. An index on log.tstamp might help.
BTW, I would recommend an update to 7.1 before you go much further.
Older releases have lots of problems with grouped views.
regards, tom lane
Hello all,
I've finished upgrading to 7.1 and I'm still having trouble getting this view
to run respectably.
Does a view run its query every time I select from the view? I had been
assuming that the view recreates itself when I modify the table to which the
view is attached, but Tom mentioned that adding an index on tstamp (which i
did) might help, which would imply that every time I select from the view it
is querying the original table (since tstamp lives there but not in the
view). I did add the index (and one on status) with no effects.
It's still taking wayyyy long to run the select against this view (see stats
below). I've included some select queries and their stats, a \d of the
error_log view, a \d of the log table from which it is derived, and an
EXPLAIN on the typical-case query.
I'm not real familiar with views so maybe I am not using them in the proper
way.Any pointers at all would be greatly appreciated, as this seems to be the
last hurdle I need to get over before I have a usable application. Thank you
very much! (Also, I promise that once I get this application working and can
get my boss off my back, I'll take some time and learn about views, and
relational databases in general, more deeply. Then maybe I can help out
around here some more! =)
Thanks,
Fran
monitoring=# select * from error_log;
count | site_id | host_id
-------+---------+---------
8 | 34 | 88
8 | 34 | 110
(2 rows)
The query statistics:
2001-05-07 16:31:57 DEBUG: query: select * from error_log;
2001-05-07 16:31:57 DEBUG: ProcessQuery
2001-05-07 16:32:02 DEBUG: CommitTransactionCommand
QUERY STATISTICS
! system usage stats:
! 4.428527 elapsed 3.720000 user 0.710000 system sec
monitoring=# select * from error_log where site_id=34 and host_id=88;
count | site_id | host_id
-------+---------+---------
8 | 34 | 88
(1 row)
2001-05-07 16:32:46 DEBUG: query: select * from error_log where site_id=34
and host_id=88;
2001-05-07 16:32:46 DEBUG: ProcessQuery
2001-05-07 16:32:48 DEBUG: CommitTransactionCommand
QUERY STATISTICS
! system usage stats:
! 2.152403 elapsed 1.530000 user 0.620000 system sec
monitoring=# \d error_log
View "error_log"
Attribute | Type | Modifier
-----------+---------+----------
count | integer |
site_id | bigint |
host_id | bigint |
View definition: SELECT count(*) AS count, log.site_id, log.host_id FROM log
WHE
RE (((log.status = 'CRIT'::"varchar") OR (log.status = 'EMERG'::"varchar"))
AND
(log.tstamp > (now() - '1 day'::"interval"))) GROUP BY log.site_id,
log.host_id;
monitoring=# \d log
Table "log"
Attribute | Type | Modifier
--------------+--------------------------+----------
site_id | bigint |
host_id | bigint |
fqdn | character varying | not null
site | character varying | not null
region | character varying | not null
hostname | character varying | not null
product | character varying | not null
class | character varying | not null
subclass | character varying | not null
status | character varying | not null
msg | character varying | not null
remote_stamp | timestamp with time zone | not null
tstamp | timestamp with time zone | not null
Indices: log_hostid_index,
log_siteid_hostid_index,
log_siteid_index,
log_status_index,
log_tstamp_index
monitoring=# explain select * from error_log where site_id=34 and host_id=88;
NOTICE: QUERY PLAN:
Subquery Scan error_log (cost=33145.20..33145.21 rows=1 width=16)
-> Aggregate (cost=33145.20..33145.21 rows=1 width=16)
-> Group (cost=33145.20..33145.21 rows=1 width=16)
-> Sort (cost=33145.20..33145.20 rows=1 width=16)
-> Seq Scan on log (cost=0.00..33145.19 rows=1
width=16)
EXPLAIN
monitoring=#
Fran Fabrizio <ffabrizio@exchange.webmd.net> writes: > Does a view run its query every time I select from the view? Yes. That's sort of the point. > View definition: SELECT count(*) AS count, log.site_id, log.host_id FROM log > WHERE (((log.status = 'CRIT'::"varchar") OR (log.status = 'EMERG'::"varchar")) > AND (log.tstamp > (now() - '1 day'::"interval"))) GROUP BY log.site_id, > log.host_id; > monitoring=# \d log > Table "log" > Attribute | Type | Modifier > --------------+--------------------------+---------- > site_id | bigint | > host_id | bigint | > fqdn | character varying | not null > site | character varying | not null > region | character varying | not null > hostname | character varying | not null > product | character varying | not null > class | character varying | not null > subclass | character varying | not null > status | character varying | not null > msg | character varying | not null > remote_stamp | timestamp with time zone | not null > tstamp | timestamp with time zone | not null > Indices: log_hostid_index, > log_siteid_hostid_index, > log_siteid_index, > log_status_index, > log_tstamp_index > monitoring=# explain select * from error_log where site_id=34 and host_id=88; > NOTICE: QUERY PLAN: > Subquery Scan error_log (cost=33145.20..33145.21 rows=1 width=16) > -> Aggregate (cost=33145.20..33145.21 rows=1 width=16) > -> Group (cost=33145.20..33145.21 rows=1 width=16) > -> Sort (cost=33145.20..33145.20 rows=1 width=16) > -> Seq Scan on log (cost=0.00..33145.19 rows=1 > width=16) You need to get rid of that bottom seqscan. Unfortunately, you're running into a couple of deficiencies that prevent Postgres from choosing either of the reasonable indexes (siteid_hostid or tstamp). The one that's easiest to get around is siteid/hostid: try explain select * from error_log where site_id=34::int8 and host_id=88::int8; As you've written it, the WHERE clause contains int8 vs. int4 comparisons, which the planner is not smart about turning into operations that have something to do with an int8 index. So you need to make the comparisons look like int8 vs. int8. (Alternatively: do the siteid and hostid really need to be bigint? Could you get by with int4, at least for a release or two more?) The other possibility is to use the tstamp index with the log.tstamp > (now() - '1 day'::"interval") clause. But this is not considered indexable because "now() - '1 day'::interval" is not known to reduce to a constant. It's possible to hack up your own function to allow this to be treated as a constant, see previous discussions eg http://www.geocrawler.com/archives/3/10/2000/9/0/4324734/ We have plans to address both of these issues in future releases... regards, tom lane
Tom, your suggestions have had an interesting and unexpected result......remember
the original query 'select count from error_log where site_id=39 and
host_id=99'....you suggested that I change this to add the ::int8 and enable use of
the index. I did this and the EXPLAIN results definitely show the difference.
However, with the new query, depending on the values of site_id and host_id,
execution time varies from .002 to 1.617 seconds!
Very odd, no? I wonder why the drastic (80000% variation!) difference in execution
times? I've vacuum'ed and vacuum anaylzed the table, too.
EXPLAIN
monitoring=# explain select count from error_log where site_id=39::int8 and
host_id=99::int8;
NOTICE: QUERY PLAN:
Subquery Scan error_log (cost=0.00..4.90 rows=1 width=16)
-> Aggregate (cost=0.00..4.90 rows=1 width=16)
-> Group (cost=0.00..4.90 rows=1 width=16)
-> Index Scan using log_siteid_hostid_index on log (cost=0.00..4.90
rows=1 width=16)
monitoring=# explain select count from error_log where site_id=14::int8 and
host_id=41::int8;
NOTICE: QUERY PLAN:
Subquery Scan error_log (cost=0.00..4.90 rows=1 width=16)
-> Aggregate (cost=0.00..4.90 rows=1 width=16)
-> Group (cost=0.00..4.90 rows=1 width=16)
-> Index Scan using log_siteid_hostid_index on log (cost=0.00..4.90
rows=1 width=16)
EXPLAIN
monitoring=#
2001-05-08 14:21:17 DEBUG: query: select count from error_log where
site_id=39::int8 and host_id=99::int8;
QUERY STATISTICS
! system usage stats:
! 0.002321 elapsed 0.000000 user 0.000000 system sec
2001-05-08 14:21:21 DEBUG: query: select count from error_log where
site_id=14::int8 and host_id=41::int8;
QUERY STATISTICS
! system usage stats:
! 1.617670 elapsed 0.810000 user 0.810000 system sec
Fran Fabrizio <ffabrizio@exchange.webmd.net> writes:
> However, with the new query, depending on the values of site_id and host_id,
> execution time varies from .002 to 1.617 seconds!
Does one site and/or host have many more table entries than the other?
regards, tom lane
Tom Lane wrote: > Fran Fabrizio <ffabrizio@exchange.webmd.net> writes: > > However, with the new query, depending on the values of site_id and host_id, > > execution time varies from .002 to 1.617 seconds! > > Does one site and/or host have many more table entries than the other? I just tried clustering the table around that siteid_hostid_index and it did reduce the number of blocks read from 15000 to 2200 for the query. However, still running pretty slow (.9 second). I'm beginning to think I need something more robust than a view. Perhaps I need to build an error_log table that gets updated via trigger upon insert into log. We shall see. Thanks, Fran