PostgreSQL: Finding last executed statement from an "idle in transaction timeout"

Question

Is there any way to log or find last executed statement from a session that terminated because of idle in transaction timeout? We only have slow statement logging and that did not capture it and we don't want to enable all statement logging as well as this will have bad impact on performance.

• Frank Heikens: Idle in transition means that the connection is waiting for the next statement. It has not been terminated. It’s a state that happens in every transaction that contains multiple statements, nothing special
• goodfella: @FrankHeikens The session is terminated once the session idle time exceeds idle_in_transaction_session_timeout. I want to find what statement is executed before it got terminated
• Frank Heikens: Why? It’s an application problem, the application doesn’t send a next statement.
• goodfella: @FrankHeikens indeed it's an app problem, but I am trying to find the last executed query so that the app team can fix it.

Answer 1

You get the last executed query for live transactions from pg_stat_activity (incl. transactions that sit idle in transaction):

SELECT backend_xid, backend_start, xact_start, query_start, query -- more?
FROM pg_catalog.pg_stat_activity
WHERE state = 'idle in transaction'
AND xact_start < now() - interval '3 sec' -- 1
ORDER BY xact_start;

1 Some interval much shorter than your timeout, but long enough to filter the bulk of shorter transactions. In chose 3 sec for your case with short transactions and a sharp idle_in_transaction_session_timeout of only 10 sec. Each can be Can be substantially longer in other setups.

Run a cron job polling the above query into a log table in intervals slightly below that setting minus 1. The latest entry for your backend_xid will show the query you are looking for.

Since you are running this in relatively high frequency, and you don't need some columns the view joins in, you might squeeze out some fractions of a ms by calling the underlying function pg_stat_get_activity() directly. ORDER BY seems expendable, too:

SELECT backend_xid, backend_start, xact_start, query_start, query
FROM pg_catalog.pg_stat_get_activity(null)
WHERE state = 'idle in transaction'
AND xact_start < now() - interval '3 sec';

The calling role needs the necessary privileges to see the query, of course.

• goodfella: We set 10secs for idle in transaction timeout ,and I have such a logging of pg_stat_activity every min but still i couldn't get it so far. I don't want to decrease the interval from 1 min, so I was looking for any alternatives method if exists.
• Erwin Brandstetter: @goodfella If your timeout is at 10 sec, then logging every min won't do, obviously. Try filtering WHERE xact_start < now() - interval '3 sec', and logging every 6 sec. (Or increase that sharp timeout and the rest by a bit.) Also, you might have disclosed that in the question.
• goodfella: Logging pg_stat_activity is the only possible solution here?
• Erwin Brandstetter: @goodfella: That's the solution I can think of.

Answer 2

In PostgreSQL, if a session is terminated due to idle_in_transaction_timeout, and you're not logging all statements, it's tricky to pinpoint the last executed statement from that session, especially if it wasn't slow enough to be caught by log_min_duration_statement.

Enable log_min_duration_statement to a low but non-zero threshold

log_min_duration_statement = 1000 # logs statements that take >= 1 second

• goodfella: Most of our queries executes in less than 100ms probably this one too. Changing statement logging from 1 sec to 100ms will impact performance for days as the timeout incident rarely happens.