Comment consigner les plans d'exécution de requêtes pour Amazon RDS PostgreSQL ou Aurora PostgreSQL afin d'optimiser les performances des requêtes ?

Lecture de 7 minute(s)

Je veux savoir quels plans d'exécution sont utilisés pour mes requêtes afin de les ajuster en conséquence. Comment puis-je consigner les plans d'exécution de ces requêtes pour une instance de base de données PostgreSQL Amazon Relational Database Service (Amazon RDS) ou un cluster de base de données PostgreSQL Amazon Aurora ?

Résolution

Vous pouvez utiliser le module auto_explain pour consigner les plans d'exécution de requêtes.

1. Ajoutez auto_explain au paramètre shared_preload_libraries.

2. Redémarrez l'instance de base de données ou le cluster.

3. Pour activer auto_explain, vous devez remplacer le paramètre auto_explain.log_min_duration par une valeur autre que -1. Cette valeur est la durée minimale d'exécution de l'instruction, en milliseconde. Lorsque la durée est épuisée et que l'instruction s'exécute, son plan d'exécution est consigné. Si vous définissez le paramètre sur 0, tous les plans sont consignés.

Important : l'attribution de la valeur 0 au paramètre auto_explain.log_min_duration entraîne une dégradation des performances et une consommation importante d'espace de stockage. Cela peut causer des problèmes avec l'instance.

4. Exécutez des requêtes sur la base de données.

5. Affichez ou téléchargez les fichiers journaux PostgreSQL, notamment les plans d'exécution. L'exemple de plan d'exécution suivant comporte la durée d'exécution (4 673,182 ms), ainsi que le plan d'exécution avec le texte de la requête :

2020-01-02 03:08:44 UTC:27.0.3.156(21356):postgres@postgres:[2040]:LOG: duration: 4673.182 ms plan:
Query Text: SELECT COUNT(*) FROM hoge ORDER BY 1;
Sort (cost=215575.00..215575.00 rows=1 width=8)
Sort Key: (count(*))
-> Aggregate (cost=215574.98..215574.99 rows=1 width=8)
-> Seq Scan on hoge (cost=0.00..190336.18 rows=10095518 width=0)

Utiliser les paramètres auto_explain pour ajuster les performances de requêtes

En plus d'activer pg_autoexplain, le paramètre auto_explain.log_min_duration vous permet également d'utiliser d'autres paramètres utiles. Vous pouvez utiliser les paramètres auto_explain suivants (que vous pouvez modifier sans effectuer un redémarrage) pour ajuster les performances de requêtes. Pour plus d'informations, consultez la documentation PostgreSQL relative à chaque paramètre.

auto_explain.log_analyze

