Le module auto_explain fournit un moyen de tracer les plans d'exécution des requêtes lentes automatiquement, sans qu'il soit nécessaire de lancer EXPLAIN(7) manuellement. C'est particulièrement utile pour repérer les requêtes non optimisées sur de grosses applications.
Le module ne fournit pas de fonctions accessibles par SQL. Pour l'utiliser, il suffit de le charger sur le serveur. Il peut être chargé dans une session individuelle :
LOAD 'auto_explain';
(Seul le super-utilisateur peut le faire.) Un usage plus caractéristique est de le précharger dans toutes les sessions en incluant auto_explain dans shared_preload_libraries dans le fichier postgresql.conf. Il est alors possible de récupérer les requêtes lentes non prévues, quel que soit le moment où elles se produisent. Évidemment, il y a un prix à payer pour cela.
Plusieurs paramètres de configuration contrôlent le comportement d'auto_explain. Le comportement par défaut est de ne rien faire. Il est donc nécessaire de préciser au minimum auto_explain.log_min_duration pour obtenir un résultat.
auto_explain.log_min_duration est la durée minimale d'exécution de requête à partir de laquelle le plan d'exécution sera tracé. Son unité est la milliseconde. La positionner à zéro trace tous les plans. -1 (la valeur par défaut) désactive l'écriture des plans. Positionnée à 250ms, tous les ordres qui durent 250 ms ou plus seront tracés. Seuls les super-utilisateurs peuvent modifier ce paramétrage.
auto_explain.log_analyze entraîne l'écriture du résultat de EXPLAIN ANALYZE, à la place du résultat de EXPLAIN, lorsqu'un plan d'exécution est tracé. Ce paramètre est désactivé par défaut. Seuls les super-utilisateurs peuvent modifier ce paramètre.
![[Note]](images/note.png)
Lorsque ce paramètre est activé, un chronométrage par nœud du plan est calculé pour tous les ordres exécutés, qu'ils durent suffisamment longtemps pour être réellement tracés, ou non. Ceci peut avoir des conséquences très négatives sur les performances.
auto_explain.log_verbose entraîne l'écriture du résultat de EXPLAIN VERBOSE au lieu du résultat de la commande simple EXPLAIN, lorsqu'un plan d'exécution est tracé. Ce paramètre est désactivé par défaut. Seuls les super-utilisateurs peuvent modifier ce paramètre.
auto_explain.log_buffers permet d'obtenir la même sortie qu'un EXPLAIN (ANALYZE, BUFFERS), plutôt que la sortie EXPLAIN habituelle quand un plan d'exécution est tracé. Ce paramètre est désactivé par défaut. Seuls les superutilisateurs peuvent modifier cette configuration. Ce paramètre n'a pas d'effet sauf si le paramètre auto_explain.log_analyze est activé.
auto_explain.log_format sélectionne le format de sortie du EXPLAIN à utiliser. Les valeurs autorisées sont text, xml, json et yaml. La valeur par défaut est text. Seuls les super-utilisateurs peuvent modifier ce paramètre.
auto_explain.log_nested_statements entraîne la prise en compte des ordres imbriqués (les requêtes exécutées dans une fonction) dans la trace. Quand il est désactivé, seuls les plans d'exécution de plus haut niveau sont tracés. Ce paramètre est désactivé par défaut. Seuls les super-utilisateurs peuvent modifier ce paramètre.
Pour positionner ces paramètres dans le fichier postgresql.conf, il convient d'ajouter auto_explain à custom_variable_classes. Un usage classique serait :
# postgresql.conf
shared_preload_libraries = 'auto_explain'
custom_variable_classes = 'auto_explain'
auto_explain.log_min_duration = '3s'
postgres=# LOAD 'auto_explain';
postgres=# SET auto_explain.log_min_duration = 0;
postgres=# SELECT count(*)
FROM pg_class, pg_index
WHERE oid = indrelid AND indisunique;
Ceci devrait produire un résultat de ce style dans les journaux applicatifs :
LOG: duration: 3.651 ms plan:
Query Text: SELECT count(*)
FROM pg_class, pg_index
WHERE oid = indrelid AND indisunique;
Aggregate (cost=16.79..16.80 rows=1 width=0) (actual time=3.626..3.627 rows=1 loops=1)
-> Hash Join (cost=4.17..16.55 rows=92 width=0) (actual time=3.349..3.594 rows=92 loops=1)
Hash Cond: (pg_class.oid = pg_index.indrelid)
-> Seq Scan on pg_class (cost=0.00..9.55 rows=255 width=4) (actual time=0.016..0.140 rows=255 loops=1)
-> Hash (cost=3.02..3.02 rows=92 width=4) (actual time=3.238..3.238 rows=92 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 4kB
-> Seq Scan on pg_index (cost=0.00..3.02 rows=92 width=4) (actual time=0.008..3.187 rows=92 loops=1)
Filter: indisunique
Takahiro Itagaki <itagaki.takahiro@oss.ntt.co.jp>
Modules supplémentaires fournis
