Aurora PostgreSQL 無限資料庫中 PostgreSQL 日誌中的分散式查詢追蹤 - Amazon Aurora
追蹤 ID使用查詢追蹤日誌範例

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

Aurora PostgreSQL 無限資料庫中 PostgreSQL 日誌中的分散式查詢追蹤

分散式查詢追蹤是跨 Aurora PostgreSQL 無限資料庫追蹤和關聯 PostgreSQL 日誌中查詢的工具。在 Aurora Postgre 中SQL，您可以使用交易 ID 來識別交易。但在 Aurora PostgreSQL 無限資料庫，交易 ID 可以在各種路由器之間重複。因此，我們建議您在無限資料庫中使用追蹤 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 日誌中的資料庫叢集日誌群組中搜尋此執行時間，以協助判斷瓶頸節點和規劃器最佳化工作。

    無論 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可以變更為查詢列印日誌行的最短查詢執行時間，其中包含執行持續時間，以及IDs跨資料庫叢集的追蹤。此參數-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 日誌，才能在失敗前從日誌IDs中找到追蹤。

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

    使用 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代表協調器和參與者節點IDs的追蹤。

  • 交易識別符 – 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