Skip to content

Introduce connection context to allow correlation of log statements to the actual connection #339

@mp911de

Description

@mp911de

From the discussion at #309, we should introduce more context details to our logging to allow for log statement to connection correlation. We should capture the logical connection id (cid) , Postgres PID (pid) and the netty channel Id showing both socket addresses of the connection (probably only when trace logging is enabled).

The logs would look like:

Debug:

11:06:54.865 reactor-tcp-kqueue-2 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x2] Response: ParameterStatus{name='session_authorization', value='test'}
11:06:54.865 reactor-tcp-kqueue-2 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x2] Response: ParameterStatus{name='standard_conforming_strings', value='on'}
11:06:54.865 reactor-tcp-kqueue-2 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x2] Response: ParameterStatus{name='TimeZone', value='Europe/Berlin'}
11:06:54.865 reactor-tcp-kqueue-2 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x2] Response: BackendKeyData{processId=110, secretKey=-168211844}
11:06:54.865 reactor-tcp-kqueue-2 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x2][pid: 110] Response: ReadyForQuery{transactionStatus=IDLE}
11:06:54.866 reactor-tcp-kqueue-2 io.r2dbc.postgresql.QUERY                               [cid: 0x2][pid: 110] Executing query: SHOW TRANS

Trace:

11:08:30.252 reactor-tcp-kqueue-1 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x1][id: 0xac115823, L:/127.0.0.1:59607 - R:localhost/127.0.0.1:33180] Response: ParameterStatus{name='TimeZone', value='Europe/Berlin'}
11:08:30.253 reactor-tcp-kqueue-1 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x1][id: 0xac115823, L:/127.0.0.1:59607 - R:localhost/127.0.0.1:33180] Response: BackendKeyData{processId=109, secretKey=233682966}
11:08:30.253 reactor-tcp-kqueue-1 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x1][pid: 109][id: 0xac115823, L:/127.0.0.1:59607 - R:localhost/127.0.0.1:33180] Response: ReadyForQuery{transactionStatus=IDLE}
11:08:30.288 reactor-tcp-kqueue-1 io.r2dbc.postgresql.QUERY                               [cid: 0x1][pid: 109][id: 0xac115823, L:/127.0.0.1:59607 - R:localhost/127.0.0.1:33180] Executing query: SHOW TRANSACTION ISOLATION LEVEL
11:08:30.288 reactor-tcp-kqueue-1 io.r2dbc.postgresql.client.ReactorNettyClient           [cid: 0x1][pid: 109][id: 0xac115823, L:/127.0.0

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions