Home > Software design >  How to read transaction from PostgreSQL statement log
How to read transaction from PostgreSQL statement log

Time:11-08

I am enabling postgresSQL statement log by SET log_statement = 'all'; and received output like below for an Java application that is using Hibernate. Default log format is used and the Postgres version is 13.1

I can guess the number in square bracket is threadID? I see that there is multiple BEGIN and multiple COMMIT scattered without explicit ID or order

Is there a way I can see the scope of a transaction from this log? (Actual statement and values are removed)

2021-11-08 05:45:52.827 UTC [107] LOG:  execute S_4: BEGIN
2021-11-08 05:45:52.841 UTC [107] LOG:  execute <unnamed>: 
    RETURNING *
2021-11-08 05:45:52.841 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:52.927 UTC [107] LOG:  execute <unnamed>: 
    RETURNING *
2021-11-08 05:45:52.927 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:52.975 UTC [107] LOG:  execute <unnamed>: 
    RETURNING *
2021-11-08 05:45:52.975 UTC [107] DETAIL:  parameters:
2021-11-08 05:45:54.209 UTC [107] LOG:  execute <unnamed>: 
2021-11-08 05:45:54.209 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:54.251 UTC [107] LOG:  execute <unnamed>: 
2021-11-08 05:45:54.251 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:54.297 UTC [107] LOG:  execute <unnamed>:
2021-11-08 05:45:54.297 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:54.565 UTC [107] LOG:  execute <unnamed>: 
2021-11-08 05:45:54.565 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:55.164 UTC [194] LOG:  execute <unnamed>: SET extra_float_digits = 3
2021-11-08 05:45:55.209 UTC [194] LOG:  execute <unnamed>: SET application_name = 'PostgreSQL JDBC Driver'
2021-11-08 05:45:55.253 UTC [194] LOG:  execute <unnamed>: BEGIN
2021-11-08 05:45:55.257 UTC [194] LOG:  execute <unnamed>: 
2021-11-08 05:45:55.257 UTC [194] DETAIL:  
2021-11-08 05:45:55.308 UTC [194] LOG:  execute <unnamed>: 
2021-11-08 05:45:55.308 UTC [194] DETAIL:  parameters: 
2021-11-08 05:45:55.354 UTC [194] LOG:  execute <unnamed>: 
    RETURNING *
2021-11-08 05:45:55.354 UTC [194] DETAIL:  parameters: 
2021-11-08 05:45:55.412 UTC [195] LOG:  execute <unnamed>: SET extra_float_digits = 3
2021-11-08 05:45:55.451 UTC [195] LOG:  execute <unnamed>: SET application_name = 'PostgreSQL JDBC Driver'
2021-11-08 05:45:55.577 UTC [194] LOG:  execute <unnamed>: 
2021-11-08 05:45:55.577 UTC [194] DETAIL:  
2021-11-08 05:45:55.617 UTC [194] LOG:  execute S_1: COMMIT
2021-11-08 05:45:56.393 UTC [196] LOG:  execute <unnamed>: SET extra_float_digits = 3
2021-11-08 05:45:56.435 UTC [196] LOG:  execute <unnamed>: SET application_name = 'PostgreSQL JDBC Driver'
2021-11-08 05:45:56.486 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:56.486 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:56.529 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:56.529 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:56.571 UTC [196] LOG:  execute <unnamed>: BEGIN
2021-11-08 05:45:56.572 UTC [196] LOG:  execute <unnamed>: 
    RETURNING *
2021-11-08 05:45:56.572 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:56.622 UTC [196] LOG:  execute S_1: COMMIT
2021-11-08 05:45:56.650 UTC [197] LOG:  execute <unnamed>: SET extra_float_digits = 3
2021-11-08 05:45:56.677 UTC [107] LOG:  execute <unnamed>: 
2021-11-08 05:45:56.677 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:56.690 UTC [197] LOG:  execute <unnamed>: SET application_name = 'PostgreSQL JDBC Driver'
2021-11-08 05:45:56.724 UTC [107] LOG:  execute <unnamed>: 
2021-11-08 05:45:56.724 UTC [107] DETAIL:  parameters: 
2021-11-08 05:45:58.603 UTC [196] LOG:  execute <unnamed>: BEGIN READ ONLY
2021-11-08 05:45:58.604 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:58.604 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:58.653 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:58.653 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:58.710 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:58.710 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:58.751 UTC [196] LOG:  execute S_1: COMMIT
2021-11-08 05:45:58.792 UTC [196] LOG:  execute <unnamed>: BEGIN READ ONLY
2021-11-08 05:45:58.792 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:58.792 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:58.836 UTC [196] LOG:  execute S_1: COMMIT
2021-11-08 05:45:58.880 UTC [196] LOG:  execute <unnamed>: BEGIN READ ONLY
2021-11-08 05:45:58.881 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:58.881 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:58.924 UTC [196] LOG:  execute S_1: COMMIT
2021-11-08 05:45:58.965 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:58.965 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:59.008 UTC [196] LOG:  execute <unnamed>: 
2021-11-08 05:45:59.008 UTC [196] DETAIL:  parameters: 
2021-11-08 05:45:59.192 UTC [107] LOG:  execute S_1: COMMIT

CodePudding user response:

According to Postgres document in log_line_prefix, You can set how Postgres print log for example log data, process id, username, etc

You can use %x for log transaction-id

  • Related