Вопросы Теги

Postgres 10.1 медленно работает на Ubuntu 16. 04

Установка единого дампа таблицы значительно медленнее на U16.04 (и выше), чем на U14.04. Тест проводился на том же компьютере с настройками по умолчанию. 

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 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 

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 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 

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);

Я тестировал это с разными версиями PG, на разных машинах, с включением / выключением autovaccum, с полной базой данных, с отдельными таблицами - но всегда один и тот же результат: U14.04 намного быстрее ...

Может быть, у кого-то есть идея, где "ошибка" ...

Спасибо, Ганс

PS: Разница во времени намного больше при сбросе нашей базы данных 5 ГБ. 

U14.04: Always around 7 minutes
U16.04:  27 minutes (autovacuum off)
U16.04: 268 minutes (autovacuum on)!!!
2
задан 31 December 2017 в 05:20
2 ответа

Этой информации недостаточно, чтобы сказать вам, что происходит. Это может быть сегментация диска или ваша внутренняя конфигурация для PostgreSQL, или сама операционная система выполняет синхронизацию и сбрасывает буфер файловой системы на диск. Или что в 14.04 куча (таблица) уже была в системном буфере - возможно, БД была горячей и страницы не нужно было читать с диска?

Нам нужно было бы увидеть два файла конфигурации для обоих версия psql, и мы должны знать, было ли это на том же оборудовании.

А если серьезно,> 12 минут на восстановление? Какая разница? Это одноразовая операция. Если вы делаете это периодически или на лету, вам необходимо проверить потоковую репликацию, логическую репликацию и доставку журналов.

0
ответ дан 3 December 2019 в 14:03

Интересно, что никто не нашел ответа ...

Это ошибка glibc: после обновления с Ubuntu 14.10 (glibc 2.19) до 15.04 (glibc 2.21) мы наблюдаем большой спад производительности в одном конкретном создании индекса PostgreSQL. Создание индекса теперь занимает более 10 минут, тогда как раньше на это требовалось около 30 секунд.

https://sourceware.org/bugzilla/show_bug.cgi?id=18441

0
ответ дан 3 December 2019 в 14:03

Теги

Похожие вопросы