Suivi des requêtes distribuées dans les journaux PostgreSQL dans Aurora PostgreSQL Limitless Database - Amazon Aurora

Les traductions sont fournies par des outils de traduction automatique. En cas de conflit entre le contenu d'une traduction et celui de la version originale en anglais, la version anglaise prévaudra.

Suivi des requêtes distribuées dans les journaux PostgreSQL dans Aurora PostgreSQL Limitless Database

Le suivi des requêtes distribuées est un outil permettant de suivre et de corréler les requêtes dans les journaux PostgreSQL dans Aurora PostgreSQL Limitless Database. Dans Aurora PostgreSQL, l’ID de transaction sert à reconnaître chaque transaction. Toutefois, dans Aurora PostgreSQL Limitless Database, le même ID de transaction peut apparaître sur plusieurs routeurs. C’est pourquoi il est préférable d’utiliser l’ID de suivi dans Limitless Database.

Voici les principaux cas d’utilisation :

  • Utilisez la fonction rds_aurora.limitless_get_last_trace_id() pour trouver l’ID de suivi unique de la dernière requête exécutée dans la session en cours. Effectuez ensuite une recherche dans le groupe de journaux du cluster de bases de données dans Amazon CloudWatch Logs à l’aide de cet ID de suivi pour trouver tous les journaux associés.

    Vous pouvez utiliser les paramètres log_min_messages et log_min_error_statement conjointement pour contrôler le volume des journaux affichés et enregistrer une instruction contenant l’ID de suivi.

  • Utilisez le paramètre log_min_duration_statement pour définir la durée d’exécution au-delà de laquelle toutes les requêtes enregistrent leur temps d’exécution et leur ID de suivi. Cette durée d’exécution peut ensuite être recherchée dans le groupe de journaux du cluster de bases de données de CloudWatch Logs afin d’identifier les nœuds constituant des goulots d’étranglement et d’évaluer les efforts d’optimisation du planificateur.

    Le paramètre log_min_duration_statement active l’ID de suivi pour tous les nœuds, quels que soient les valeurs des paramètres log_min_messages et log_min_error_statement.

ID de suivi

Cette fonctionnalité repose sur un identifiant unique, désigné sous le nom d’ID de suivi. L’ID de suivi est une chaîne composée de 31 chiffres, ajoutée aux lignes de journal de type STATEMENT dans les journaux PostgreSQL. Il sert d’identifiant unique permettant de corréler les entrées associées à l’exécution d’une requête donnée. Par exemple, 1126253375719408504000000000011 et 1126253375719408495000000000090.

L’ID de suivi est composé des éléments suivants :

  • Identifiant de transaction : les 20 premiers chiffres, identifiant de manière unique la transaction.

  • Identifiant de commande : les 30 premiers chiffres, indiquant une requête individuelle au sein d’une transaction.

    Si plus de 4 294 967 294 requêtes sont exécutées dans un bloc de transaction explicite, l’identifiant de commande revient à 1. Dans ce cas, vous êtes averti par le message LOG suivant dans le journal PostgreSQL :

    wrapping around the tracing ID back to 1 after running 4294967294 (4.2 billion or 2^32-2) queries inside of an explicit transaction block
  • Identifiant du type de nœud : le dernier chiffre indiquant si le nœud fonctionne en tant que routeur coordinateur (1) ou en tant que nœud participant (0).

Les exemples suivants illustrent les composants de l’ID de suivi :

  • 1126253375719408504000000000011:

    • Identifiant de transaction : 1126253375719408504

    • Identifiant de commande : 112625337571940850400000000001 indique la première commande du bloc de transactions

    • Identifiant du type de nœud : 1 indique un routeur coordinateur

  • 1126253375719408495000000000090:

    • Identifiant de transaction : 1126253375719408495

    • Identifiant de commande : 112625337571940849500000000009 indique la neuvième commande du bloc de transactions

    • Identifiant du type de nœud : 0 indique un nœud participant

Utilisation du suivi des requêtes

