Muita geração de log - Postgres 10

Olá pessoal, bom dia.

Eu administro um ambiente de postgres que utilizava a versão 9.6 e o volume
de logs era normal, o diretório não passava de 5gb.
Fizemos o upgrade para versão 10.12 e o volume de logs gerados cresceu
absurdamente. Agora está gerando cerca de 1g por hora. Não fizemos nenhuma
alteração nos parâmetros de log com o upgrade.

Alguém já passou por algo do tipo? Sabem se a versão 10 gera mais log do
que a 9.6?

Segue abaixo os parâmetros de log que temos configurado hoje:

logging_collector = on
log_rotation_age = 1d
log_rotation_size = 1024MB
log_min_messages = notice
log_min_error_statement = error
log_duration = off
log_error_verbosity = default
log_hostname = off
log_line_prefix = '%t [%p]: [%l-1] user=%u,app=%a,host=%h'
log_lock_waits = off
log_statement = 'ddl'
log_temp_files = 0
log_timezone = 'America/Bahia' #'localtime'

Agradeço desde já!

Atenciosamente,

*Hortência da Silva Campos*

+55 71 99274-1197

Oi Osvaldo,

Verifiquei que ta escrevendo tudo no log, parece que todas operações,
select's inclusive.

Ai eu lembrei que no dia do upgrade desabilitei (sem querer) o parâmetro
que carregava a biblioteca pg_stat_statements.
Estou achando que depois disso o banco passou a escrever todos os
statements dentro do log.

Atenciosamente,

*Hortência da Silva Campos*

+55 71 99274-1197

Em qui., 19 de nov. de 2020 às 11:16, Osvaldo Kussama <
osvaldo(dot)kussama(at)gmail(dot)com> escreveu:

> Em 19/11/2020, Hortencia Campos<hortenciadsc(at)gmail(dot)com> escreveu:
> > Olá pessoal, bom dia.
> >
> > Eu administro um ambiente de postgres que utilizava a versão 9.6 e o
> volume
> > de logs era normal, o diretório não passava de 5gb.
> > Fizemos o upgrade para versão 10.12 e o volume de logs gerados cresceu
> > absurdamente. Agora está gerando cerca de 1g por hora. Não fizemos
> nenhuma
> > alteração nos parâmetros de log com o upgrade.
> >
> > Alguém já passou por algo do tipo? Sabem se a versão 10 gera mais log do
> > que a 9.6?
> >
> > Segue abaixo os parâmetros de log que temos configurado hoje:
> >
> > logging_collector = on
> > log_rotation_age = 1d
> > log_rotation_size = 1024MB
> > log_min_messages = notice
> > log_min_error_statement = error
> > log_duration = off
> > log_error_verbosity = default
> > log_hostname = off
> > log_line_prefix = '%t [%p]: [%l-1] user=%u,app=%a,host=%h'
> > log_lock_waits = off
> > log_statement = 'ddl'
> > log_temp_files = 0
> > log_timezone = 'America/Bahia' #'localtime'
> >
>
>
> Em primeiro lugar verifique o que está sendo gravado no log.
> Pode ser que algo não esteja funcionando adequadamente na nova instalação.
> Note que o valor default para log_min_messages é warning e não notice.
>
> Osvaldo
>

Em qui., 19 de nov. de 2020 às 16:11, Hortencia Campos <
hortenciadsc(at)gmail(dot)com> escreveu:

> Oi Osvaldo,
>
> Verifiquei que ta escrevendo tudo no log, parece que todas operações,
> select's inclusive.
>
> Ai eu lembrei que no dia do upgrade desabilitei (sem querer) o parâmetro
> que carregava a biblioteca pg_stat_statements.
> Estou achando que depois disso o banco passou a escrever todos os
> statements dentro do log.
>
>
Entre no seu banco e faça :
SELECT name, setting, unit FROM pg_settings WHERE name like 'log%';

E mande pra nós.
Veja em especial os resultados de log_statement e
log_min_duration_statement.

Flavio Gurgel

Flavio,

Segue resultado:

postgres=# SELECT name, setting, unit FROM pg_settings WHERE name like
'log%';
name | setting | unit
-----------------------------+----------------------------------------+------
log_autovacuum_min_duration | 0 | ms
log_checkpoints | off |
log_connections | off |
log_destination | stderr |
log_directory | log |
log_disconnections | off |
log_duration | off |
log_error_verbosity | default |
log_executor_stats | off |
log_file_mode | 0600 |
log_filename | postgresql-%Y-%m-%d_%H%M%S.log |
log_hostname | off |
log_line_prefix | %t [%p]: [%l-1] user=%u,app=%a,host=%h |
log_lock_waits | off |
*log_min_duration_statement | 120000 | ms*
log_min_error_statement | error |
log_min_messages | warning |
log_parser_stats | off |
log_planner_stats | off |
log_replication_commands | off |
log_rotation_age | 1440 | min
log_rotation_size | 1048576 | kB
*log_statement | ddl |*
log_statement_stats | off |
log_temp_files | 0 | kB
log_timezone | America/Bahia |
log_truncate_on_rotation | off |
logging_collector | on |

Atenciosamente,

*Hortência da Silva Campos*

+55 71 99274-1197

Em qui., 19 de nov. de 2020 às 14:45, Flavio Henrique Araque Gurgel <
fhagur(at)gmail(dot)com> escreveu:

>
>
> Em qui., 19 de nov. de 2020 às 16:11, Hortencia Campos <
> hortenciadsc(at)gmail(dot)com> escreveu:
>
>> Oi Osvaldo,
>>
>> Verifiquei que ta escrevendo tudo no log, parece que todas operações,
>> select's inclusive.
>>
>> Ai eu lembrei que no dia do upgrade desabilitei (sem querer) o parâmetro
>> que carregava a biblioteca pg_stat_statements.
>> Estou achando que depois disso o banco passou a escrever todos os
>> statements dentro do log.
>>
>>
> Entre no seu banco e faça :
> SELECT name, setting, unit FROM pg_settings WHERE name like 'log%';
>
> E mande pra nós.
> Veja em especial os resultados de log_statement e
> log_min_duration_statement.
>
> Flavio Gurgel
>

Em qui., 19 de nov. de 2020 às 16:57, Flavio Henrique Araque Gurgel <
fhagur(at)gmail(dot)com> escreveu:

> Por favor prefira responder quotando, ou abaixo da resposta anterior.
>
> *log_min_duration_statement | 120000 |
>> ms*
>>
>
> Tudo o que passar de 120 segundos vai cair no seu log. Isso explica as
> consultas que está vendo.
>
>
>> *log_statement | ddl |*
>>
>
> Todos os comandos DDL vão aparecer no log (CREATE, ALTER, etc)
>
>
>>
>> log_temp_files | 0 | kB
>>
>
> Todos os arquivos temporários vão cair no log.
>
> Flavio Gurgel
>

Oi Flavio,

Desculpa a demora e obrigada pela ajuda!

Eu alterei o parâmetro log_min_duration_statement para -1 e ainda está
escrevendo muitos selects, a impressão que eu tenho é que ta escrevendo
tudo.
Esse parâmetro é dinâmico, correto? Além de reload, teria que fazer mais
alguma coisa para se ter o efeito?

Consultando no banco parece que já ta certo:

log_min_duration_statement
----------------------------
-1
(1 registro)

Em relação a DDL e temp_files não teria problema. O que me atrapalha mais
são os SELECTs, que estão enchendo muito os logs e, consequentemente, o
disco.

Agradeço desde já!

On Mon, 7 Dec 2020 at 12:10, Hortencia Campos <hortenciadsc(at)gmail(dot)com>
wrote:

>
> Eu alterei o parâmetro log_min_duration_statement para -1 e ainda está
> escrevendo muitos selects, a impressão que eu tenho é que ta escrevendo
> tudo.
> Esse parâmetro é dinâmico, correto? Além de reload, teria que fazer mais
> alguma coisa para se ter o efeito?
>
> Não. Um reload é suficiente.

> Consultando no banco parece que já ta certo:
>
> log_min_duration_statement
> ----------------------------
> -1
> (1 registro)
>
> Está sim. Todavia, há um pequeno detalhe: esse parâmetro pode ser ajustado
por usuário ou banco de dados. Provavelmente alguém utilizou um ALTER ROLE
SET ou ALTER DATABASE SET. Use a seguinte consulta para verificar os
parâmetros definidos por usuário ou banco:

SELECT d.datname, setrole::regrole, setconfig FROM pg_db_role_setting s
LEFT JOIN pg_database d ON (d.oid = s.setdatabase);

Você pode resetar o parâmetro com:

ALTER ROLE foo RESET log_min_duration_statement;

ou se for definido por banco:

ALTER DATABASE foo RESET log_min_duration_statement;

--
Euler Taveira http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Em seg., 7 de dez. de 2020 às 14:04, Euler Taveira <
euler(dot)taveira(at)2ndquadrant(dot)com> escreveu:

> On Mon, 7 Dec 2020 at 12:10, Hortencia Campos <hortenciadsc(at)gmail(dot)com>
> wrote:
>
>>
>> Eu alterei o parâmetro log_min_duration_statement para -1 e ainda está
>> escrevendo muitos selects, a impressão que eu tenho é que ta escrevendo
>> tudo.
>> Esse parâmetro é dinâmico, correto? Além de reload, teria que fazer mais
>> alguma coisa para se ter o efeito?
>>
>> Não. Um reload é suficiente.
>
>
>> Consultando no banco parece que já ta certo:
>>
>> log_min_duration_statement
>> ----------------------------
>> -1
>> (1 registro)
>>
>> Está sim. Todavia, há um pequeno detalhe: esse parâmetro pode ser
> ajustado por usuário ou banco de dados. Provavelmente alguém utilizou um
> ALTER ROLE SET ou ALTER DATABASE SET. Use a seguinte consulta para
> verificar os parâmetros definidos por usuário ou banco:
>
> SELECT d.datname, setrole::regrole, setconfig FROM pg_db_role_setting s
> LEFT JOIN pg_database d ON (d.oid = s.setdatabase);
>
> Você pode resetar o parâmetro com:
>
> ALTER ROLE foo RESET log_min_duration_statement;
>
> ou se for definido por banco:
>
> ALTER DATABASE foo RESET log_min_duration_statement;
>
>
> --
> Euler Taveira http://www.2ndQuadrant.com/
> PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
>

Oi Euler,

Rodei a consulta que vc mandou e esse parâmetro não aparece no resultado.

Porém, apareceu uma outra coisa interessante para o usuário principal da
aplicação : {pgaudit.log=}

Um colega estava testando a auditoria em outro ambiente, mas acabou se
atrapalhando e setando esse parâmetro em produção. Depois ele zerou o
parâmetro e nós nem habilitamos a biblioteca do pgaudit nesse banco de
dados.
Tem alguma chance desse parâmetro está causando esse volume de mensagens no
log?
Se sim, como eu faço pra "desabilitar" isso?

On Mon, 7 Dec 2020 at 14:27, Hortencia Campos <hortenciadsc(at)gmail(dot)com>
wrote:

>
> Rodei a consulta que vc mandou e esse parâmetro não aparece no resultado.
>
> Porém, apareceu uma outra coisa interessante para o usuário principal da
> aplicação : {pgaudit.log=}
>
> Um colega estava testando a auditoria em outro ambiente, mas acabou se
> atrapalhando e setando esse parâmetro em produção. Depois ele zerou o
> parâmetro e nós nem habilitamos a biblioteca do pgaudit nesse banco de
> dados.
> Tem alguma chance desse parâmetro está causando esse volume de mensagens
> no log?
> Se sim, como eu faço pra "desabilitar" isso?
>
>
Qualquer super-usuário pode alterar esse parâmetro em tempo de execução:

SET log_min_duration_statement TO 0;

O log do pgAudit tem o prefixo AUDIT. É esse o seu caso?

Para desabilitar o pgAudit, remova-o do shared_preload_libraries e reinicie
o serviço.

--
Euler Taveira http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Oi Euler,

Se eu setar o log_min_duration_statement para 0 não vai acabar pegando
tudo que foi executado no banco?

O prefixo no arquivo de log é STATEMENT.

Atenciosamente,

*Hortência da Silva Campos*

+55 71 99274-1197

Em seg., 7 de dez. de 2020 às 14:54, Euler Taveira <
euler(dot)taveira(at)2ndquadrant(dot)com> escreveu:

> On Mon, 7 Dec 2020 at 14:27, Hortencia Campos <hortenciadsc(at)gmail(dot)com>
> wrote:
>
>>
>> Rodei a consulta que vc mandou e esse parâmetro não aparece no resultado.
>>
>> Porém, apareceu uma outra coisa interessante para o usuário principal da
>> aplicação : {pgaudit.log=}
>>
>> Um colega estava testando a auditoria em outro ambiente, mas acabou se
>> atrapalhando e setando esse parâmetro em produção. Depois ele zerou o
>> parâmetro e nós nem habilitamos a biblioteca do pgaudit nesse banco de
>> dados.
>> Tem alguma chance desse parâmetro está causando esse volume de mensagens
>> no log?
>> Se sim, como eu faço pra "desabilitar" isso?
>>
>>
> Qualquer super-usuário pode alterar esse parâmetro em tempo de execução:
>
> SET log_min_duration_statement TO 0;
>
> O log do pgAudit tem o prefixo AUDIT. É esse o seu caso?
>
> Para desabilitar o pgAudit, remova-o do shared_preload_libraries e
> reinicie o serviço.
>
>
> --
> Euler Taveira http://www.2ndQuadrant.com/
> PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
>

Pessoal,

Esses parâmetros de log são dinâmicos mesmo, né? Basta um reload para ter
efeito.

Já tentei mudar quase todos aqui e nada resolve.

Atenciosamente,

*Hortência da Silva Campos*

+55 71 99274-1197

Em qui., 10 de dez. de 2020 às 14:28, Hortencia Campos <
hortenciadsc(at)gmail(dot)com> escreveu:

> Oi Euler,
>
> Se eu setar o log_min_duration_statement para 0 não vai acabar pegando
> tudo que foi executado no banco?
>
> O prefixo no arquivo de log é STATEMENT.
>
>
> Atenciosamente,
>
> *Hortência da Silva Campos*
>
> +55 71 99274-1197
>
>
> Em seg., 7 de dez. de 2020 às 14:54, Euler Taveira <
> euler(dot)taveira(at)2ndquadrant(dot)com> escreveu:
>
>> On Mon, 7 Dec 2020 at 14:27, Hortencia Campos <hortenciadsc(at)gmail(dot)com>
>> wrote:
>>
>>>
>>> Rodei a consulta que vc mandou e esse parâmetro não aparece no
>>> resultado.
>>>
>>> Porém, apareceu uma outra coisa interessante para o usuário principal da
>>> aplicação : {pgaudit.log=}
>>>
>>> Um colega estava testando a auditoria em outro ambiente, mas acabou se
>>> atrapalhando e setando esse parâmetro em produção. Depois ele zerou o
>>> parâmetro e nós nem habilitamos a biblioteca do pgaudit nesse banco de
>>> dados.
>>> Tem alguma chance desse parâmetro está causando esse volume de mensagens
>>> no log?
>>> Se sim, como eu faço pra "desabilitar" isso?
>>>
>>>
>> Qualquer super-usuário pode alterar esse parâmetro em tempo de execução:
>>
>> SET log_min_duration_statement TO 0;
>>
>> O log do pgAudit tem o prefixo AUDIT. É esse o seu caso?
>>
>> Para desabilitar o pgAudit, remova-o do shared_preload_libraries e
>> reinicie o serviço.
>>
>>
>> --
>> Euler Taveira http://www.2ndQuadrant.com/
>> PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
>>
>

Oi Flavio,

Ontem eu estava analisando aquelas primeiras observações que você fez e
tinha deixado passar o parâmetro log_temp_files. Eu tinha entendido que ele
logaria apenas a utilização dos temps e não os statements dele.
Quando eu desabilitei ele, o log parou de escrever tão absurdamente e meu
problema foi resolvido.

Agradeço pela ajuda de todos e peço desculpas pela confusão!

Atenciosamente,

*Hortência da Silva Campos*

+55 71 99274-1197

Em sex., 11 de dez. de 2020 às 03:29, Flavio Henrique Araque Gurgel <
fhagur(at)gmail(dot)com> escreveu:

>
>
> Em qui, 10 de dez de 2020 19:10, Hortencia Campos <hortenciadsc(at)gmail(dot)com>
> escreveu:
>
>> Pessoal,
>>
>> Esses parâmetros de log são dinâmicos mesmo, né? Basta um reload para ter
>> efeito.
>>
>> Já tentei mudar quase todos aqui e nada resolve.
>>
>> Atenciosamente,
>>
>> *Hortência da Silva Campos*
>>
>> +55 71 99274-1197
>>
>>
>> Hortência, poderia nos enviar o resultado da consulta abaixo?
> SELECT name, setting, unit FROM pg_settings WHERE name LIKE 'log%';
>
> Flavio
>
>>
>>>>
>>>>