Aurora PostgreSQL Limitless Database 中 PostgreSQL 日誌中的分散式查詢追蹤 - Amazon Aurora
追蹤 ID使用查詢追蹤日誌範例

本文為英文版的機器翻譯版本，如內容有任何歧義或不一致之處，概以英文版為準。

Aurora PostgreSQL Limitless Database 中 PostgreSQL 日誌中的分散式查詢追蹤

分散式查詢追蹤是跨 Aurora PostgreSQL Limitless Database 追蹤和關聯 PostgreSQL 日誌中查詢的工具。在 Aurora PostgreSQL 中，您可以使用交易 ID 來識別交易。但在 Aurora PostgreSQL Limitless Database 中，交易 ID 可以在各種路由器之間重複。因此，我們建議您在 Limitless Database 中使用追蹤 ID。

下列為若干關鍵使用案例：

  • 使用 rds_aurora.limitless_get_last_trace_id() 函數尋找在目前工作階段中上次查詢執行的唯一追蹤 ID。然後使用該追蹤 ID，在 Amazon CloudWatch Logs 中搜尋資料庫叢集日誌群組，以尋找所有相關日誌。

    您可以同時使用 log_min_messages 和 log_min_error_statement 參數來控制列印的日誌量，以及列印包含追蹤 ID 的陳述式。

  • 使用 log_min_duration_statement 參數，來判斷所有查詢列印其執行持續時間和追蹤 ID 的執行時間。然後，您可以在 CloudWatch Logs 中的資料庫叢集日誌群組中搜尋此執行時間，以協助判斷瓶頸節點和規劃器最佳化工作。

    無論 log_min_messages 和 log_min_error_statement 參數的值為何，log_min_duration_statement 參數都會啟用所有節點的追蹤 ID。

追蹤 ID

此功能的核心是稱為追蹤 ID 的唯一識別符。追蹤 ID 是附加至 PostgreSQL 日誌 STATEMENT 日誌行的 31 位數字串，可作為與特定查詢執行相關日誌的精確識別符。範例包括 1126253375719408504000000000011 和 1126253375719408495000000000090。

追蹤 ID 由下列項目組成：

  • 交易識別符：前 20 位數，用來唯一識別交易。

  • 命令識別符：前 30 位數，表示交易中的個別查詢。

    如果在明確的交易區塊內執行超過 4,294,967,294 個查詢，則命令識別符會繞回至 1。發生這種情況時，您會在 PostgreSQL 日誌中收到下列 LOG 訊息的通知：

    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

  • 節點類型識別符：最後一個數字，指出節點是作為協調器路由器 (1) 還是參與者節點 (0)。

下列範例說明追蹤 ID 的元件：

  • 1126253375719408504000000000011:

    • 交易識別符：1126253375719408504

    • 命令識別符：112625337571940850400000000001 指出交易區塊中的第一個命令

    • 節點類型識別符：1 表示協調器路由器

  • 1126253375719408495000000000090:

    • 交易識別符：1126253375719408495

    • 命令識別符：112625337571940849500000000009 指出交易區塊中的第九個命令

    • 節點類型識別符：0 表示參與者節點

使用查詢追蹤

執行下列任務以使用查詢追蹤：

  1. 確定已啟用追蹤。

    您可以使用下列命令來檢查：

    SHOW rds_aurora.limitless_log_distributed_trace_id;

    依預設會啟用此功能 (on)。如果未啟用，請使用下列命令進行設定：

    SET rds_aurora.limitless_log_distributed_trace_id = on;

  2. 透過設定日誌嚴重性層級，來控制列印的日誌數量。

    日誌數量由 log_min_messages 參數控制。log_min_error_statement 參數用於列印具有追蹤 ID 的 STATEMENT 行。預設會將兩者設為 ERROR。您可以使用下列命令來檢查：

    SHOW log_min_messages;
SHOW log_min_error_statement;

    若要更新嚴重性層級並列印目前工作階段的 STATEMENT 行，請使用下列命令搭配其中一個嚴重性層級：

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

    例如：

    SET log_min_messages = 'WARNING';
