如何在 PostgreSQL 中记录“准备”语句？答案

【问题标题】：How can I log `PREPARE` statements in PostgreSQL?如何在 PostgreSQL 中记录“准备”语句？
【发布时间】：2016-12-08 14:29:23
【问题描述】：

我正在使用一个数据库工具（Elixir's Ecto），它使用prepared statements 进行大多数 PostgreSQL 查询。我想看看它是如何以及何时这样做的。

我通过在psql 中运行SHOW config_file; 找到了正确的Postgres 配置文件postgresql.conf。我对其进行了编辑以包含

log_statement = 'all'

正如 Dogbert 建议的 here。

根据the PostgreSQL 9.6 docs，此设置应导致PREPARE 语句被记录。

重启 PostgreSQL 后，我可以 tail -f 其日志文件（运行 postgres 可执行文件时由 -r 标志指定的文件），我确实看到了这样的条目：

LOG:  execute ecto_728: SELECT i0."id", i0."store_id", i0."title", i0."description"
  FROM "items" AS i0 WHERE (i0."description" LIKE $1)
DETAIL:  parameters: $1 = '%foo%'

这对应于一个查询（尽管我认为是通过二进制协议完成的）

EXECUTE ecto_728('%foo%');

但是，我没有看到创建 ecto_728 的原始 PREPARE。

我尝试删除并重新创建数据库。之后，同样的查询被执行为ecto_578，所以看起来原来的prepared statement与数据库一起被删除并创建了一个新的。

但是当我在 PostgreSQL 日志中搜索 ecto_578 时，我只看到它正在执行，而不是创建。

如何在 PostgreSQL 日志中查看 PREPARE 语句？

【问题讨论】：

为什么，出于兴趣？无论如何，您在执行时都会看到查询文本。
@CraigRinger 没有实际原因。 :) 我只是想了解我正在使用的工具。例如，我很好奇 Ecto 是否在编译我的代码或启动应用程序时执行 PREPARE。我想我可以在 PostgreSQL 未运行时尝试编译，看看会发生什么。
原来它在给定会话中第一次执行查询之前执行PREPARE，因为"a named prepared-statement object lasts till the end of the current session"所以真的没有其他方法可以做到这一点。

标签： postgresql

【解决方案1】：

正如您所提到的，您的查询是通过扩展查询协议准备的，这与 PREPARE 语句不同。根据log_statement 的文档：

对于使用扩展查询协议的客户端，日志记录发生在收到执行消息

（也就是说，当接收到 Parse 或 Bind 消息时，记录不会发生。）

但是，如果你设置log_min_duration_statement = 0，那么：

对于使用扩展查询协议的客户端，解析的持续时间，独立记录绑定和执行步骤

同时启用这两个设置将在每次执行时为您提供两个日志条目（收到消息时来自log_statement，在执行完成后另一个来自log_min_duration_statement）。

【讨论】：

不错！如果您好奇，请参阅我的答案以了解我的发现。干杯！

【解决方案2】：

Nick's answer 是正确的；我只是在回答添加我通过尝试学到的知识。

首先，我能够在日志中看到三个单独的操作：parse 创建准备好的语句，bind 为其提供参数，execute 让数据库实际携带它出并返回结果。这被描述为in the PostgreSQL docs for the "extended query protocol"。

LOG:  duration: 0.170 ms  parse ecto_918: SELECT i0."id", i0."store_id",
   i0."title", i0."description"
  FROM "items" AS i0 WHERE (i0."description" LIKE $1)
LOG:  duration: 0.094 ms  bind ecto_918: SELECT i0."id", i0."store_id",
  i0."title", i0."description"
  FROM "items" AS i0 WHERE (i0."description" LIKE $1)
DETAIL:  parameters: $1 = '%priceless%'
LOG:  execute ecto_918: SELECT i0."id", i0."store_id", 
  i0."title", i0."description"
  FROM "items" AS i0 WHERE (i0."description" LIKE $1)
DETAIL:  parameters: $1 = '%priceless%'

此输出是在运行一些自动化测试期间生成的。在随后的运行中，我看到相同的查询具有不同的名称 - 例如，ecto_1573。这没有删除数据库，甚至没有重新启动 PostgreSQL 进程。 The docs 这么说

如果成功创建，一个命名的prepared-statement对象将持续到当前会话的结束，除非明确销毁。

所以这些语句必须在每个会话中重新创建，并且我的测试套件可能在每次运行时都有一个新会话。

【讨论】：