In a previous post I discussed a way to find out which transaction dropped a table by examining the transaction log, in order to set a restore point to right before the table was dropped.
But what if we have the luxury of planning ahead (right? Well, let's call it the second time it happens?). Shouldn't we be able to log which transaction dropped a table, and use that? Of course we should.
The first thing one tries is then of course something like this in
log_statement='ddl' log_line_prefix = '%t [%u@%d] <%x> '
to include the transaction id of the table. Unfortunately:
2017-02-12 12:16:39 CET [mha@postgres] <0> LOG: statement: drop table testtable;
0 as a transaction id indicates that this command was run in a virtual transaction, and did not have a real transaction id. The reason for this is that the statement logging happens before the statement has actually acquired a transaction. For example, if I instead drop two tables, and do so in a transaction:
postgres=# BEGIN; BEGIN postgres=# DROP TABLE test1; DROP TABLE postgres=# DROP TABLE test2; DROP TABLE postgres=# COMMIT; COMMIT
I get this interesting output:
2017-02-12 12:17:43 CET [mha@postgres] <0> LOG: statement: DROP TABLE test1; 2017-02-12 12:17:45 CET [mha@postgres] <156960> LOG: statement: DROP TABLE test2;
Which shows two different transaction ids (one real and one not) for statements in the same transaction. That's obviously not true - they were both dropped by transaction
156960. The transaction id just wasn't available at the time of logging.
So what can we do about that? Event triggers to the rescue!