Comprendre pourquoi une requête qui fonctionne bien en développement et en test explose en production peut parfois être un défi. Poursuivez votre lecture pour en savoir plus sur quelques fonctionnalités qui peuvent fournir des informations sur la façon dont vos requêtes se comportent en production.
Requêtes en cours d'exécution
Lorsqu'un client se connecte à un serveur PostgreSQL, le processus principal du serveur PostgreSQL (historiquement appelé le postmaster ) génère un nouveau processus (appelé lebackend ) pour répondre aux demandes du client. Par conséquent, chaque backend attend que son client envoie une requête ou essaie d'en exécuter une.
La vue système pg_stat_activity affiche des informations sur chaque backend en cours d'exécution. En particulier, il montre la requête que le backend est en train d'exécuter s'il est actif, ou la dernière requête qu'il a exécutée s'il attend que le client envoie une autre requête.
Voici deux backends servant des clients connectés à la base de données testdb
, les deux exécutant activement leurs requêtes :
testdb=# select usename,datname,state,query from pg_stat_activity where datname='testdb';
-[ RECORD 1 ]-----------------------------------------------------------------------------
usename | postgres
datname | testdb
state | active
query | SELECT pg_sleep(10);
-[ RECORD 2 ]-----------------------------------------------------------------------------
usename | postgres
datname | testdb
state | active
query | select usename,datname,state,query from pg_stat_activity where datname='testdb';
Parfois, la requête peut attendre un verrou, ce qui indique également inpg_stat_activity. Vous pouvez voir un INSERT en attente d'un verrou de relation ici :
testdb=# select wait_event_type, wait_event, left(query, 60) from pg_stat_activity where datname='testdb';
-[ RECORD 1 ]---+-------------------------------------------------------------
wait_event_type | Client
wait_event | ClientRead
left | lock table t in access exclusive mode;
-[ RECORD 2 ]---+-------------------------------------------------------------
wait_event_type |
wait_event |
left | select wait_event_type, wait_event, left(query, 60) from pg_
-[ RECORD 3 ]---+-------------------------------------------------------------
wait_event_type | Lock
wait_event | relation
left | insert into t values (1);
Pour plus d'informations sur pg_stat_activity, consultez la documentation.
Bien que cette vue soit utile pour comprendre ce que fait actuellement Postgres, elle ne fournit pas d'informations sur les statistiques d'exécution des requêtes, ni d'informations sur les requêtes dont l'exécution est terminée.
Toutes les requêtes exécutées dans le passé
Pour cela, l'extension pg_stat_statements est inestimable. Cette extension est incluse dans la distribution principale de PostgreSQL et également disponible sur les services gérés comme AWS RDS et GCP SQL.
pg_stat_statements (PSS) est une "extension" en termes PostgreSQL, et doit d'abord être installé :
- Consultez la documentation de votre distribution Linux pour voir si l'extension est préinstallée ou si elle nécessite l'installation d'un autre package. Par exemple, sur Centos 7, vous devrez
sudo yum install postgresql-contrib
. - Modifiez le fichier de configuration principal postgresql.conf (généralement sous
/etc
, comme/etc/postgresql/10/main/postgresql.conf
sur Debian) et modifiez la valeur deshared_preload_libraries
à "pg_stat_statements". Il s'agit d'une liste de valeurs séparées par des virgules, donc s'il y a déjà quelque chose, ajoutez une virgule puis "pg_stat_statements". - Pour AWS RDS, vous devrez modifier votre groupe de paramètres actifs et définir la valeur.
- Après avoir modifié "shared_preload_libraries", vous devrez redémarrer le démon PostgreSQL. Malheureusement, il n'y a pas moyen de contourner cela. Sur AWS RDS, vous devrez redémarrer l'instance RDS.
- Après un redémarrage, le serveur PostgreSQL aurait chargé la bibliothèque partagée, et nous pouvons installer l'extension en exécutant
CREATE EXTENSION pg_stat_statements
. Vous devez être un superutilisateur pour exécuter cette commande. - Vous pouvez réellement installer l'extension dans n'importe quelle base de données, et voir les requêtes dans toutes les bases de données.
Une fois l'extension installée, vous pouvez interroger la vue appelée pg_stat_statements
pour obtenir des informations sur chaque requête exécutée depuis l'installation de l'extension.
Les nombres, comme le temps nécessaire pour exécuter la requête, sont accumulés sous forme de somme. Pour le seul temps d'exécution de la requête, quelques statistiques (moyenne, min, max, écart-type) sont présentées. Ces valeurs peuvent être effacées à l'aide de la fonction pg_stat_statements_reset
.
Voici comment une ligne de pg_stat_statements
ressemble à :
testdb=# select * from pg_stat_statements where query like '%pg_sleep%' and dbid=42548;
-[ RECORD 1 ]-------+--------------------
userid | 10
dbid | 42548
queryid | 2649515222348904837
query | SELECT pg_sleep($1)
calls | 1
total_time | 10016.782625
min_time | 10016.782625
max_time | 10016.782625
mean_time | 10016.782625
stddev_time | 0
rows | 1
shared_blks_hit | 0
shared_blks_read | 0
shared_blks_dirtied | 0
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_dirtied | 0
local_blks_written | 0
temp_blks_read | 0
temp_blks_written | 0
blk_read_time | 0
blk_write_time | 0
Outre les paramètres d'identification (utilisateur, base de données, requête), vous pouvez comprendre beaucoup de choses intéressantes sur votre requête :
- Combien de temps il faut généralement pour s'exécuter (
mean_time
) - Combien de lignes il renvoie en moyenne (
rows
/calls
) - La quantité de données lues à partir du cache de tampon partagé et la quantité de données lues à partir du disque (le
shared_blks_read
affiche la quantité totale de données lues par la requête, dontshared_blks_hit
vient du cache) - La quantité de données qui a dû être écrite sur le disque de manière synchrone en raison de la pression du cache (
shared_blks_written
) - La quantité de données écrites, comme le nombre de blocs touchés (
shared_blks_dirtied
) - Le temps passé en lectures et écritures sur le disque (
blk_{read,write}_time
) - Fichiers temporaires écrits et lus depuis (
temp_blks_{read,written}
) - Tables temporaires écrites et lues depuis (
local_*
)
Les temps de lecture et d'écriture du disque ne sont disponibles que si le paramètre de configuration track_io_timing
est allumé. Par défaut, ce n'est pas le cas. Sur la plupart des systèmes Linux modernes, il devrait être possible d'activer ce paramètre. En savoir plus.
Il vaut la peine de prendre un instantané des pg_stat_statements
données en continu à intervalles réguliers pour voir comment ces paramètres évoluent sur une base par requête. L'outil open source pgmetrics peut extraire et exposer les pg_stat_statements
données au format JSON pour une automatisation plus facile.
Requêtes exécutées pendant une plage horaire
Une fois que vous avez un tel système en place, il devient facile de suivre les requêtes exécutées dans un laps de temps donné. Cela facilite le débogage des problèmes tels que la raison pour laquelle un travail par lots nocturne a pris plus de temps que prévu.
En soustrayant les compteurs entre deux horodatages donnés, vous pouvez trouver la plupart des nombres comme auparavant, à l'exception du min, du max et de l'écart type. Cela suffit pour identifier les requêtes qui ont été exécutées dans la plage de temps et les ressources qu'elles ont consommées.
Journaliser les requêtes lentes
Une autre façon d'identifier rapidement les requêtes qui prennent plus de temps que prévu consiste à activer la journalisation des instructions. Vous pouvez spécifier une durée de seuil, et si la requête prend plus de temps que cela pour se terminer, elle est consignée. (Dans le fichier journal standard de PostgreSQL, il n'y en a pas de séparé pour les requêtes lentes.)
Pour activer cette fonctionnalité, modifiez la configuration comme ci-dessous :
log_min_duration_statement = 1000 # in milliseconds
et rechargez Postgres. Vous pouvez également utiliser ALTER SYSTEM
:
ALTER SYSTEM SET log_min_duration_statement = 1000; -- in milliseconds
Avec cela, toute instruction (y compris celles qui ne sont pas DML) qui prend plus d'une seconde pour se terminer est enregistrée :
2019-12-02 16:57:05.727 UTC [8040] postgres@testdb LOG: duration: 10017.862 ms statement: SELECT pg_sleep(10);
Le temps réel pris par la requête, ainsi que le texte SQL complet, sont enregistrés.
Si vous disposez d'un système de surveillance des journaux et pouvez suivre le nombre de requêtes lentes par heure / par jour, cela peut servir de bon indicateur des performances de l'application.
Plans d'exécution des requêtes
Une fois que vous avez localisé une requête qui, selon vous, devrait s'exécuter plus rapidement, l'étape suivante consiste à examiner son plan de requête. En règle générale, vous avez besoin du plan de requête réel des serveurs de production pour travailler avec. Si vous pouvez exécuter EXPLAIN sur des serveurs de production aussi bien, sinon vous devez vous fier à auto_explain
.
auto_explain
est une autre extension principale de PostgreSQL, soit déjà installée, soit disponible en tant que package "contrib" pour votre distribution. Il est également disponible sur AWSRDS. auto_explain
est un peu plus simple à installer que pg_stat_statements
:
- Modifier la configuration postgres (ou le groupe de paramètres RDS)
shared_preload_libraries
pour inclureauto_explain
. - Vous n'avez pas besoin de redémarrer Postgres, vous pouvez simplement exécuter :
LOAD 'auto_explain';
. - Vous voudrez configurer ses paramètres, au moins celui-ci :
auto_explain.log_min_duration = 1000 # seconds
Essentiellement, chaque fois qu'une requête prend plus de temps que auto_explain.log_min_duration
nombre de secondes pour terminer, auto_explain enregistre la requête et son plan d'exécution de la requête dans le fichier journal, comme ceci :
2019-12-04 09:23:05.130 UTC [12823] postgres@testdb LOG: duration: 11025.765 ms plan:
Query Text: select pg_sleep(11);
Result (cost=0.00..0.01 rows=1 width=4) (actual time=11025.716..11025.718 rows=1 loops=1)
Output: pg_sleep('11'::double precision)
Il peut également enregistrer le plan au format JSON, si vous disposez de scripts capables de le traiter :
2019-12-02 17:30:53.676 UTC [8040] postgres@testdb LOG: duration: 10000.230 ms plan:
{
"Query Text": "SELECT pg_sleep(10);",
"Plan": {
"Node Type": "Result",
"Parallel Aware": false,
"Startup Cost": 0.00,
"Total Cost": 0.01,
"Plan Rows": 1,
"Plan Width": 4,
"Actual Startup Time": 10000.205,
"Actual Total Time": 10000.206,
"Actual Rows": 1,
"Actual Loops": 1,
"Output": ["pg_sleep('10'::double precision)"],
"Shared Hit Blocks": 0,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"I/O Read Time": 0.000,
"I/O Write Time": 0.000
},
"Triggers": [
]
}
Dans Postgres, il n'y a pas d'autre moyen que auto_explain pour consulter le plan d'exécution d'une requête déjà exécutée, ce qui fait de auto_explain un outil important dans votre boîte à outils.