Sampling de logs no PostgreSQL: como ver queries lentas sem afogar o disco

O problema que Christophe Pettus expõe em sua série All Your GUCs in a Row, publicada no Planet PostgreSQL↳PostgreSQL11 conteúdosPostgreSQL via SSL com GolangData · abr 20195 itens legais sobre data types do PostgreSQLData · mar 20195 serviços gratuitos na cloud para bancos de dados PostgresData · fev 2025Ver tudo em Data →, é familiar a quem administra banco em produção: depois de configurar log_min_duration_statement com um limiar que valha a pena investigar, tudo o que roda abaixo dele fica invisível. E o que roda abaixo costuma ser justamente a história que interessa.

A aritmética do artigo é o melhor argumento. Uma query que demora um minuto é um problema que você enxerga de imediato. Já vinte milhões de queries a um milissegundo cada somam cinco horas e meia de tempo de banco, e não produzem uma única linha de log. O pg_stat_statements mostra esse agregado, mas não entrega um espécime: uma execução real, com os valores reais de parâmetro, no momento real em que aconteceu. É esse espécime que os três parâmetros de amostragem compram, a um volume de log que o DBA decide de antemão.

O par que amostra por duração

Os dois primeiros GUCs trabalham juntos, e ambos exigem contexto de superusuário. O log_min_duration_sample (padrão -1, desabilitado; medido em milissegundos, com 0 considerando tudo) define o piso da faixa que você quer amostrar. O log_statement_sample_rate (padrão 1.0) é o dial: a fração dos statements acima daquele piso que efetivamente vão para o log. A linha resultante é indistinguível de uma linha comum de log_min_duration_statement, porque é a mesma linha:

LOG: duration: 0.300 ms statement: SELECT 12 + 0

A amostragem é um cara ou coroa por statement, não um intervalo fixo. Pettus relata que, em um de seus testes, a taxa 0.25 registrou exatamente 10 statements de 40; a 0.5, 17 de 40. Nas palavras dele, é "estatisticamente honesto, aritmeticamente desarrumado". Ou seja: não espere 0.5 produzir exatos 50%.

A regra que torna o par seguro de usar é a prioridade absoluta do log_min_duration_statement. Qualquer statement acima desse limiar é logado sempre, independentemente do que a amostragem diga. Pettus verificou o comportamento com log_statement_sample_rate = 0: uma query de 415ms entrou no log mesmo com uma configuração de sampling que, nominalmente, não loga nada.

O corolário prático é importante para não desperdiçar configuração: o log_min_duration_sample só faz alguma coisa quando está abaixo do log_min_duration_statement. Se você o define acima, tudo o que ele amostraria já está sendo logado incondicionalmente. A configuração de trabalho fica assim:

log_min_duration_statement = '1s'    # o alarme
log_min_duration_sample    = '100ms' # o piso da amostra
log_statement_sample_rate  = 0.05    # 5% da faixa entre 100ms e 1s

Por que existem dois limiares, e não um

A regra de prioridade, segundo Pettus, "não é um capricho de design, é uma cicatriz". Vale a lição de história. O sampling de statements foi commitado para o PostgreSQL 12 numa forma mais simples: um único dial, aplicado sobre os statements que já excediam o log_min_duration_statement. O efeito colateral era grave: o seu pior statement do dia podia ser descartado pelo sampler, e a única garantia que o log sempre ofereceu, a de que os piores statements estão nele, silenciosamente deixava de valer.

A comunidade detectou o problema ainda no beta e reverteu o recurso por completo, com o argumento de que o segundo limiar precisava fazer parte do recurso desde o início, e não chegar depois como um conserto que quebra compatibilidade. A versão de dois limiares só desembarcou no PostgreSQL 13. A lição generaliza para qualquer esquema de amostragem que se vá construir, dentro ou fora do banco:

Decida primeiro o que nunca pode ser descartado pela amostragem.

Christophe Pettus, Planet PostgreSQL

Para um DBA, isso significa tratar o limiar de alarme como sagrado e a amostra como um instrumento estatístico separado, que nunca compete com ele.

Amostrar a transação inteira

O log_transaction_sample_rate (padrão 0, também superusuário, no core desde o PostgreSQL 12) opera num eixo completamente diferente. A moeda é jogada uma vez, quando a transação começa, e a duração não entra na conta. Se a transação ganha o sorteio, todos os statements dela são logados, do BEGIN ao COMMIT, cada um com sua duração:

LOG: duration: 0.099 ms   statement: BEGIN;
LOG: duration: 2.068 ms   statement: INSERT INTO orders VALUES (9000001, 4242, now());
LOG: duration: 397.231 ms statement: SELECT count(*) FROM orders WHERE customer_id = 4242;
LOG: duration: 1.344 ms   statement: COMMIT;

Esse é o trace que você quer quando o problema não é um statement, mas uma forma: qual statement adquiriu o lock atrás do qual todo o resto ficou enfileirado, o que rodou antes do lento, se a aplicação está mantendo uma transação aberta atravessando uma chamada de rede que não deveria. O log por limiar de duração não mostra nada disso, porque entrega o statement lento despido do seu contexto. Para investigar contenção e transações longas, essa visão completa costuma valer mais que o espécime isolado.

A armadilha do autocommit

Antes de ligar o sampling de transação, há uma pegadinha que o artigo faz questão de sinalizar. Um statement fora de uma transação explícita é uma transação. Então, numa carga de trabalho autocommit (que é, na prática, a maior parte do tráfego de leitura de um ORM), o log_transaction_sample_rate degenera para um sampling de statement cego à duração. No teste de Pettus, 40 statements autocommit a 0.5 produziram 17 "transações" logadas de um statement cada.

Nesse tipo de carga, o parâmetro gera volume sem a coerência que o justifica. Ele só se paga onde transações multi-statement são a norma, e mesmo ali é um parâmetro que se liga para uma investigação e se desliga em seguida.

Quando não vale, e o que usar no lugar

O estado permanente recomendado é o dos padrões, com o log_min_duration_statement fazendo o trabalho diário. O par de sampling entra em cena quando as queries que você precisa ver vivem abaixo do limiar de alarme; o dial de transação entra quando você precisa de contexto, não de espécimes.

Há um caso claro em que nenhum dos três é a ferramenta certa. Se o que você quer é o agregado, quantas vezes uma query rodou, o tempo total que consumiu, isso nunca foi um problema de logging. É trabalho do pg_stat_statements, e, como resume Pettus, nenhuma taxa de amostragem vai vencê-lo no que é a especialidade dele. Amostrar log para reconstruir estatística agregada é o caminho errado: gera I/O de disco, ruído e ainda entrega um número enviesado pela própria amostragem.

A leitura para quem opera bancos PostgreSQL no Brasil é direta: sampling de log é instrumento cirúrgico, não configuração de rotina. Ele resolve o ponto cego entre o agregado do pg_stat_statements e o alarme do log_min_duration_statement, capturando execuções reais a um custo de log previsível. Ligado permanentemente, ou mal ordenado em relação ao limiar de alarme, vira só mais linha de log para armazenar e girar.

Fonte: Planet PostgreSQL