SET log_min_error_statement = 'WARNING';

  3. 啟用在超過特定執行時間後，在日誌中列印追蹤 ID 的功能。

    log_min_duration_statement 參數可變更為查詢的最短執行時間，當查詢執行時間超過此值時，系統將列印日誌行 (內含執行持續時間與資料庫叢集中的追蹤 ID)。此參數預設為 -1，這表示其已停用。您可以使用下列命令來檢查：

    SHOW log_min_duration_statement;

    將其變更為 0 會列印資料庫叢集中每個查詢日誌中的持續時間和追蹤 ID。您可以使用下列命令，將目前工作階段的此項目設為 0：

    SET log_min_duration_statement = 0;

  4. 取得追蹤 ID。

    執行查詢後 (即使在明確交易區塊內)，請呼叫 rds_aurora.limitless_get_last_trace_id 函數以取得上次查詢執行的追蹤 ID：

    SELECT * FROM rds_aurora.limitless_get_last_trace_id();

    此函數會傳回交易識別符和命令識別符。其不會傳回節點類型識別符。

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

    函數會傳回非分散式查詢的空白行，因為其沒有追蹤 ID。

    => SET search_path = public;
SET

=> SELECT * FROM rds_aurora.limitless_get_last_trace_id();
 transaction_identifier | command_identifier 
------------------------+--------------------
                        | 
(1 row)
    注意

    對於 VACUUM 和 ANALYZE 查詢，不會使用追蹤 ID 記錄持續時間陳述式。因此，limitless_get_last_trace_id() 不會傳回追蹤 ID。如果 VACUUM 或 ANALYZE 是長時間執行的操作，您可以使用下列查詢來取得該操作的追蹤 ID：

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

    如果伺服器在您可以找到最後一個追蹤 ID 前停止，您必須手動搜尋 PostgreSQL 日誌，以便在失敗之前從日誌中找到追蹤 ID。

  5. 使用 CloudWatch 在資料庫叢集日誌中搜尋追蹤 ID。

    如下列範例所示，使用 CloudWatch Insights 查詢資料庫叢集的日誌群組。

    • 查詢特定交易識別符，以及其中執行的所有命令：

      fields @timestamp, @message
| filter @message like /10104661421959001813/
| sort @timestamp desc

    • 查詢特定命令識別符：

      fields @timestamp, @message
| filter @message like /101046614219590018130000000001/
| sort @timestamp desc

  6. 檢查分散式查詢所產生之資料庫叢集中的所有日誌。

日誌範例

下列範例示範查詢追蹤的使用。

將容易出錯的查詢日誌進行關聯

在此範例中，當 customers 資料表不存在時，TRUNCATE 命令會在該資料表上執行。

沒有查詢追蹤

協調器路由器上的 PostgreSQL 日誌檔案：

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 日誌檔案：

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;

這些是典型的日誌。其缺少在資料庫叢集之間輕鬆關聯查詢所需的精確識別符。

使用查詢追蹤

協調器路由器上的 PostgreSQL 日誌檔案：

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 日誌檔案：

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;

在查詢追蹤的情況，每個日誌行都會附加 31 位數的唯一識別符。在這裡，1126253375719408502700000000011 和 1126253375719408502700000000010 分別代表協調器和參與者節點的追蹤 ID。

  • 交易識別符：11262533757194085027

  • 命令識別符：112625337571940850270000000001

  • 節點類型識別符：最後一個位數 (1 或 0) 分別表示協調器路由器和參與者節點。

關聯日誌以尋找各種節點上的查詢執行時間

在此範例中，log_min_duration_statement 參數已更新為 0，以列印所有查詢的持續時間。

沒有查詢追蹤
2024-01-15 07:28:46 UTC:[local]:postgres@postgres_limitless:[178322]:LOG: duration: 12.779 ms statement: select * from customers;
使用查詢追蹤

協調器路由器上的 PostgreSQL 日誌檔案：

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

參與者碎片上的 PostgreSQL 日誌檔案：

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