Lorsque vous travaillez avec des bases de données OLTP (OnLine Transaction Processing), les performances des requêtes sont primordiales car elles ont un impact direct sur l'expérience utilisateur. Les requêtes lentes signifient que l'application ne répond pas et est lente, ce qui entraîne de mauvais taux de conversion, des utilisateurs mécontents et toutes sortes de problèmes.
OLTP est l'un des cas d'utilisation courants de PostgreSQL, vous voulez donc que vos requêtes s'exécutent aussi facilement que possible. Dans ce blog, nous aimerions parler de la façon dont vous pouvez identifier les problèmes liés aux requêtes lentes dans PostgreSQL.
Comprendre le journal lent
Généralement, la façon la plus courante d'identifier les problèmes de performances avec PostgreSQL est de collecter les requêtes lentes. Il existe plusieurs façons de le faire. Tout d'abord, vous pouvez l'activer sur une seule base de données :
pgbench=# ALTER DATABASE pgbench SET log_min_duration_statement=0;
ALTER DATABASEAprès cela, toutes les nouvelles connexions à la base de données « pgbench » seront enregistrées dans le journal PostgreSQL.
Il est également possible de l'activer globalement en ajoutant :
log_min_duration_statement = 0à la configuration PostgreSQL, puis rechargez la configuration :
pgbench=# SELECT pg_reload_conf();
pg_reload_conf
----------------
t
(1 row)Cela active la journalisation de toutes les requêtes sur toutes les bases de données de votre PostgreSQL. Si vous ne voyez aucun journal, vous pouvez également activer logging_collector =on. Les journaux incluront tout le trafic provenant des tables système PostgreSQL, ce qui le rendra plus bruyant. Pour nos besoins, tenons-nous en à la journalisation au niveau de la base de données.
Ce que vous verrez dans le journal sont les entrées ci-dessous :
2020-02-21 09:45:39.022 UTC [13542] LOG: duration: 0.145 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 29817899;
2020-02-21 09:45:39.022 UTC [13544] LOG: duration: 0.107 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 11782597;
2020-02-21 09:45:39.022 UTC [13529] LOG: duration: 0.065 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 16318529;
2020-02-21 09:45:39.022 UTC [13529] LOG: duration: 0.082 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + 3063 WHERE tid = 3244;
2020-02-21 09:45:39.022 UTC [13526] LOG: duration: 16.450 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + 1359 WHERE bid = 195;
2020-02-21 09:45:39.023 UTC [13523] LOG: duration: 15.824 ms statement: UPDATE pgbench_accounts SET abalance = abalance + -3726 WHERE aid = 5290358;
2020-02-21 09:45:39.023 UTC [13542] LOG: duration: 0.107 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -2716 WHERE tid = 1794;
2020-02-21 09:45:39.024 UTC [13544] LOG: duration: 0.112 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -3814 WHERE tid = 278;
2020-02-21 09:45:39.024 UTC [13526] LOG: duration: 0.060 ms statement: INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (4876, 195, 39955137, 1359, CURRENT_TIMESTAMP);
2020-02-21 09:45:39.024 UTC [13529] LOG: duration: 0.081 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + 3063 WHERE bid = 369;
2020-02-21 09:45:39.024 UTC [13523] LOG: duration: 0.063 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
2020-02-21 09:45:39.024 UTC [13542] LOG: duration: 0.100 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + -2716 WHERE bid = 210;
2020-02-21 09:45:39.026 UTC [13523] LOG: duration: 0.092 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -3726 WHERE tid = 67;
2020-02-21 09:45:39.026 UTC [13529] LOG: duration: 0.090 ms statement: INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (3244, 369, 16318529, 3063, CURRENT_TIMESTAMP);Vous pouvez voir des informations sur la requête et sa durée. Pas grand-chose d'autre, mais c'est certainement un bon point de départ. La principale chose à garder à l'esprit est que toutes les requêtes lentes ne sont pas un problème. Parfois, les requêtes doivent accéder à une quantité importante de données et on s'attend à ce qu'elles prennent plus de temps pour accéder et analyser toutes les informations demandées par l'utilisateur. Une autre question est de savoir ce que signifie "lent" ? Cela dépend principalement de l'application. Si nous parlons d'applications interactives, tout ce qui est plus lent qu'une seconde est probablement perceptible. Idéalement, tout est exécuté dans la limite de 100 à 200 millisecondes.
Développement d'un plan d'exécution de requête
Une fois que nous avons déterminé qu'une requête donnée est effectivement quelque chose que nous voulons améliorer, nous devrions jeter un œil au plan d'exécution de la requête. Tout d'abord, il peut arriver que nous ne puissions rien y faire et nous devrons accepter que la requête donnée soit simplement lente. Deuxièmement, les plans d'exécution des requêtes peuvent changer. Les optimiseurs essaient toujours de choisir le plan d'exécution le plus optimal, mais ils prennent leurs décisions en se basant uniquement sur un échantillon de données. Il peut donc arriver que le plan d'exécution de la requête change dans le temps. Dans PostgreSQL, vous pouvez vérifier le plan d'exécution de deux manières. Tout d'abord, le plan d'exécution estimé, en utilisant EXPLAIN :
pgbench=# EXPLAIN SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
QUERY PLAN
----------------------------------------------------------------------------------------------
Index Scan using pgbench_accounts_pkey on pgbench_accounts (cost=0.56..8.58 rows=1 width=4)
Index Cond: (aid = 5290358)Comme vous pouvez le voir, nous sommes censés accéder aux données en utilisant la recherche de clé primaire. Si nous voulons revérifier comment exactement la requête sera exécutée, nous pouvons utiliser EXPLAIN ANALYZE :
pgbench=# EXPLAIN ANALYZE SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------
Index Scan using pgbench_accounts_pkey on pgbench_accounts (cost=0.56..8.58 rows=1 width=4) (actual time=0.046..0.065 rows=1 loops=1)
Index Cond: (aid = 5290358)
Planning time: 0.053 ms
Execution time: 0.084 ms
(4 rows)Maintenant, PostgreSQL a exécuté cette requête et il peut nous dire non seulement les estimations, mais aussi les chiffres exacts en ce qui concerne le plan d'exécution, le nombre de lignes consultées, etc. N'oubliez pas que la journalisation de toutes les requêtes peut devenir une surcharge importante pour votre système. Vous devez également garder un œil sur les journaux et vous assurer qu'ils sont correctement tournés.
Pg_stat_statements
Pg_stat_statements est l'extension qui collecte les statistiques d'exécution pour différents types de requêtes.
pgbench=# select query, calls, total_time, min_time, max_time, mean_time, stddev_time, rows from public.pg_stat_statements order by calls desc LIMIT 10;
query | calls | total_time | min_time | max_time | mean_time | stddev_time | rows
------------------------------------------------------------------------------------------------------+-------+------------------+----------+------------+---------------------+---------------------+-------
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 30437 | 6636.83641200002 | 0.006533 | 83.832148 | 0.218051595492329 | 1.84977058799388 | 30437
BEGIN | 30437 | 231.095600000001 | 0.000205 | 20.260355 | 0.00759258796859083 | 0.26671126085716 | 0
END | 30437 | 229.483213999999 | 0.000211 | 16.980678 | 0.0075396134310215 | 0.223837608828596 | 0
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 30437 | 290021.784321001 | 0.019568 | 805.171845 | 9.52859297305914 | 13.6632712046825 | 30437
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 30437 | 6667.27243200002 | 0.00732 | 212.479269 | 0.219051563294674 | 2.13585110968012 | 30437
SELECT abalance FROM pgbench_accounts WHERE aid = $1 | 30437 | 3702.19730600006 | 0.00627 | 38.860846 | 0.121634763807208 | 1.07735927551245 | 30437
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4, CURRENT_TIMESTAMP) | 30437 | 2349.22475800002 | 0.003218 | 61.372127 | 0.0771831901304325 | 0.971590327400244 | 30437
SELECT $1 | 6847 | 60.785467 | 0.002321 | 7.882384 | 0.00887767883744706 | 0.105198744982906 | 6847
insert into pgbench_tellers(tid,bid,tbalance) values ($1,$2,$3) | 5000 | 18.592042 | 0.001572 | 0.741427 | 0.0037184084 | 0.0137660355678027 | 5000
insert into pgbench_tellers(tid,bid,tbalance) values ($1,$2,$3) | 3000 | 7.323788 | 0.001598 | 0.40152 | 0.00244126266666667 | 0.00834442591085048 | 3000
(10 rows)Comme vous pouvez le voir sur les données ci-dessus, nous avons une liste de différentes requêtes et des informations sur leurs temps d'exécution - ce n'est qu'une partie des données que vous pouvez voir dans les pg_stat_statements mais c'est suffisant pour nous faire comprendre que notre recherche de clé primaire prend parfois près de 39 secondes - cela n'a pas l'air bien et c'est certainement quelque chose que nous voulons étudier.
Si vous n'avez pas activé pg_stat_statements, vous pouvez le faire de manière standard. Soit via le fichier de configuration et
shared_preload_libraries = 'pg_stat_statements'Ou vous pouvez l'activer via la ligne de commande PostgreSQL :
pgbench=# CREATE EXTENSION pg_stat_statements;
CREATE EXTENSIONUtiliser ClusterControl pour éliminer les requêtes lentes
Si vous utilisez ClusterControl pour gérer votre base de données PostgreSQL, vous pouvez l'utiliser pour collecter des données sur les requêtes lentes.
Comme vous pouvez le voir, il collecte des données sur l'exécution de la requête - les lignes envoyées et examiné, les statistiques de temps d'exécution et ainsi de suite. Avec lui, vous pouvez facilement identifier les requêtes les plus coûteuses et voir à quoi ressemblent les temps d'exécution moyens et maximaux. Par défaut, ClusterControl collecte les requêtes qui ont pris plus de 0,5 seconde à se terminer, vous pouvez modifier cela dans les paramètres :
Conclusion
Ce court blog ne couvre en aucun cas tous les aspects et outils utiles pour identifier et résoudre les problèmes de performances des requêtes dans PostgreSQL. Nous espérons que c'est un bon début et qu'il vous aidera à comprendre ce que vous pouvez faire pour identifier la cause première des requêtes lentes.
