How can I log `PREPARE` statements in PostgreSQL?

Question

I'm using a database tool (Elixir's Ecto) which uses prepared statements for most PostgreSQL queries. I want to see exactly how and when it does that.

I found the correct Postgres config file, postgresql.conf, by running SHOW config_file; in psql. I edited it to include

log_statement = 'all'

as Dogbert suggested here.

According to the PostgreSQL 9.6 docs, this setting should cause PREPARE statements to be logged.

After restarting PostgreSQL, I can tail -f its log file (the one specified by the -r flag when running the postgres executable) and I do see entries like this:

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

This corresponds to a query (albeit done over binary protocol, I think) like

EXECUTE ecto_728('%foo%');

However, I don't see the original PREPARE that created ecto_728.

I tried dropping and recreating the database. Afterwards, the same query is executed as ecto_578, so it seems that the original prepared statement was dropped with the database and a new one was created.

But when I search the PostgreSQL log for ecto_578, I only see it being executed, not created.

How can I see PREPARE statements in the PostgreSQL log?

Answer 1

As you mentioned, your queries are being prepared via the extended query protocol, which is distinct from a PREPARE statement. And according to the docs for log_statement:

For clients using extended query protocol, logging occurs when an Execute message is received

(Which is to say that logging does not occur when a Parse or Bind message is received.)

However, if you set log_min_duration_statement = 0, then:

For clients using extended query protocol, durations of the Parse, Bind, and Execute steps are logged independently

Enabling both of these settings together will give you two log entries per Execute (one from log_statement when the message is received, and another from log_min_duration_statement once execution is complete).