# 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。 **Topics** + [跟踪 ID](#limitless-query.tracing.ID) + [使用查询跟踪](#limitless-query.tracing.using) + [日志示例](#limitless-query.tracing.examples) ## 跟踪 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; ``` 1. 通过配置日志严重性级别来控制打印的日志量。 日志量由 `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'; ``` 1. 允许在特定运行时间以上的日志中打印跟踪 ID。 可以将 `log_min_duration_statement` 参数更改为查询运行时间的最小值，超过该值时，查询将打印一条包含运行持续时间的日志行以及数据库集群中的跟踪 ID。默认情况下，此参数设置为 `-1`，这意味着它已被禁用。您可以使用以下命令进行检查： ``` SHOW log_min_duration_statement; ``` 将其更改为 `0`，在日志中打印数据库集群中每次查询的持续时间和跟踪 ID。您可以使用以下命令在当前会话中将其设置为 `0`： ``` SET log_min_duration_statement = 0; ``` 1. 获取跟踪 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。 1. 使用 CloudWatch 在数据库集群日志中搜索跟踪 ID。 使用 [CloudWatch Insights](https://docs.amazonaws.cn/AmazonCloudWatch/latest/logs/AnalyzingLogData.html) 查询数据库集群的日志组，如以下示例所示。 + 查询特定的事务标识符及其内部运行的所有命令： ``` fields @timestamp, @message | filter @message like /10104661421959001813/ | sort @timestamp desc ``` + 查询特定的命令标识符： ``` fields @timestamp, @message | filter @message like /101046614219590018130000000001/ | sort @timestamp desc ``` 1. 检查分布式查询在数据库集群中生成的所有日志。 ## 日志示例 以下示例演示了如何使用查询跟踪。 ### 关联日志，查找容易出错的查询 在此示例中，当 `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 : 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 /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 /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 ```