Tracciamento delle query distribuito nei log di Postgre nel database Aurora SQL Postgre Limitless SQL - Amazon Aurora

Le traduzioni sono generate tramite traduzione automatica. In caso di conflitto tra il contenuto di una traduzione e la versione originale in Inglese, quest'ultima prevarrà.

Tracciamento delle query distribuito nei log di Postgre nel database Aurora SQL Postgre Limitless SQL

Il tracciamento distribuito delle query è uno strumento per tracciare e correlare le query nei log di Postgre SQL su Aurora Postgre Limitless Database. SQL In Aurora PostgreSQL, si utilizza l'ID della transazione per identificare una transazione. Ma in Aurora Postgre SQL Limitless Database, l'ID della transazione può essere ripetuto su vari router. Pertanto, ti consigliamo di utilizzare l'ID di tracciamento invece in Limitless Database.

I casi d'uso principali sono i seguenti:

  • Utilizzate la rds_aurora.limitless_get_last_trace_id() funzione per trovare l'ID di tracciamento univoco dell'ultima query eseguita nella sessione corrente. Quindi cerca nel gruppo di log del cluster DB in Amazon CloudWatch Logs utilizzando quell'ID di tracciamento per trovare tutti i log correlati.

    Puoi utilizzare i log_min_error_statement parametri log_min_messages e insieme per controllare il volume dei log stampati e stampare una dichiarazione che contenga l'ID di tracciamento.

  • Utilizzate il log_min_duration_statement parametro per determinare il tempo di esecuzione oltre il quale tutte le query stampano la durata di esecuzione e l'ID di tracciamento. Questa fase di esecuzione può quindi essere ricercata nel gruppo di log del cluster DB in CloudWatch Logs per determinare i nodi critici e le attività di ottimizzazione del pianificatore.

    Il log_min_duration_statement parametro abilita l'ID di tracciamento per tutti i nodi indipendentemente dai valori e dai parametri. log_min_messages log_min_error_statement

ID di tracciamento

Al centro di questa funzionalità c'è un identificatore univoco noto come ID di tracciamento. L'ID di tracciamento è una stringa di 31 cifre aggiunta alle righe di registro dei STATEMENT log di Postgre, che funge da identificatore preciso per correlare SQL i log relativi all'esecuzione di una specifica query. Alcuni esempi sono 1126253375719408504000000000011 e 1126253375719408495000000000090.

L'ID di tracciamento è composto da quanto segue:

  • Identificatore della transazione: le prime 20 cifre, che identificano in modo univoco la transazione.

  • Identificatore di comando: le prime 30 cifre, che indicano una singola query all'interno di una transazione.

    Se vengono eseguite più di 4.294.967.294 query all'interno di un blocco di transazione esplicito, il comando Identifier si riferisce a. 1 Quando ciò accade, vieni avvisato dal seguente messaggio nel registro di Postgre: LOG SQL

    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
  • Identificatore del tipo di nodo: l'ultima cifra, che indica se il nodo funziona come router coordinatore (1) o nodo partecipante (). 0

I seguenti esempi illustrano i componenti dell'ID di tracciamento:

  • 1126253375719408504000000000011:

    • Identificatore della transazione: 1126253375719408504

    • Identificatore di comando: 112625337571940850400000000001 indica il primo comando nel blocco di transazione

    • Identificatore del tipo di nodo: 1 indica un router coordinatore

  • 1126253375719408495000000000090:

    • Identificatore della transazione — 1126253375719408495

    • Identificatore di comando: 112625337571940849500000000009 indica il nono comando nel blocco di transazione

    • Identificatore del tipo di nodo: 0 indica un nodo partecipante

Utilizzo del tracciamento delle query

