=?UTF-8?Q?Mart=c3=adn_Marqu=c3=a9s?= <martin@2ndquadrant.com> writes:
> [ log_line_prefix %x frequently reports zero ]
> <2016-02-10 17:41:19 EST [5729]: [1] xid=0
> db=data,user=postgres,app=psql,client=[local]>LOG: duration: 17.242 ms
> statement: create table test_xid (id int);
> <2016-02-10 17:41:21 EST [5729]: [2] xid=0
> db=data,user=postgres,app=psql,client=[local]>LOG: duration: 0.055 ms
> statement: begin;
> <2016-02-10 17:41:32 EST [5729]: [3] xid=31063
> db=data,user=postgres,app=psql,client=[local]>LOG: duration: 6.858 ms
> statement: drop table test_xid;
> <2016-02-10 17:41:34 EST [5729]: [4] xid=0
> db=data,user=postgres,app=psql,client=[local]>LOG: duration: 2.540 ms
> statement: end;
> It's clear that if the command isn't executed in an explicit
> transaction, you don't get the xid in the logs. Very annoying!
Think you're outta luck on that. If we logged the duration before
commit, it would be entirely misleading for short commands, because
the time needed to commit wouldn't be included. So we log it after,
when there's no longer any active transaction.
We could maybe fix this by redefining %x as "the current or most recent
xid", so that it'd still be valid for messages issued post-commit.
But I'm afraid that would add about as many bad behaviors as it would
remove. In your example above, that would result in a pretty misleading
xid attached to the "begin" statement, since at that point we have
started a new transaction but not assigned it any xid.
regards, tom lane