Introdução ao auto_explain:como registrar automaticamente planos de consulta lentos do Postgres

Você quer saber por que uma consulta do PostgreSQL é lenta? Então EXPLAIN ANALYZE é um ótimo ponto de partida. Mas os planos de consulta podem depender de outras atividades do servidor, podem demorar um pouco para serem executados e podem mudar ao longo do tempo, portanto, se você quiser ver os planos de execução reais de suas consultas mais lentas, o auto_explain é a ferramenta necessária. Neste post, veremos o que ele faz, como configurá-lo e como usar esses logs para acelerar suas consultas.

O que é auto_explain?

auto_explain é uma extensão do PostgreSQL que permite registrar os planos de consulta para consultas mais lentas que um limite (configurável). Isso é incrivelmente útil para depurar consultas lentas, especialmente aquelas que às vezes são problemáticas. É um dos módulos de contribuição, portanto pode ser instalado e configurado facilmente no PostgreSQL normal, e é tão útil que o temos por padrão no ScaleGrid.

Muito obrigado a Takahiro Itagaki, o principal autor por trás da primeira versão do auto_explain (commit, thread), Dean Rasheed, cujo patch inicial e sugestão foi baseado, e os muitos colaboradores e revisores desde então.

Quais parâmetros auto_explain devo usar?

A seguir, discutiremos os parâmetros mais importantes, mas revise a tabela abaixo ou a documentação oficial para obter mais informações sobre o conjunto completo de coisas que você pode acompanhar.

O parâmetro mais importante para auto_explain é log_min_duration . Por padrão, isso é definido como -1 , o que significa que nada será registrado - então, se quisermos alguns logs, precisamos alterá-lo! A unidade padrão é ms, portanto, uma configuração de 100 registrará os planos de consulta para todas as consultas que excederem 100ms. Isso é o que escolhemos como padrão no ScaleGrid, mas pode ser configurado em Admin -> Config. Se, por algum motivo, você quiser registrar o plano de consulta para cada consulta, você pode definir isso como 0 – mas cuidado, isso pode ter sérias implicações de desempenho.

Como as consultas já estão sendo executadas no servidor, você provavelmente também deseja habilitar auto_explain.log_analyze . Isso torna a saída equivalente à execução de EXPLAIN ANALYZE . Por padrão, isso também significa que os tempos por operação são rastreados. Isso vem com alguma sobrecarga adicional, que pode ser minimizada desativando auto_explain.log_timing (ativado por padrão com log_analyze ). Naturalmente, porém, os tempos por operação são muito úteis ao depurar consultas lentas! Nossos testes internos mostraram sobrecargas aceitáveis ​​para isso, portanto, está ativado por padrão no ScaleGrid, mas, como sempre, teste sua carga de trabalho para ver se a sobrecarga é aceitável no seu caso. Atualmente, há informações públicas limitadas sobre esse tópico, mas uma postagem recente da equipe pgMustard mostrou que, pelo menos em uma pequena carga de trabalho transacional, a sobrecarga pode ser tão baixa quanto 2%. Como eles observaram, isso pode ser reduzido com o auto_explain.sample_rate parâmetro, ao custo de rastrear apenas um subconjunto de suas consultas.

O parâmetro final que discutiremos em detalhes é auto_explain.log_format . A saída padrão é TEXT, que provavelmente é o que você está mais familiarizado ao usar EXPLAIN .

Aqui está um exemplo simples de como a saída auto_explain no formato TEXT pode se parecer:

2021-09-10 15:32:04.606 BST [22770] LOG:  duration: 3184.383 ms  plan:
	Query Text: select * from table1 order by column1;
	Sort  (cost=12875.92..13125.92 rows=100000 width=37) (actual time=2703.799..3055.401 rows=100000 loops=1)
	  Sort Key: column1
	  Sort Method: external merge  Disk: 4696kB
	  Buffers: shared hit=837, temp read=587 written=589
	  ->  Seq Scan on table  (cost=0.00..1834.01 rows=100000 width=37) (actual time=0.033..27.795 rows=100000 loops=1)
	        Buffers: shared hit=834

Você pode ver aqui que você obtém a duração da consulta no início, que você pode estar acostumado a ver no final dos planos de consulta normalmente. Você também verá o texto da consulta, incluindo quaisquer parâmetros.

As ferramentas de visualização populares Explain.depesz e Explain.dalibo aceitam planos de consulta no formato TEXT, mas também suportam o formato JSON. Se alguns de sua equipe preferirem usar ferramentas como PEV e pgMustard, que suportam apenas o formato JSON, talvez você queira definir isso como o formato. Para clientes no ScaleGrid, optamos pelo formato JSON, em parte porque queríamos analisá-lo mais facilmente para nosso próprio recurso de análise de consulta lenta.

Aqui está uma lista completa dos parâmetros auto_explain e seus padrões:

Instalando auto_explain

No ScaleGrid, auto_explain está ativado por padrão, com um limite de 100ms. Você pode configurar isso em Admin -> Config.

No Vanilla PostgreSQL, você pode instalar o auto_explain simplesmente adicionando-o a uma das session_preload_libraries ou shared_preload_libraries . O primeiro tem as vantagens de a) não exigir reinicialização (mas só será carregado em novas sessões) eb) possibilitar ativá-lo apenas para alguns usuários (definindo este parâmetro com ALTER ROLE SET ).


Assim, uma configuração básica para auto_explain pode ser assim:


session_preload_libraries = auto_explain
auto_explain.log_min_duration = 100
auto_explain.log_analyze = true
auto_explain.log_buffers = true
auto_explain.log_format = JSON

LOAD 'auto_explain';