Postgres 10.1 lento no Ubuntu 16.04

Question

Postgres 10.1 lento no Ubuntu 16.04

#1 resposta do (0 votos)
#2 resposta do (0 votos)

2

Instalar um único dump de tabela é significativamente mais lento no U16.04 (e superior) do que no U14.04. O teste foi feito no mesmo computador com as configurações padrão.

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

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

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

Eu testei isso com diferentes versões do PG, em máquinas diferentes, com o autovaccum ligado / desligado, com um banco de dados completo, com tabelas únicas - mas sempre o mesmo resultado: o U14.04 é muito mais rápido ...

Pode ser que alguém tenha uma ideia de onde o "bug" é ...

Obrigado Hans

PS: A diferença de tempo é muito maior ao descarregar nosso banco de dados de 5 GB.

U14.04: Always around 7 minutes
U16.04:  27 minutes (autovacuum off)
U16.04: 268 minutes (autovacuum on)!!!

postgresql dump ubuntu

por Barmi 31.12.2017 / 04:20

2 respostas

Tags postgresql dump ubuntu

Asterisk - Nome do chamador de saída no cliente Scripts em /etc/profile.d estão sendo executados duas vezes no login

score 0 · Answer 1

Isso não é informação suficiente para lhe dizer o que está acontecendo. Pode ser a segmentação de disco ou a configuração interna do PostgreSQL, ou o próprio sistema operacional, que executa e libera o buffer do sistema de arquivos no disco. Ou que em 14.04 o heap (tabela) já estava no buffer do sistema - talvez o banco de dados estivesse quente e as páginas não precisassem ser lidas do disco?

Teríamos que ver os dois arquivos de configuração para ambas as versões do psql, e teríamos que saber se isso estava no mesmo hardware.

Mas, sério, > 12min em uma restauração? Quem se importa? É uma operação única. Se você está fazendo isso periodicamente ou em tempo real, precisa verificar a replicação de streaming, a replicação lógica e o envio de logs.

score 0 · Answer 2

Interessante que ninguém encontrou a resposta ...

É um bug da glibc: Após a atualização do Ubuntu 14.10 (glibc 2.19) para o 15.04 (glibc 2.21), estamos experimentando uma grande regressão de desempenho em uma criação de índice do PostgreSQL em particular. A criação do índice demora mais de 10 minutos, enquanto antes era feita em cerca de 30 segundos.

link