The problem appeared when I found the queries suddenly taking longer
than usual. Investigation showed that execution time greatly depends
on the way the queries are invoked.
Consider fn(x) simply a macro containing a plain SQL SELECT statement
returning SETOF (further detail follows below):
# SELECT fn(x);
-> 6.3 sec.
# SELECT a from fn(x) as a;
-> 1.3 sec.
Further investigation with auto_explain shows different plans being
chosen. The slower one uses an Index Only Scan, which seems to perform
bad. Slightly increasing random_page_cost solves this, but this seems
the wrong way, because we are on SSD+ZFS, where random_page_cost
actually should be DEcreased, as there is no difference if random or
sequential.
During this effort I accidentally came upon from_collapse_limit,
and setting it off significantly changed things:
# SET from_collapse_limit = 1;
# SELECT fn(x);
-> 0.6 sec.
# SELECT a from fn(x) as a;
-> 1.2 sec.
The plans look different now (obviousely), and again the difference
between the two invocations comes from an an Index Only Scan, but
this time the Index Only Scan is faster. So now we can reduce
random_page_cost in order to better reflect physical circumstances,
and then both invocations will be fast.
>From here it looks like from_collapse is the problem.
Now for the details:
VACUUM ANALYZE is up to date, and all respective configurations are as
default.
The query itself contains three nested SELECTS working all on the same
table. The table is 400'000 rows, 36 MB. (The machine is a pentium-3,
which is my router - so don't be surprized about the comparatively long
execution times.)
This is the (critical part of the) query - let $1 be something like
'2017-03-03':
SELECT MAX(quotes.datum) AS ratedate, aktkurs.*
FROM quotes, wpnames, places,
(SELECT quotes.datum, close, quotes.wpname_id, places.waehrung
FROM quotes, wpnames, places,
(SELECT MAX(datum) AS datum, wpname_id
FROM quotes
WHERE datum <= $1
GROUP BY wpname_id) AS newest
WHERE newest.datum = quotes.datum
AND newest.wpname_id = quotes.wpname_id
AND quotes.wpname_id = wpnames.id
AND wpnames.place_id = places.id) AS aktkurs
WHERE quotes.wpname_id = wpnames.id
AND wpnames.place_id = places.id AND places.platz = 'WAEHR'
AND wpnames.nummer = aktkurs.waehrung
AND quotes.datum <= aktkurs.datum
GROUP BY aktkurs.datum, aktkurs.close, aktkurs.wpname_id,
aktkurs.waehrung
Here are the (respective parts of the) tables:
CREATE TABLE public.quotes -- rows = 405466, 36 MB
(
id integer NOT NULL DEFAULT nextval('quotes_id_seq'::regclass),
wpname_id integer NOT NULL,
datum date NOT NULL,
close double precision NOT NULL,
CONSTRAINT quotes_pkey PRIMARY KEY (id),
CONSTRAINT fk_rails_626c320689 FOREIGN KEY (wpname_id)
REFERENCES public.wpnames (id) MATCH SIMPLE
ON UPDATE NO ACTION ON DELETE NO ACTION
)
CREATE INDEX quotes_wd_idx -- 8912 kB
ON public.quotes
USING btree
(wpname_id, datum);
CREATE TABLE public.wpnames -- rows = 357, 40 kB
(
id integer NOT NULL DEFAULT nextval('wpnames_id_seq'::regclass),
place_id integer NOT NULL,
nummer text NOT NULL,
name text NOT NULL,
CONSTRAINT wpnames_pkey PRIMARY KEY (id),
CONSTRAINT fk_rails_18eae07552 FOREIGN KEY (place_id)
REFERENCES public.places (id) MATCH SIMPLE
ON UPDATE NO ACTION ON DELETE NO ACTION
)
CREATE TABLE public.places -- rows = 11, 8192 b
(
id integer NOT NULL DEFAULT nextval('places_id_seq'::regclass),
platz text NOT NULL,
text text,
waehrung character varying(3) NOT NULL,
CONSTRAINT places_pkey PRIMARY KEY (id)
)
Hint: the quotes table contains daily stock quotes AND forex quotes,
and what the thing does is fetch the newest quotes before a given
date (inmost SELECT), fetch the respective currency ("waehrung") from
wpnames+places (next SELECT), and fetch the (date of the) respective
newest forex quote (last SELECT). (A final outermost fourth select
will then put it all together, but thats not part of the problem.)
Finally, the execution plans:
6 sec. index only scan with from_collapse:
https://explain.depesz.com/s/IPaT
1.3 sec. seq scan with from_collapse:
https://explain.depesz.com/s/Bxys
1.2 sec. seq scan w/o from_collapse:
https://explain.depesz.com/s/V02L
0.6 sec. index only scan w/o from_collapse:
https://explain.depesz.com/s/8Xh
Addendum: from the Guides for the mailing list, supplemental
information as requested. As this concerns planner strategy, which is
influenced by statistics, it appears difficult to me to create a
proper test-case, because I would need to know from where the planner
fetches the decision-relevant information - which is exactly my
question: how does it get the clue to choose the bad plans?
CPU: Intel Pentium III (945.02-MHz 686-class CPU)
avail memory = 2089263104 (1992 MB)
FreeBSD 11.1-RELEASE-p7
PostgreSQL 9.5.7 on i386-portbld-freebsd11.1, compiled by FreeBSD clang version 4.0.0 (tags/RELEASE_400/final 297347) (based on LLVM 4.0.0), 32-bit
name | current_setting | source
------------------------------+----------------------------------------+--------------------
application_name | psql | client
archive_command | ~pgsql/autojobs/RedoLog.copy "%f" "%p" | configuration file
archive_mode | on | configuration file
autovacuum | off | configuration file
autovacuum_naptime | 5min | configuration file
checkpoint_completion_target | 0 | configuration file
checkpoint_timeout | 10min | configuration file
client_encoding | UTF8 | client
DateStyle | German, DMY | configuration file
default_text_search_config | pg_catalog.german | configuration file
dynamic_shared_memory_type | posix | configuration file
effective_cache_size | 1GB | configuration file
effective_io_concurrency | 2 | configuration file
full_page_writes | off | configuration file
lc_messages | en_US.UTF-8 | configuration file
lc_monetary | en_US.UTF-8 | configuration file
lc_numeric | en_US.UTF-8 | configuration file
lc_time | de_DE.UTF-8 | configuration file
listen_addresses | 192.168.97.9,192.168.97.17 | configuration file
log_checkpoints | on | configuration file
log_connections | on | configuration file
log_destination | syslog | configuration file
log_disconnections | on | configuration file
log_error_verbosity | terse | configuration file
log_line_prefix | %u:%d[%r] | configuration file
log_lock_waits | on | configuration file
log_min_duration_statement | 1min | configuration file
log_min_messages | info | configuration file
log_temp_files | 10000kB | configuration file
maintenance_work_mem | 350MB | configuration file
max_connections | 60 | configuration file
max_files_per_process | 200 | configuration file
max_stack_depth | 60MB | configuration file
max_wal_size | 1GB | configuration file
min_wal_size | 80MB | configuration file
shared_buffers | 180MB | configuration file
synchronous_commit | on | configuration file
temp_buffers | 80MB | configuration file
unix_socket_permissions | 0777 | configuration file
wal_buffers | 256kB | configuration file
wal_level | archive | configuration file
wal_writer_delay | 2s | configuration file
work_mem | 350MB | configuration file
