Installing a single table-dump is significant slower on U16.04 (and higher) than on U14.04. The test was done on the same computer with default settings.
testdb=# \d photos_searchlog
Table "public.photos_searchlog"
Column | Type | Collation | Nullable | Default
----------+--------------------------+-----------+----------+----------------------------------------------
id | integer | | not null | nextval('photos_searchlog_id_seq'::regclass)
created | timestamp with time zone | | not null |
updated | timestamp with time zone | | not null |
lang | character varying(2) | | not null |
q | character varying(255) | | not null |
hits | integer | | not null |
count | integer | | not null |
ip_list | text | | not null |
locked | boolean | | not null |
ts_list | text | | not null |
ts_count | integer | | not null |
Indexes:
"photos_searchlog_pkey" PRIMARY KEY, btree (id)
"photos_searchlog_lang_q_key" UNIQUE CONSTRAINT, btree (lang, q)
"photos_searchlog_count" btree (count)
"photos_searchlog_created" btree (created)
"photos_searchlog_ts_count" btree (ts_count)
"photos_searchlog_updated" btree (updated)
testdb=# select count(*) from photos_searchlog;
count
---------
4006671
(1 row)
U16.04 - Time
time psql testdb < searchlog_noowner.sql
SET
SET
SET
SET
SET
SET
SET
SET
SET
CREATE TABLE
CREATE SEQUENCE
ALTER SEQUENCE
ALTER TABLE
COPY 4006671
setval
----------
16211932
(1 row)
ALTER TABLE
ALTER TABLE
CREATE INDEX
CREATE INDEX
CREATE INDEX
CREATE INDEX
real 13m7.987s
user 0m0.688s
sys 0m0.268s
U16.04 - Postgres 10.1 logs
tail -f postgresql-10-main.log
FROM pg_catalog.pg_database d
ORDER BY 1;
2017-12-31 03:30:59.567 CET [1114] postgres@postgres LOG: duration: 1.809 ms statement: SELECT d.datname as "Name",
pg_catalog.pg_get_userbyid(d.datdba) as "Owner",
pg_catalog.pg_encoding_to_char(d.encoding) as "Encoding",
d.datcollate as "Collate",
d.datctype as "Ctype",
pg_catalog.array_to_string(d.datacl, E'\n') AS "Access privileges"
FROM pg_catalog.pg_database d
ORDER BY 1;
2017-12-31 03:31:27.766 CET [1128] hans@postgres LOG: duration: 244.787 ms statement: CREATE DATABASE testdb;
2017-12-31 03:31:40.223 CET [1143] hans@testdb LOG: duration: 0.098 ms statement: SET statement_timeout = 0;
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.038 ms statement: SET lock_timeout = 0;
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.018 ms statement: SET client_encoding = 'UTF8';
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.017 ms statement: SET standard_conforming_strings = on;
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.013 ms statement: SET check_function_bodies = false;
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.012 ms statement: SET client_min_messages = warning;
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.022 ms statement: SET search_path = public, pg_catalog;
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.013 ms statement: SET default_tablespace = '';
2017-12-31 03:31:40.224 CET [1143] hans@testdb LOG: duration: 0.011 ms statement: SET default_with_oids = false;
2017-12-31 03:31:40.245 CET [1143] hans@testdb LOG: duration: 21.011 ms statement: CREATE TABLE photos_searchlog (
id integer NOT NULL,
created timestamp with time zone NOT NULL,
updated timestamp with time zone NOT NULL,
lang character varying(2) NOT NULL,
q character varying(255) NOT NULL,
hits integer NOT NULL,
count integer NOT NULL,
ip_list text NOT NULL,
locked boolean NOT NULL,
ts_list text NOT NULL,
ts_count integer NOT NULL
);
2017-12-31 03:31:40.250 CET [1143] hans@testdb LOG: duration: 4.735 ms statement: CREATE SEQUENCE photos_searchlog_id_seq
START WITH 1
INCREMENT BY 1
NO MINVALUE
NO MAXVALUE
CACHE 1;
2017-12-31 03:31:40.255 CET [1143] hans@testdb LOG: duration: 4.476 ms statement: ALTER SEQUENCE photos_searchlog_id_seq OWNED BY photos_searchlog.id;
2017-12-31 03:31:40.261 CET [1143] hans@testdb LOG: duration: 5.990 ms statement: ALTER TABLE ONLY photos_searchlog ALTER COLUMN id SET DEFAULT nextval('photos_searchlog_id_seq'::regclass);
2017-12-31 03:31:47.883 CET [1095] LOG: checkpoints are occurring too frequently (20 seconds apart)
2017-12-31 03:31:47.883 CET [1095] HINT: Consider increasing the configuration parameter "max_wal_size".
2017-12-31 03:31:51.556 CET [1143] hans@testdb LOG: duration: 11294.817 ms statement: COPY photos_searchlog (id, created, updated, lang, q, hits, count, ip_list, locked, ts_list, ts_count) FROM stdin;
2017-12-31 03:31:51.560 CET [1143] hans@testdb LOG: duration: 4.234 ms statement: SELECT pg_catalog.setval('photos_searchlog_id_seq', 16211932, true);
2017-12-31 03:44:28.160 CET [1143] hans@testdb LOG: duration: 756599.117 ms statement: ALTER TABLE ONLY photos_searchlog
ADD CONSTRAINT photos_searchlog_lang_q_key UNIQUE (lang, q);
2017-12-31 03:44:32.092 CET [1143] hans@testdb LOG: duration: 3932.650 ms statement: ALTER TABLE ONLY photos_searchlog
ADD CONSTRAINT photos_searchlog_pkey PRIMARY KEY (id);
2017-12-31 03:44:36.149 CET [1143] hans@testdb LOG: duration: 4056.127 ms statement: CREATE INDEX photos_searchlog_count ON photos_searchlog USING btree (count);
2017-12-31 03:44:40.210 CET [1143] hans@testdb LOG: duration: 4061.228 ms statement: CREATE INDEX photos_searchlog_created ON photos_searchlog USING btree (created);
2017-12-31 03:44:44.602 CET [1143] hans@testdb LOG: duration: 4391.615 ms statement: CREATE INDEX photos_searchlog_ts_count ON photos_searchlog USING btree (ts_count);
2017-12-31 03:44:48.166 CET [1143] hans@testdb LOG: duration: 3563.880 ms statement: CREATE INDEX photos_searchlog_updated ON photos_searchlog USING btree (updated);
U14.04 - Time
time psql testdb < searchlog_noowner.sql
SET
SET
SET
SET
SET
SET
SET
SET
SET
SET
SET
CREATE TABLE
CREATE SEQUENCE
ALTER SEQUENCE
ALTER TABLE
COPY 4006671
setval
----------
16211932
(1 row)
ALTER TABLE
ALTER TABLE
CREATE INDEX
CREATE INDEX
CREATE INDEX
CREATE INDEX
real 1m46.952s
user 0m0.784s
sys 0m0.240s
U14.04 - Postgres 10.1 logs
tail -f postgresql-10-main.log
FROM pg_catalog.pg_database d
ORDER BY 1;
2017-12-31 03:32:38.645 CET [17171] postgres@postgres LOG: duration: 0.618 ms statement: SELECT d.datname as "Name",
pg_catalog.pg_get_userbyid(d.datdba) as "Owner",
pg_catalog.pg_encoding_to_char(d.encoding) as "Encoding",
d.datcollate as "Collate",
d.datctype as "Ctype",
pg_catalog.array_to_string(d.datacl, E'\n') AS "Access privileges"
FROM pg_catalog.pg_database d
ORDER BY 1;
2017-12-31 03:33:22.935 CET [17201] hans@postgres LOG: duration: 291.882 ms statement: CREATE DATABASE testdb;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.069 ms statement: SET statement_timeout = 0;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.015 ms statement: SET lock_timeout = 0;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.013 ms statement: SET idle_in_transaction_session_timeout = 0;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.014 ms statement: SET client_encoding = 'UTF8';
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.015 ms statement: SET standard_conforming_strings = on;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.012 ms statement: SET check_function_bodies = false;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.011 ms statement: SET client_min_messages = warning;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.010 ms statement: SET row_security = off;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.019 ms statement: SET search_path = public, pg_catalog;
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.010 ms statement: SET default_tablespace = '';
2017-12-31 03:34:09.304 CET [17247] hans@testdb LOG: duration: 0.008 ms statement: SET default_with_oids = false;
2017-12-31 03:34:09.312 CET [17247] hans@testdb LOG: duration: 8.316 ms statement: CREATE TABLE photos_searchlog (
id integer NOT NULL,
created timestamp with time zone NOT NULL,
updated timestamp with time zone NOT NULL,
lang character varying(2) NOT NULL,
q character varying(255) NOT NULL,
hits integer NOT NULL,
count integer NOT NULL,
ip_list text NOT NULL,
locked boolean NOT NULL,
ts_list text NOT NULL,
ts_count integer NOT NULL
);
2017-12-31 03:34:09.314 CET [17247] hans@testdb LOG: duration: 1.382 ms statement: CREATE SEQUENCE photos_searchlog_id_seq
START WITH 1
INCREMENT BY 1
NO MINVALUE
NO MAXVALUE
CACHE 1;
2017-12-31 03:34:09.315 CET [17247] hans@testdb LOG: duration: 1.097 ms statement: ALTER SEQUENCE photos_searchlog_id_seq OWNED BY photos_searchlog.id;
2017-12-31 03:34:09.316 CET [17247] hans@testdb LOG: duration: 1.453 ms statement: ALTER TABLE ONLY photos_searchlog ALTER COLUMN id SET DEFAULT nextval('photos_searchlog_id_seq'::regclass);
2017-12-31 03:34:27.048 CET [17247] hans@testdb LOG: duration: 17731.032 ms statement: COPY photos_searchlog (id, created, updated, lang, q, hits, count, ip_list, locked, ts_list, ts_count) FROM stdin;
2017-12-31 03:34:27.049 CET [17247] hans@testdb LOG: duration: 1.126 ms statement: SELECT pg_catalog.setval('photos_searchlog_id_seq', 16211932, true);
2017-12-31 03:35:36.752 CET [17247] hans@testdb LOG: duration: 69703.146 ms statement: ALTER TABLE ONLY photos_searchlog
ADD CONSTRAINT photos_searchlog_lang_q_key UNIQUE (lang, q);
2017-12-31 03:35:40.236 CET [17247] hans@testdb LOG: duration: 3483.664 ms statement: ALTER TABLE ONLY photos_searchlog
ADD CONSTRAINT photos_searchlog_pkey PRIMARY KEY (id);
2017-12-31 03:35:44.521 CET [17247] hans@testdb LOG: duration: 4284.701 ms statement: CREATE INDEX photos_searchlog_count ON photos_searchlog USING btree (count);
2017-12-31 03:35:48.969 CET [17247] hans@testdb LOG: duration: 4447.547 ms statement: CREATE INDEX photos_searchlog_created ON photos_searchlog USING btree (created);
2017-12-31 03:35:52.850 CET [17247] hans@testdb LOG: duration: 3881.215 ms statement: CREATE INDEX photos_searchlog_ts_count ON photos_searchlog USING btree (ts_count);
2017-12-31 03:35:56.222 CET [17247] hans@testdb LOG: duration: 3371.491 ms statement: CREATE INDEX photos_searchlog_updated ON photos_searchlog USING btree (updated);
I tested this with different PG versions, on different machines, with autovaccum on/off, with a complete database, with single tables - but always the same result: U14.04 is much faster...
May be someone has an idea where the "bug" is...
Thanks Hans
PS: The time difference is much bigger when dumping our 5 GB database.
U14.04: Always around 7 minutes
U16.04: 27 minutes (autovacuum off)
U16.04: 268 minutes (autovacuum on)!!!