Verteiltes Abfrage-Tracing in PostgreSQL-Protokollen in Aurora PostgreSQL Limitless Database - Amazon Aurora

Die vorliegende Übersetzung wurde maschinell erstellt. Im Falle eines Konflikts oder eines Widerspruchs zwischen dieser übersetzten Fassung und der englischen Fassung (einschließlich infolge von Verzögerungen bei der Übersetzung) ist die englische Fassung maßgeblich.

Verteiltes Abfrage-Tracing in PostgreSQL-Protokollen in Aurora PostgreSQL Limitless Database

Verteiltes Abfrage-Tracing ist ein Tool zum Verfolgen und Korrelieren von Abfragen in PostgreSQL-Protokollen in Aurora PostgreSQL Limitless Database. In Aurora PostgreSQL verwenden Sie die Transaktions-ID, um eine Transaktion zu identifizieren. In Aurora PostgreSQL Limitless Database kann sich eine Transaktions-ID jedoch auf verschiedenen Routern wiederholen. Daher empfehlen wir, dass Sie in Limitless Database stattdessen die Tracing-ID verwenden.

Wichtige Anwendungsfälle:

  • Verwenden Sie die Funktion rds_aurora.limitless_get_last_trace_id(), um die eindeutige Tracing-ID der letzten Abfrage in der aktuellen Sitzung zu ermitteln. Durchsuchen Sie dann die DB-Cluster-Protokollgruppe in Amazon CloudWatch Logs mit dieser Tracing-ID, um alle zugehörigen Protokolle zu finden.

    Sie können die Parameter log_min_messages und log_min_error_statement zusammen verwenden, um die Menge der abgedruckten Protokolle zu steuern und eine Anweisung abzudrucken, die die Tracing-ID enthält.

  • Verwenden Sie den Parameter log_min_duration_statement, um die Laufzeit zu bestimmen, bei deren Überschreitung alle Abfragen ihre Ausführungsdauer und die Tracing-ID abdrucken. Diese Laufzeit kann dann in der Protokollgruppe des DB-Clusters in CloudWatch-Protokollen gesucht werden, um Knoten mit Engpässen zu ermitteln und Optimierungsmaßnahmen zu planen.

    Der Parameter log_min_duration_statement aktiviert die Tracing-ID für alle Knoten, unabhängig von den Werten der Parameter log_min_messages und log_min_error_statement.

Tracing-ID

Im Mittelpunkt dieser Funktion steht eine eindeutige Kennung, die sogenannte Tracing-ID. Die Tracing-ID ist eine 31-stellige Zeichenfolge, die an die STATEMENT-Protokollzeilen von PostgreSQL-Protokollen angehängt wird und als genaue Kennung für korrelierende Protokolle dient, die sich auf eine bestimmte Abfrage beziehen. Beispiele sind 1126253375719408504000000000011 und 1126253375719408495000000000090.

Die Tracing-ID besteht aus den folgenden Elementen:

  • Transaktions-ID: Die ersten 20 Zeichen, die die Transaktion eindeutig identifizieren.

  • Befehls-ID: Die ersten 30 Zeichen, die auf eine einzelne Abfrage innerhalb einer Transaktion hinweisen.

    Wenn innerhalb eines expliziten Transaktionsblocks mehr als 4 294 967 294 Abfragen ausgeführt werden, wird die Befehls-Id zu 1. In diesem Fall werden Sie durch die folgende LOG-Meldung im PostgreSQL-Protokoll benachrichtigt:

    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
  • Knotentyp-ID: Die letzte Ziffer, die angibt, ob der Knoten als Koordinator-Router (1) oder als Teilnehmerknoten (0) fungiert.

Die folgenden Beispiele veranschaulichen die Komponenten der Tracing-ID:

  • 1126253375719408504000000000011:

    • Transaktions-ID: 1126253375719408504

    • Befehls-ID: 112625337571940850400000000001 gibt den ersten Befehl im Transaktionsblock an.

    • Knotentyp-ID: 1 gibt einen Koordinator-Router an.

  • 1126253375719408495000000000090:

    • Transaktions-ID: 1126253375719408495

    • Befehls-ID: 112625337571940849500000000009 gibt den neunten Befehl im Transaktionsblock an.

    • Knotentyp-ID: 0 gibt einen Teilnehmerknoten an.

Verwenden des Abfrage-Tracings