Effectuez les tâches suivantes pour activer le suivi des requêtes :

  1. Vérifiez que le suivi est activé.

    Pour effectuer la vérification, utilisez la commande suivante :

    SHOW rds_aurora.limitless_log_distributed_trace_id;

    Elle est activée par défaut (on). S’il n’est pas activé, définissez-le à l’aide de la commande suivante :

    SET rds_aurora.limitless_log_distributed_trace_id = on;
  2. Contrôlez le volume de journaux affichés en configurant le niveau de gravité des journaux.

    Le volume des journaux est contrôlé par le paramètre log_min_messages. Le paramètre log_min_error_statement est utilisé pour afficher la ligne STATEMENT contenant l’ID de suivi. Les deux sont définis sur ERROR par défaut. Pour effectuer la vérification, utilisez les commandes suivantes :

    SHOW log_min_messages; SHOW log_min_error_statement;

    Pour mettre à jour le niveau de gravité et afficher la ligne STATEMENT correspondant à la session en cours, utilisez les commandes suivantes avec l’un de ces niveaux de gravité :

    SET log_min_messages = 'DEBUG5 | DEBUG4 | DEBUG3 | DEBUG2 | DEBUG1 | INFO | NOTICE | WARNING | ERROR | LOG | FATAL | PANIC'; SET log_min_error_statement = 'DEBUG5 | DEBUG4 | DEBUG3 | DEBUG2 | DEBUG1 | INFO | NOTICE | WARNING | ERROR | LOG | FATAL | PANIC';

    Exemples :

    SET log_min_messages = 'WARNING'; SET log_min_error_statement = 'WARNING';
  3. Activez l’affichage de l’ID de suivi dans les journaux pour les exécutions dépassant une durée spécifique.

    Le paramètre log_min_duration_statement peut être modifié en fonction de la durée minimale d’exécution d’une requête, au-delà de laquelle celle-ci enregistre une ligne de journal indiquant sa durée d’exécution ainsi que les identifiants de suivi dans le cluster de bases de données. Ce paramètre est défini sur -1 par défaut, ce qui signifie qu’il est désactivé. Pour effectuer la vérification, utilisez la commande suivante :

    SHOW log_min_duration_statement;

    En le définissant sur 0, la durée d’exécution et l’ID de suivi sont enregistrés dans les journaux pour chaque requête du cluster de bases de données. Vous pouvez le définir sur 0 pour la session actuelle en utilisant la commande suivante :

    SET log_min_duration_statement = 0;
  4. Obtenez l’ID de suivi.

    Après avoir exécuté une requête (même à l’intérieur d’un bloc de transaction explicite), appelez la fonction rds_aurora.limitless_get_last_trace_id pour obtenir l’ID de suivi de la dernière requête exécutée :

    SELECT * FROM rds_aurora.limitless_get_last_trace_id();

    Cette fonction renvoie l’identifiant de transaction et l’identifiant de commande. Elle ne renvoie pas l’identifiant du type de nœud.

    => SELECT * FROM customers; customer_id | fname | lname -------------+-------+------- (0 rows) => SELECT * FROM rds_aurora.limitless_get_last_trace_id(); transaction_identifier | command_identifier ------------------------+-------------------------------- 10104661421959001813 | 101046614219590018130000000001 (1 row)

    La fonction renvoie une ligne vide pour les requêtes non distribuées, puisqu’aucun ID de suivi ne leur est attribué.

    => SET search_path = public; SET => SELECT * FROM rds_aurora.limitless_get_last_trace_id(); transaction_identifier | command_identifier ------------------------+-------------------- | (1 row)
    Note

    Pour les requêtes VACUUM et ANALYZE, l’instruction de durée n’est pas enregistrée avec l’ID de suivi. Par conséquent, limitless_get_last_trace_id() ne renvoie pas l’ID de suivi. Si une opération VACUUM ou ANALYZE s’exécute pendant une longue durée, vous pouvez utiliser la requête suivante pour obtenir l’ID de suivi correspondant à cette opération :

    SELECT * FROM rds_aurora.limitless_stat_activity WHERE distributed_tracing_id IS NOT NULL;

    Si le serveur s’arrête avant que vous n’ayez récupéré le dernier ID de suivi, vous devrez effectuer une recherche manuelle dans les journaux PostgreSQL afin d’identifier les ID de suivi figurant dans les entrées précédant la panne.

  5. Recherchez l’ID de suivi dans les journaux du cluster de bases de données à l’aide de CloudWatch.

    Utilisez CloudWatch Insights pour interroger le groupe de journaux du cluster de bases de données, comme illustré dans les exemples suivants.

    • Requête permettant d’afficher un identifiant de transaction spécifique ainsi que toutes les commandes exécutées à l’intérieur de celle-ci :

      fields @timestamp, @message | filter @message like /10104661421959001813/ | sort @timestamp desc
    • Requête permettant d’afficher un identifiant de commande spécifique :

      fields @timestamp, @message | filter @message like /101046614219590018130000000001/ | sort @timestamp desc
  6. Examinez tous les journaux du cluster de bases de données produits par la requête distribuée.

