Postgres - How to debug/trace 'Idle in transaction' connection

Question

I am using Postgres for one of my applications and sometimes (not very frequently) one of the connection goes into <IDLE> in transaction state and it keeps acquired lock that causes other connections to wait on these locks ultimately causing my application to hang.

Following is the output from pg_stat_activity table for that process:

select * from pg_stat_activity

24081 | db     |     798 |    16384 | db     |                  | 10.112.61.218 |                 |       59034 | 2013-09-12 23:46:05.132267+00 | 2013-09-12 23:47:31.763084+00 | 2013-09-12 23:47:31.763534+00 | f       | <IDLE> in transaction

This indicates that PID=798 is in <IDLE> in transaction state. The client process on web server is found as following using the client_port (59034) from above output.

sudo netstat -apl | grep 59034

tcp        0      0 ip-10-112-61-218.:59034 db-server:postgresql    ESTABLISHED 23843/pgbouncer

I know that something is wrong in my application code (I killed one of the running application cron and it freed the locks) that is causing the connection to hang, but I am not able to trace it.

This is not very frequent and I can't find any definite reproduction steps either as this only occurs on the production server.

I would like to get inputs on how to trace such idle connection, e.g. getting last executed query or some kind of trace-back to identify which part of code is causing this issue.

Answer 1

If you upgrade to 9.2 or higher, the pg_stat_activity view will show you what the most recent query executed was for idle in transaction connections.

select * from pg_stat_activity  \x\g\x

...
waiting          | f
state            | idle in transaction
query            | select count(*) from pg_class ;

You can also (even in 9.1) look in pg_locks to see what locks are being held by the idle in transaction process. If it only has locks on very commonly used objects, this might not narrow things down much, but if it was a peculiar lock that could tell you exactly where in your code to look.

If you are stuck with 9.1, you can perhaps use the debugger to get all but the first 22 characters of the query (the first 22 are overwritten by the <IDLE> in transaction\0 message). For example:

(gdb) printf "%s\n", ((MyBEEntry->st_activity)+22)