Führen Sie die folgenden Aufgaben aus, um das Abfrage-Tracing zu verwenden:

  1. Stellen Sie sicher, dass Tracing aktiviert ist.

    Sie können zur Überprüfung den folgenden Befehl verwenden:

    SHOW rds_aurora.limitless_log_distributed_trace_id;

    Die Funktion ist standardmäßig aktiviert (on). Wenn sie nicht aktiviert ist, aktivieren Sie sie mit dem folgenden Befehl:

    SET rds_aurora.limitless_log_distributed_trace_id = on;
  2. Steuern Sie die Menge der abgedruckten Protokolle, indem Sie den Schweregrad des Protokolls konfigurieren.

    Die Menge der Protokolle wird durch den Parameter log_min_messages gesteuert. Der Parameter log_min_error_statement wird verwendet, um die STATEMENT-Zeile mit der Tracing-ID abzudrucken. Beide sind standardmäßig auf ERROR eingestellt. Sie können zur Überprüfung folgende Befehle verwenden:

    SHOW log_min_messages; SHOW log_min_error_statement;

    Um den Schweregrad zu aktualisieren und die Zeile STATEMENT für die aktuelle Sitzung abzudrucken, verwenden Sie die folgenden Befehle mit einem dieser Schweregrade:

    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';

    Zum Beispiel:

    SET log_min_messages = 'WARNING'; SET log_min_error_statement = 'WARNING';
  3. Aktivieren Sie das Abdrucken der Tracing-ID in den Protokollen ab einer bestimmten Laufzeit.

    Der Parameter log_min_duration_statement kann in die minimale Abfragelaufzeit geändert werden, bei deren Überschreitung die Abfrage für den gesamten DB-Cluster eine Protokollzeile mit der Ausführungsdauer zusammen mit den Tracing-IDs ausgibt. Dieser Parameter ist standardmäßig auf -1 gesetzt, was bedeutet, dass er deaktiviert ist. Sie können zur Überprüfung den folgenden Befehl verwenden:

    SHOW log_min_duration_statement;

    Wenn Sie ihn in 0 ändern, werden die Dauer und die Tracing-ID in den Protokollen für jede Abfrage im DB-Cluster abgedruckt. Sie können ihn mit dem folgenden Befehl für die aktuelle Sitzung auf 0 festlegen:

    SET log_min_duration_statement = 0;
  4. Rufen Sie die Tracing-ID ab.

    Rufen Sie nach dem Ausführen einer Abfrage (auch innerhalb eines expliziten Transaktionsblocks) die Funktion rds_aurora.limitless_get_last_trace_id auf, um die Tracing-ID des letzten Abfragelaufs abzurufen:

    SELECT * FROM rds_aurora.limitless_get_last_trace_id();

    Diese Funktion gibt die Transaktions-ID und die Befehls-ID zurück. Sie gibt die Knotentyp-ID nicht zurück.

    => 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)

    Die Funktion gibt für nicht verteilte Abfragen eine Leerzeile zurück, da sie über keine Tracing-ID verfügen.

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

    Bei VACUUM- und ANALYZE-Abfragen wird die Anweisung zur Dauer nicht mit der Tracing-ID protokolliert. Daher gibt limitless_get_last_trace_id() die Tracing-ID nicht zurück. Wenn es sich bei VACUUM oder ANALYZE um einen Vorgang mit langer Laufzeit handelt, können Sie die folgende Abfrage verwenden, um die Tracing-ID für diesen Vorgang abzurufen:

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

    Wenn der Server stoppt, bevor Sie die letzte Tracing-ID ausfindig machen können, müssen Sie die PostgreSQL-Protokolle manuell durchsuchen, um die Tracing-IDs in den Protokollen vom Zeitpunkt unmittelbar vor dem Ausfall zu finden.

  5. Suchen Sie mit CloudWatch in den DB-Cluster-Protokollen nach der Tracing-ID.

    Verwenden Sie CloudWatch Insights, um die Protokollgruppe des DB-Clusters abzufragen, wie in den folgenden Beispielen gezeigt.

    • Abfrage nach einer bestimmten Transaktions-ID und alle Befehle werden darin ausgeführt:

      fields @timestamp, @message | filter @message like /10104661421959001813/ | sort @timestamp desc
    • Abfrage nach einer bestimmten Befehls-ID:

      fields @timestamp, @message | filter @message like /101046614219590018130000000001/ | sort @timestamp desc
  6. Untersuchen Sie alle Protokolle im DB-Cluster, die durch die verteilte Abfrage erstellt wurden.

Beispiele für Protokolle

Die folgenden Beispiele zeigen die Verwendung von Abfrage-Tracing.

Korrelierung von Protokollen für fehleranfällige Abfragen

In diesem Beispiel wird der Befehl TRUNCATE an der Tabelle customers ausgeführt, wenn diese Tabelle nicht existiert.

Ohne Abfrage-Tracing

PostgreSQL-Protokolldatei auf dem Koordinator-Router:

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;

PostgreSQL-Protokolldatei auf einem Teilnehmer-Shard:

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;

Diese Protokolle sind typisch. Ihnen fehlen die exakten IDs, die für die einfache Korrelation von Abfragen im gesamten DB-Cluster erforderlich sind.

Mit Abfrage-Tracing

PostgreSQL-Protokolldatei auf dem Koordinator-Router:

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;

PostgreSQL-Protokolldatei auf einem Teilnehmer-Shard:

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;

Beim Abfrage-Tracing wird an jede Protokollzeile eine 31-stellige eindeutige Kennung angehängt. Hier stellen 1126253375719408502700000000011 und 1126253375719408502700000000010 jeweils die Tracing-IDs für den Koordinator- und die Teilnehmerknoten dar.

  • Transaktions-ID: 11262533757194085027

  • Befehls-ID: 112625337571940850270000000001

  • Knotentyp-ID: Die letzte Ziffer, 1 oder 0, steht für einen Koordinator-Router bzw. einen Teilnehmerknoten.

Korrelieren von Protokollen, um die Abfragelaufzeit auf verschiedenen Knoten zu ermitteln

In diesem Beispiel wurde der Parameter log_min_duration_statement in 0 geändert, damit für alle Abfragen die Dauer abgedruckt wird.

Ohne Abfrage-Tracing
2024-01-15 07:28:46 UTC:[local]:postgres@postgres_limitless:[178322]:LOG: duration: 12.779 ms statement: select * from customers;
Mit Abfrage-Tracing

PostgreSQL-Protokolldatei auf dem Koordinator-Router:

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

PostgreSQL-Protokolldatei auf einem Teilnehmer-Shard:

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