Eseguite le seguenti attività per utilizzare il tracciamento delle query:

  1. Assicurati che il tracciamento sia abilitato.

    Puoi controllare usando il seguente comando:

    SHOW rds_aurora.limitless_log_distributed_trace_id;

    È abilitato di default (on). Se non è abilitato, impostalo usando il seguente comando:

    SET rds_aurora.limitless_log_distributed_trace_id = on;
  2. Controlla il volume dei log stampati configurando il livello di gravità del registro.

    Il volume del registro è controllato dal log_min_messages parametro. Il log_min_error_statement parametro viene utilizzato per stampare la STATEMENT riga con l'ID di tracciamento. Entrambi sono impostati come impostazione ERROR predefinita. È possibile effettuare il controllo utilizzando i seguenti comandi:

    SHOW log_min_messages; SHOW log_min_error_statement;

    Per aggiornare il livello di gravità e stampare la STATEMENT riga per la sessione corrente, utilizzate i seguenti comandi con uno di questi livelli di 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';

    Per esempio:

    SET log_min_messages = 'WARNING'; SET log_min_error_statement = 'WARNING';
  3. Abilita la stampa dell'ID di tracciamento nei registri al di sopra di un periodo di esecuzione specifico.

    Il log_min_duration_statement parametro può essere modificato impostando il tempo minimo di esecuzione della query al di sopra del quale la query stampa una riga di registro con la durata dell'esecuzione, insieme alla traccia nel cluster IDs DB. Questo parametro è impostato come impostazione -1 predefinita, il che significa che è disabilitato. È possibile verificare utilizzando il seguente comando:

    SHOW log_min_duration_statement;

    Se lo si modifica, vengono 0 stampati la durata e l'ID di tracciamento nei log per ogni query nel cluster DB. È possibile impostarlo 0 per la sessione corrente utilizzando il seguente comando:

    SET log_min_duration_statement = 0;
  4. Ottieni l'ID di tracciamento.

    Dopo aver eseguito una query (anche all'interno di un blocco di transazione esplicito), chiama la rds_aurora.limitless_get_last_trace_id funzione per ottenere l'ID di tracciamento dell'ultima esecuzione della query:

    SELECT * FROM rds_aurora.limitless_get_last_trace_id();

    Questa funzione restituisce l'identificatore della transazione e l'identificatore del comando. Non restituisce l'identificatore del tipo di nodo.

    => 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 funzione restituisce una riga vuota per le query non distribuite, in quanto non dispongono di un ID di tracciamento.

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

    Per le ANALYZE query VACUUM e, l'istruzione di durata non viene registrata con l'ID di tracciamento. Pertanto, limitless_get_last_trace_id() non restituisce l'ID di tracciamento. Se VACUUM o ANALYZE è un'operazione di lunga durata, è possibile utilizzare la seguente query per ottenere l'ID di traccia per tale operazione:

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

    Se il server si arresta prima che tu riesca a trovare l'ultimo ID di tracciamento, dovrai cercare manualmente nei SQL log di Postgre per trovare la traccia contenuta IDs nei log immediatamente prima dell'errore.

  5. Cerca l'ID di tracciamento nei log del cluster DB utilizzando. CloudWatch

    Utilizza CloudWatch Insights per interrogare il gruppo di log del cluster DB, come illustrato negli esempi seguenti.

    • Esegui una query per un particolare identificatore di transazione e tutti i comandi vengono eseguiti al suo interno:

      fields @timestamp, @message | filter @message like /10104661421959001813/ | sort @timestamp desc
    • Interrogazione per un particolare identificatore di comando:

      fields @timestamp, @message | filter @message like /101046614219590018130000000001/ | sort @timestamp desc
  6. Esamina tutti i log del cluster DB prodotti dalla query distribuita.

Esempi di log

Gli esempi seguenti mostrano l'uso del tracciamento delle query.

Correlazione dei log per le interrogazioni soggette a errori

In questo esempio il TRUNCATE comando viene eseguito sulla customers tabella quando tale tabella non esiste.

Senza tracciamento delle query

File di SQL registro Postgre sul router del coordinatore:

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;

File di SQL registro Postgre su un partecipante condiviso:

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;

Questi log sono tipici. Mancano degli identificatori precisi necessari per correlare facilmente le query all'interno del cluster DB.

Con tracciamento delle query

File di SQL registro Postgre sul router del coordinatore:

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;

File di SQL registro Postgre su un partecipante condiviso:

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;

In presenza del tracciamento delle interrogazioni, a ogni riga di registro viene aggiunto un identificatore univoco di 31 cifre. Qui, 1126253375719408502700000000011 e 1126253375719408502700000000010 rappresentano la traccia IDs per i nodi coordinatore e partecipante, rispettivamente.

  • Identificatore della transazione: 11262533757194085027

  • Identificatore del comando: — 112625337571940850270000000001

  • Identificatore del tipo di nodo: l'ultima cifra, 1 o0, indica rispettivamente un router coordinatore e un nodo partecipante.

Registri correlati per trovare il tempo di esecuzione della query su vari nodi

In questo esempio, il log_min_duration_statement parametro è stato aggiornato 0 per stampare la durata di tutte le query.

Senza tracciamento delle query
2024-01-15 07:28:46 UTC:[local]:postgres@postgres_limitless:[178322]:LOG: duration: 12.779 ms statement: select * from customers;
Con tracciamento delle interrogazioni

File di SQL registro Postgre sul router del coordinatore:

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

File di SQL registro Postgre su un partecipante condiviso:

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