Exemples de journaux

Les exemples suivants illustrent l’utilisation du suivi des requêtes.

Corrélation des journaux pour les requêtes sujettes aux erreurs

Dans cet exemple, la commande TRUNCATE est exécutée sur la table customers, alors que cette table n’existe pas.

Sans suivi des requêtes

Fichier journal PostgreSQL sur le routeur coordinateur :

2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:ERROR: failed to execute remote query 2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:DETAIL: relation "public.customers" does not exist 2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:CONTEXT: remote SQL command: truncate public.customers; 2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:STATEMENT: truncate customers;

Fichier journal PostgreSQL sur une partition participante :

2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[ 27503]:ERROR: failed to execute remote query 2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[ 27503]:STATEMENT: truncate customers;

Il s’agit de journaux types. Ils ne disposent pas des identifiants précis nécessaires pour corréler facilement les requêtes au sein du cluster de bases de données.

Avec suivi des requêtes

Fichier journal PostgreSQL sur le routeur coordinateur :

2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:ERROR: failed to execute remote query 2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:DETAIL: relation "public.customers" does not exist 2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:CONTEXT: remote SQL command: truncate public.customers; 2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:STATEMENT: /* tid = 1126253375719408502700000000011 */ truncate customers;

Fichier journal PostgreSQL sur une partition participante :

2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:ERROR: failed to execute remote query 2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:STATEMENT: /* tid = 1126253375719408502700000000010 */ truncate customers;

En présence d’un suivi des requêtes, chaque ligne de journal est associée à un identifiant unique composé de 31 chiffres. Ici, 1126253375719408502700000000011 et 1126253375719408502700000000010 représentent les ID de suivi pour les nœuds coordinateur et participant, respectivement.

  • Identifiant de transaction : 11262533757194085027

  • Identifiant de commande : 112625337571940850270000000001

  • Identifiant du type de nœud : le dernier chiffre 1 ou 0, indique respectivement un routeur coordinateur et un nœud participant.

Corrélation des journaux pour déterminer la durée d’exécution de la requête sur différents nœuds

Dans cet exemple, le paramètre log_min_duration_statement a été défini sur 0 pour afficher la durée de toutes les requêtes.

Sans suivi des requêtes
2024-01-15 07:28:46 UTC:[local]:postgres@postgres_limitless:[178322]:LOG: duration: 12.779 ms statement: select * from customers;
Avec suivi des requêtes

Fichier journal PostgreSQL sur le routeur coordinateur :

2024-01-15 07:32:08 UTC:[local]:postgres@postgres_limitless:[183877]:LOG: duration: 12.618 ms statement: /* tid = 0457669566240497088400000000011 */ select * from customers;

Fichier journal PostgreSQL sur une partition participante :

2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.279 ms statement: /* tid = 0457669566240497088400000000010 */ START TRANSACTION ISOLATION LEVEL READ COMMITTED 2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.249 ms parse <unnamed>: SELECT customer_id, fname, lname FROM public.customers 2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.398 ms bind <unnamed>/c1: SELECT customer_id, fname, lname FROM public.customers 2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.019 ms execute <unnamed>/c1: SELECT customer_id, fname, lname FROM public.customers 2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.073 ms statement: /* tid = 0457669566240497088400000000010 */ COMMIT TRANSACTION