Le paramètre auto_explain.log_analyzeimprime une sortie EXPLAIN ANALYZE (au lieu d'une sortie EXPLAIN) lorsqu'un plan d'exécution est consigné. Ce paramètre peut dégrader les performances de requêtes en raison des frais généraux ; la valeur par défaut est off (désactivé). Pour plus d'informations, consultez auto_explain.log_analyze dans la documentation Postgres.

Consultez l'exemple suivant :

2020-02-01 07:42:09 UTC:27.0.3.145(29943):master@postgres:[789]:LOG:  duration: 18.658 ms  plan:
 Query Text: SELECT COUNT(*) FROM t1 INNER JOIN t2 USING(id);
 Aggregate  (cost=577.45..577.46 rows=1 width=8) (actual time=18.641..18.641 rows=1 loops=1)
   ->  Hash Join  (cost=269.98..552.45 rows=9999 width=0) (actual time=8.108..16.576 rows=9999 loops=1)
         Hash Cond: (t1.id = t2.id)
         ->  Seq Scan on t1  (cost=0.00..144.99 rows=9999 width=4) (actual time=0.839..4.151 rows=9999 loops=1)
         ->  Hash  (cost=144.99..144.99 rows=9999 width=4) (actual time=7.186..7.186 rows=9999 loops=1)
               Buckets: 16384  Batches: 1  Memory Usage: 480kB
               ->  Seq Scan on t2  (cost=0.00..144.99 rows=9999 width=4) (actual time=0.667..4.289 rows=9999 loops=1)

auto_explain.log_buffers

Utilisez le paramètre auto_explain.log_buffers pour déterminer si les statistiques d'utilisation de la mémoire tampon sont imprimées lorsque vous consignez un plan d'exécution. L'utilisation de ce paramètre a le même effet que l'utilisation de l'option Buffers avec Explain. Veillez à activer auto_explain.log_analyze avec auto_explain.log_buffers. Par défaut, ce paramètre est off (désactivé), et vous ne pouvez le modifier que si vous êtes un superutilisateur. Pour plus d'informations, consultez auto_explain.log_buffers dans la documentation PostgreSQL.

Consultez l'exemple de sortie suivant :

2020-02-01 08:02:02 UTC:27.0.3.145(27477):master@postgres:[15514]:LOG:  duration: 14.875 ms  plan:
 Query Text: SELECT COUNT(*) FROM t1 INNER JOIN t2 USING(id);
 Aggregate  (cost=577.45..577.46 rows=1 width=8) (actual time=14.861..14.861 rows=1 loops=1)
   Buffers: shared hit=93
   ->  Hash Join  (cost=269.98..552.45 rows=9999 width=0) (actual time=5.293..12.768 rows=9999 loops=1)
         Hash Cond: (t1.id = t2.id)
         Buffers: shared hit=93
         ->  Seq Scan on t1  (cost=0.00..144.99 rows=9999 width=4) (actual time=0.007..2.385 rows=9999 loops=1)
               Buffers: shared hit=45
         ->  Hash  (cost=144.99..144.99 rows=9999 width=4) (actual time=5.250..5.250 rows=9999 loops=1)
               Buckets: 16384  Batches: 1  Memory Usage: 480kB
               Buffers: shared hit=45
               ->  Seq Scan on t2  (cost=0.00..144.99 rows=9999 width=4) (actual time=0.009..2.348 rows=9999 loops=1)
                     Buffers: shared hit=45

auto_explain.log_nested_statements

Utilisez le paramètre auto_explain.log_nested_statements pour prendre en compte les instructions imbriquées relatives à la journalisation. Les plans de requêtes de niveau supérieur sont consignés, par défaut, sauf si vous activez ce paramètre. La valeur par défaut est off (désactivé). Pour plus d'informations, consultez auto_explain.nested_statements dans la documentation PostgreSQL.

Consultez l'exemple suivant :

CREATE OR REPLACE FUNCTION count_tables() RETURNS integer AS $$
        DECLARE
         i integer;
         j integer;
        BEGIN
                SELECT COUNT(*) INTO i FROM t1;
                SELECT COUNT(*) INTO j FROM t2;
                RETURN i + j;                
        END;
$$ LANGUAGE plpgsql;

Consultez l'exemple de sortie suivant :

2020-02-01 08:15:25 UTC:27.0.3.145(27477):master@postgres:[15514]:LOG:  duration: 0.651 ms  plan:
 Query Text: SELECT COUNT(*)        FROM t1
 Aggregate  (cost=169.99..170.00 rows=1 width=8)
   ->  Seq Scan on t1  (cost=0.00..144.99 rows=9999 width=0)
2020-02-01 08:15:25 UTC:27.0.3.145(27477):master@postgres:[15514]:CONTEXT:  SQL statement "SELECT COUNT(*)        FROM t1"
 PL/pgSQL function count_tables() line 6 at SQL statement
2020-02-01 08:15:25 UTC:27.0.3.145(27477):master@postgres:[15514]:LOG:  duration: 0.637 ms  plan:
 Query Text: SELECT COUNT(*)        FROM t2
 Aggregate  (cost=169.99..170.00 rows=1 width=8)
   ->  Seq Scan on t2  (cost=0.00..144.99 rows=9999 width=0)
2020-02-01 08:15:25 UTC:27.0.3.145(27477):master@postgres:[15514]:CONTEXT:  SQL statement "SELECT COUNT(*)        FROM t2"
 PL/pgSQL function count_tables() line 7 at SQL statement
2020-02-01 08:15:25 UTC:27.0.3.145(27477):master@postgres:[15514]:LOG:  duration: 1.435 ms  plan:
 Query Text: SELECT count_tables();
 Result  (cost=0.00..0.26 rows=1 width=4)

auto_explain.log_timing

Utilisez le paramètre auto_explain.log_timing pour contrôler si les informations de synchronisation par nœud sont imprimées lorsque vous consignez un plan d'exécution. L'utilisation de ce paramètre est similaire à celle de l'option Timing avec Explain. La désactivation de auto_explain.log_timing peut réduire la surcharge liée à la lecture répétée de l'horloge système. La valeur par défaut est on (activé). Pour plus d'informations, consultez auto_explain.log_timing dans la documentation PostgreSQL.

auto_explain.log_triggers

Utilisez le paramètre auto_explain.log_triggers pour inclure les statistiques d'exécution de déclencheurs lorsque vous consignez un plan d'exécution. Vous devez également activer auto_explain.log_analyze lorsque vous utilisez auto_explain.log_triggers. La valeur par défaut est off (désactivée).

Pour plus d'informations, consultez auto_explain.log_triggers dans la documentation PostgreSQL.

Consultez l'exemple suivant :

CREATE FUNCTION emp_log_trigger_func() RETURNS trigger AS $emp_stamp$
    DECLARE
        count integer;
    BEGIN
        SELECT COUNT(*) INTO count FROM emp WHERE empname = NEW.empname;
        INSERT INTO emp_log(created_at, operation, user_name) VALUES(current_timestamp, TG_OP, user);
        RETURN NEW;
    END;
$emp_stamp$ LANGUAGE plpgsql;
CREATE TRIGGER emp_stamp BEFORE INSERT OR UPDATE ON emp
    FOR EACH ROW EXECUTE PROCEDURE emp_log_trigger_func();

Consultez l'exemple de sortie suivant :

2020-02-01 08:57:44 UTC:27.0.3.145(27477):master@postgres:[15514]:LOG:  duration: 1.463 ms  plan:
 Query Text: INSERT INTO emp_log(created_at, operation, user_name) VALUES(current_timestamp, TG_OP, user)
 Insert on emp_log  (cost=0.00..0.03 rows=1 width=168) (actual time=1.461..1.461 rows=0 loops=1)
   ->  Result  (cost=0.00..0.03 rows=1 width=168) (actual time=0.009..0.010 rows=1 loops=1)
2020-02-01 08:57:44 UTC:27.0.3.145(27477):master@postgres:[15514]:CONTEXT:  SQL statement "INSERT INTO emp_log(created_at, operation, user_name) VALUES(current_timestamp, TG_OP, user)"
 PL/pgSQL function emp_log_trigger_func() line 3 at SQL statement
2020-02-01 08:57:44 UTC:27.0.3.145(27477):master@postgres:[15514]:LOG:  duration: 1.602 ms  plan:
 Query Text: INSERT INTO emp VALUES('name', 100, current_timestamp, 'hoge');
 Insert on emp  (cost=0.00..0.01 rows=1 width=76) (actual time=1.600..1.600 rows=0 loops=1)
   ->  Result  (cost=0.00..0.01 rows=1 width=76) (actual time=0.006..0.006 rows=1 loops=1)
 Trigger emp_stamp: time=1.584 calls=1

auto_explain.log_verbose

Utilisez le paramètre auto_explain.log_verbose pour déterminer si des informations détaillées sont imprimées lorsque vous consignez un plan d'exécution. L'utilisation de ce paramètre est similaire à celle de l'option Verbose avec Explain. La valeur par défaut est off (désactivé). Pour plus d'informations, consultez auto_explain.log_verbose dans la documentation PostgreSQL.

Consultez l'exemple suivant :

2020-02-01 09:03:20 UTC:27.0.3.145(27477):master@postgres:[15514]:LOG:  duration: 3.492 ms  plan:
 Query Text: SELECT COUNT(*) FROM t1 INNER JOIN t2 USING(id);
 Aggregate  (cost=577.45..577.46 rows=1 width=8)
   Output: count(*)
   ->  Hash Join  (cost=269.98..552.45 rows=9999 width=0)
         Hash Cond: (t1.id = t2.id)
         ->  Seq Scan on public.t1  (cost=0.00..144.99 rows=9999 width=4)
               Output: t1.id
         ->  Hash  (cost=144.99..144.99 rows=9999 width=4)
               Output: t2.id
               Buckets: 16384  Batches: 1  Memory Usage: 480kB
               ->  Seq Scan on public.t2  (cost=0.00..144.99 rows=9999 width=4)
                     Output: t2.id

Ou, si vous voulez afficher le plan Explain pour moins de requêtes à des fins de réglage, vous pouvez exécuter l'instruction EXPLAIN ANALYZE sur ces requêtes. Cela élimine les frais généraux liés à la journalisation et affiche le plan de la requête étape par étape, ainsi que la durée d'exécution de chaque étape. Si vous appelez manuellement l'instruction EXPLAIN ANALYZE , vous pouvez identifier des événements tels que l'étape qui a généré les fichiers temporaires, l'étape qui effectue l'analyse séquentielle, etc.

postgres=> EXPLAIN ANALYZE SELECT * FROM hoge ORDER BY 1;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------
Sort (cost=7343904.60..7444904.60 rows=40400000 width=4) (actual time=37795.033..45133.431 rows=40400000 loops=1)
Sort Key: id
Sort Method: external merge Disk: 553512kB
-> Seq Scan on hoge (cost=0.00..582762.00 rows=40400000 width=4) (actual time=0.579..8184.498 rows=40400000 loops=1)
Planning Time: 0.549 ms
Execution Time: 47161.516 ms
(6 rows)