"idle in transaction" entry in pg_logs

From: Raghavendra <raghavendra(dot)rao(at)enterprisedb(dot)com>
To: pgsql-general(at)postgresql(dot)org
Subject: "idle in transaction" entry in pg_logs
Date: 2011-11-10 22:48:23
Message-ID: CA+h6AhjMwjcbj0i=94GUJC1Q+yKP3_5=4JymM1NL1Mha_NMk2w@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

Respected,

All the time we see 'idle in transaction' in pg_stat_activity and dig
details with process pid from pg_logs for the query,query execution time
etc..
Instead of searching with process pid, am trying to pull the information
with shell scripting for lines prefixed with 'idle in transaction' in
pg_logs line.
With log_line_prefix %i option I can see logs are prefixing 'idle in
transaction'.

log_line_prefix = '%m-%u(at)%d-[%x]-%p-%i'

Case 1: [ log_min_duration_statement = 0, log_statement='all',
log_duration=off or log_duration=on ]
In logs:

2011-10-05 18:28:22.028 IST-postgres(at)postgres-[0]-22398-idle LOG:
statement: begin;
2011-10-05 18:28:22.029 IST-postgres(at)postgres-[0]-22398-BEGIN LOG:
duration: 0.703 ms
2011-10-05 18:28:39.847 IST-postgres(at)postgres-*[0]*-22398-idle in
transaction LOG: statement: insert into abc VALUES (11);
2011-10-05 18:28:39.848 IST-postgres(at)postgres-[682]-22398-INSERT LOG:
duration: 0.474 ms
2011-10-05 18:29:00.591 IST-postgres(at)postgres-[682]-22398-idle in
transaction LOG: statement: end;
2011-10-05 18:29:00.595 IST-postgres(at)postgres-[0]-22398-COMMIT LOG:
duration: 3.216 ms

Case 2: [ log_min_duration_statement = -1, log_statement='all',
log_duration=off ]
In logs:

2011-10-05 18:20:04.612 IST-postgres(at)postgres-[0]-22398-idle LOG:
statement: begin;
2011-10-05 18:20:15.922 IST-postgres(at)postgres-[0]-22398-idle in transaction
LOG: statement: insert into abc VALUES (10);
2011-10-05 18:20:27.633 IST-postgres(at)postgres-[681]-22398-idle in
transaction LOG: statement: end;

Sample transaction did twice with above changes to log parameters:
postgres=# begin;
BEGIN
postgres=# insert into abc VALUES (11);
INSERT 0 1
postgres=# end;
COMMIT

Question:

1. Is it a standard behavior in Case 1, that every transaction will write
two lines in logs ? (i.e., if log_statement='all' and log_duration=on and
log_min_duration=0 and log_statement='all')

2. I used %x in log_line_prefix to get transaction id, but I see
transaction-id written in logs only when its committed. You can see in both
the cases. Why its not written at first occurrence ?

Thanks in Advance.

---
Regards,
Raghavendra
EnterpriseDB Corporation
Blog: http://raghavt.blogspot.com/

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Bborie Park 2011-11-10 22:59:28 Passing NULL to a function called with OidFunctionCall3
Previous Message John R Pierce 2011-11-10 22:41:46 Re: PostgreSQL uninstall fails