Slow query with 100% cpu - Mailing list pgsql-general

Postgresql 8.2.6, Fedora 8, 2 GB memory.

A query that used to perform in a few seconds is now taking 64 seconds
with 100% cpu:

fahstats=> explain analyze
fahstats-> select
fahstats->   donor::smallInt as new_members,
fahstats->   active_members,
fahstats->   d.data::date as day,
fahstats->   isodow(d.data::date)::smallInt as dow
fahstats-> from
fahstats->   team_active_members_history as tam
fahstats->   inner join
fahstats->   datas as d on d.data_serial = tam.serial_date
fahstats->   inner join
fahstats->   select_new_members(13802, 8) as nm on nm.data::date = d.data::date
fahstats-> where
fahstats->   team_number = 13802
fahstats->   and
fahstats->   d.data_serial = (
fahstats(>     select data_serial
fahstats(>     from datas
fahstats(>     where date_trunc('day', data) = date_trunc('day', d.data)
fahstats(>     order by data desc
fahstats(>     limit 1
fahstats(>     )
fahstats-> ;

     QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Hash Join  (cost=46026.35..120281.84 rows=1020 width=16) (actual
time=64110.099..64404.762 rows=56 loops=1)
   Hash Cond: ((d.data)::date = (nm.data)::date)
   ->  Hash Join  (cost=46001.35..120154.33 rows=204 width=12) (actual
time=3378.246..63602.774 rows=812 loops=1)
         Hash Cond: (d.data_serial = tam.serial_date)
         ->  Index Scan using data_ndx on datas d
(cost=0.00..73990.18 rows=32 width=12) (actual time=19.474..63583.966
rows=879 loops=1)
               Filter: (data_serial = (subplan))
               SubPlan
                 ->  Limit  (cost=0.00..11.69 rows=1 width=12) (actual
time=10.076..10.078 rows=1 loops=6302)
                       ->  Index Scan Backward using pk_data on datas
(cost=0.00..374.05 rows=32 width=12) (actual time=10.070..10.070
rows=1 loops=6302)
                             Filter: (date_trunc('day'::text, data) =
date_trunc('day'::text, $0))
         ->  Hash  (cost=45499.27..45499.27 rows=40167 width=8)
(actual time=10.398..10.398 rows=821 loops=1)
               ->  Bitmap Heap Scan on team_active_members_history tam
 (cost=664.25..45499.27 rows=40167 width=8) (actual time=0.428..9.110
rows=821 loops=1)
                     Recheck Cond: (team_number = 13802)
                     ->  Bitmap Index Scan on
ndx_team_active_members_history  (cost=0.00..654.21 rows=40167
width=0) (actual time=0.314..0.314 rows=821 loops=1)
                           Index Cond: (team_number = 13802)
   ->  Hash  (cost=12.50..12.50 rows=1000 width=12) (actual
time=794.528..794.528 rows=56 loops=1)
         ->  Function Scan on select_new_members nm  (cost=0.00..12.50
rows=1000 width=12) (actual time=794.356..794.411 rows=56 loops=1)
 Total runtime: 64405.040 ms
(18 rows)

I REINDEXed the database before this explain analyze. These are the
non commented lines of postgresql.conf

listen_addresses = '127.0.0.1,10.1.1.101'        # what IP address(es) to listen on;
max_connections = 150            # (change requires restart)
shared_buffers = 64MB            # min 128kB or max_connections*16kB
max_prepared_transactions = 150        # can be 0 or more
work_mem = 32MB                # min 64kB
maintenance_work_mem = 768MB        # min 1MB
max_stack_depth = 4MB            # min 100kB
max_fsm_pages = 1000000        # min max_fsm_relations*16, 6 bytes each
vacuum_cost_delay = 1000            # 0-1000 milliseconds
vacuum_cost_limit = 5000        # 0-10000 credits
bgwriter_lru_maxpages = 0        # 0-1000 buffers max written/round
bgwriter_all_maxpages = 0        # 0-1000 buffers max written/round
fsync = off                # turns forced synchronization on or off
full_page_writes = off
wal_buffers = 1024kB            # min 32kB
checkpoint_segments = 8            # in logfile segments, min 1, 16MB each
checkpoint_timeout = 10min        # range 30s-1h
effective_cache_size = 768MB
geqo_effort = 8            # range 1-10
default_statistics_target = 50        # range 1-1000
redirect_stderr = on            # Enable capturing of stderr into log
log_directory = 'pg_log'        # Directory where log files are written
log_truncate_on_rotation = on        # If on, any existing log file of the same
log_rotation_age = 1d            # Automatic rotation of logfiles will
log_rotation_size = 0            # Automatic rotation of logfiles will
debug_pretty_print = on
datestyle = 'iso, ymd'
timezone = UTC            # actually, defaults to TZ
extra_float_digits = 2            # min -15, max 2
lc_messages = 'en_US.UTF-8'            # locale for system error message
lc_monetary = 'en_US.UTF-8'            # locale for monetary formatting
lc_numeric = 'en_US.UTF-8'            # locale for number formatting
lc_time = 'en_US.UTF-8'                # locale for time formatting



Same query in another computer with 4 GB memory, 8.2.6, Fedora 8:

fahstats=> explain analyze
fahstats-> select
fahstats->   donor::smallInt as new_members,
fahstats->   active_members,
fahstats->   d.data::date as day,
fahstats->   isodow(d.data::date)::smallInt as dow
fahstats-> from
fahstats->   team_active_members_history as tam
fahstats->   inner join
fahstats->   datas as d on d.data_serial = tam.serial_date
fahstats->   inner join
fahstats->   select_new_members(13802, 8) as nm on nm.data::date = d.data::date
fahstats-> where
fahstats->   team_number = 8
fahstats->   and
fahstats->   d.data_serial = (
fahstats(>     select data_serial
fahstats(>     from datas
fahstats(>     where date_trunc('day', data) = date_trunc('day', d.data)
fahstats(>     order by data desc
fahstats(>     limit 1
fahstats(>     )
fahstats-> ;

              QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.00..12990.31 rows=10 width=16) (actual
time=431.023..3448.132 rows=56 loops=1)
   Join Filter: ((nm.data)::date = (d.data)::date)
   ->  Nested Loop  (cost=0.00..12930.16 rows=2 width=12) (actual
time=0.080..2977.293 rows=823 loops=1)
         ->  Index Scan using ndx_team_active_members_history on
team_active_members_history tam  (cost=0.00..1221.93 rows=449 width=8)
(actual time=0.040..2.521 rows=832 loops=1)
               Index Cond: (team_number = 8)
         ->  Index Scan using data_ndx on datas d  (cost=0.00..26.06
rows=1 width=12) (actual time=3.574..3.574 rows=1 loops=832)
               Index Cond: (d.data_serial = tam.serial_date)
               Filter: (data_serial = (subplan))
               SubPlan
                 ->  Limit  (cost=0.00..24.38 rows=1 width=12) (actual
time=3.589..3.589 rows=1 loops=823)
                       ->  Index Scan Backward using pk_data on datas
(cost=0.00..780.05 rows=32 width=12) (actual time=3.588..3.588 rows=1
loops=823)
                             Filter: (date_trunc('day'::text, data) =
date_trunc('day'::text, $0))
   ->  Function Scan on select_new_members nm  (cost=0.00..12.50
rows=1000 width=12) (actual time=0.524..0.534 rows=56 loops=823)
 Total runtime: 3448.225 ms
(14 rows)

Regards, Clodoaldo Pinto Neto