log_connections now logs trust connections

The one login the audit trail never described

Turn connection logging on and a Postgres server narrates every login in three acts: the connection arrived, the client proved who it was, the server let it in. Until PostgreSQL 17 the middle act had a gap in it. A client that matched a rule requiring no proof at all produced the first line and the third, and nothing in between. The log said a session opened and said which role it opened as, and said nothing whatsoever about how that role had been established.

That is a strange hole to leave in an audit trail, because the connections falling into it are exactly the ones an auditor cares most about. Rules requiring no proof are not rare in the wild. They are how the local socket is usually configured on a single-tenant box, how a great many container images ship, how a replication user is sometimes wired between two hosts on a private network, and how somebody’s afternoon of debugging occasionally ends. Every one of those is a session the server accepted without checking anything, and the log recorded it in the same shape as a session that had presented a verified secret.

PostgreSQL 17 closes it. The middle line is now written for those connections too, naming the method and the rule file and line that matched. The release notes carry it as a single sentence in the Monitoring section of the PostgreSQL 17 release notes, which is a fair reflection of how much code it took and a poor reflection of what it changes for anyone whose logs are evidence.

What it changes is what can be proved rather than asserted. Before 17, an operator asked to show that a particular session had authenticated with a particular method could answer for the sessions that had authenticated and could only shrug about the rest, because the absence of a line meant either a rule requiring no proof or a version too old to say. Those are very different facts and the log rendered them identically. After the upgrade the absence of that line on a 17 cluster means something specific and narrow, and the presence of it carries the method and the rule that produced it. An access review stops being a reconstruction from configuration files that may not be the ones in force, and becomes a query over what the server actually did.

The same applies in the less comfortable direction. A cluster whose logs now show a stream of sessions admitted with no proof at all has not become less secure than it was on the previous version; it has become harder to be vague about. Several of the postures people describe as “locked down” are one local socket rule away from not being, and the first upgrade to 17 is where that stops being invisible.

Two roles, two rules, one connection each

The fixture gives the server two roles and two rules to match them with, one demanding a password and one demanding nothing, and then connects once as each. Prepending the rules puts them on known line numbers so the captured output is comparable between the two servers.

CREATE EXTENSION dblink;
CREATE ROLE payments_app LOGIN;
CREATE ROLE reporting_app LOGIN PASSWORD 'rotate-me-in-your-own-cluster';
COPY (SELECT unnest(ARRAY['local all reporting_app scram-sha-256',
                          'local all payments_app   trust']))
  TO PROGRAM 'cat - "$PGDATA"/pg_hba.conf > /tmp/hba && cp /tmp/hba "$PGDATA"/pg_hba.conf';
SELECT pg_reload_conf();

CREATE EXTENSION
CREATE ROLE
CREATE ROLE
COPY 2
 pg_reload_conf 
----------------
 t
(1 row)

Both servers run with the collector on and connection logging on, so the log is a file the server itself can read back. The query strips the timestamp and process id from each line, because those are the only parts that differ between one run and the next.

SELECT dblink_connect('pay', 'dbname=' || current_database() || ' user=payments_app') AS trust_login,
       dblink_connect('rep', 'dbname=' || current_database()
                             || ' user=reporting_app password=rotate-me-in-your-own-cluster') AS password_login;
SELECT dblink_disconnect('pay') AS closed_pay, dblink_disconnect('rep') AS closed_rep;
SELECT pg_sleep(1);
SELECT regexp_replace(regexp_replace(l, '^[^\[]*\[\d+\] ', ''), '\(\S*/', '(') AS logged
FROM regexp_split_to_table(pg_read_file(pg_current_logfile()), E'\n') AS l
WHERE l ~ '(payments|reporting)_app'
ORDER BY l;

On 16.15, three lines for two logins:

 trust_login | password_login 
-------------+----------------
 OK          | OK
(1 row)

 closed_pay | closed_rep 
------------+------------
 OK         | OK
(1 row)

 pg_sleep 
----------
 
(1 row)

                                            logged                                             
-----------------------------------------------------------------------------------------------
 LOG:  connection authorized: user=payments_app database=dbx_17_log_connections_trust
 LOG:  connection authenticated: identity="reporting_app" method=scram-sha-256 (pg_hba.conf:1)
 LOG:  connection authorized: user=reporting_app database=dbx_17_log_connections_trust
(3 rows)

On 17.11, four:

 trust_login | password_login 
-------------+----------------
 OK          | OK
(1 row)

 closed_pay | closed_rep 
------------+------------
 OK         | OK
(1 row)

 pg_sleep 
----------
 
(1 row)

                                            logged                                             
-----------------------------------------------------------------------------------------------
 LOG:  connection authenticated: user="payments_app" method=trust (pg_hba.conf:2)
 LOG:  connection authorized: user=payments_app database=dbx_17_log_connections_trust
 LOG:  connection authenticated: identity="reporting_app" method=scram-sha-256 (pg_hba.conf:1)
 LOG:  connection authorized: user=reporting_app database=dbx_17_log_connections_trust
(4 rows)

Read the new line carefully, because it is not the same sentence as the one above it with a different method spliced in. The password login reports an identity, which is the name the client proved it held and which can differ from the role it ends up as. The trust login reports a user, because there is no proved identity to report; the server is naming the role it decided on, not a claim it verified. Both lines name the rule that matched, by file and line number, and that is the part worth having: after an upgrade the log answers “which rule let this session in” for every session rather than most of them.

The rule that keeps working and stops meaning the same thing

Nothing in the catalog moved here, so no query against a system view fails. The thing that changes answer is anything counting lines, and counting is a shape a great many log rules take.

SELECT count(*) FILTER (WHERE l LIKE '%connection authenticated:%') AS authenticated_lines,
       count(*) FILTER (WHERE l LIKE '%connection authorized:%')    AS authorized_lines
FROM regexp_split_to_table(pg_read_file(pg_current_logfile()), E'\n') AS l
WHERE l ~ '(payments|reporting)_app';

On 16.15:

 authenticated_lines | authorized_lines 
---------------------+------------------
                   1 |                2
(1 row)

On 17.11:

 authenticated_lines | authorized_lines 
---------------------+------------------
                   2 |                2
(1 row)

Identical traffic, two logins either way, and a number that doubles across the upgrade. No error is raised, no line is missing, and nothing in the pipeline notices. A dashboard panel counting authenticated logins per minute steps upward on the night of the upgrade on a cluster that is doing exactly what it did the week before, and the first instinct on seeing that step is to go looking for a traffic change that is not there.

The sharper version of the same problem is a parser rather than a counter. Extraction rules are usually written against the line that was there when the rule was written, and the line that was there reported an identity.

SELECT substring(l from 'method=([a-z0-9-]+)')  AS method,
       substring(l from 'identity="([^"]+)"')   AS identity_captured
FROM regexp_split_to_table(pg_read_file(pg_current_logfile()), E'\n') AS l
WHERE l LIKE '%connection authenticated:%'
  AND l ~ '(payments|reporting)_app'
ORDER BY 1;

On 16.15 there is one such line and the capture group finds what it is looking for:

    method     | identity_captured 
---------------+-------------------
 scram-sha-256 | reporting_app
(1 row)

On 17.11 there are two, and the second one yields nothing:

    method     | identity_captured 
---------------+-------------------
 scram-sha-256 | reporting_app
 trust         | 
(2 rows)

That empty cell is the failure worth naming. The line matched the filter, so it is counted as an authenticated connection. The capture group did not match, so whatever field the pipeline populates from it is null, or empty, or the literal text of the pattern, depending on how forgiving the tool is. A report grouping authenticated sessions by identity now has a bucket it did not have before, filled with every session that was never authenticated at all, and the bucket is easy to read as a parsing bug rather than as the traffic that was admitted without being checked.

Fix it by keying on the method rather than on the identity. The method field is present on both shapes of the line and on both versions, and it is the field that actually answers the question an auditor asks.

Knowing in advance how much of this you will get

The volume is not guesswork. The server knows which rules require no proof, and it will tell you before the upgrade rather than after.

SELECT line_number, type, database[1] AS database, user_name[1] AS user_name, auth_method
FROM pg_hba_file_rules
WHERE auth_method = 'trust'
ORDER BY line_number;

 line_number | type  |  database   |  user_name   | auth_method 
-------------+-------+-------------+--------------+-------------
           2 | local | all         | payments_app | trust
         119 | local | all         | all          | trust
         121 | host  | all         | all          | trust
         123 | host  | all         | all          | trust
         126 | local | replication | all          | trust
         127 | host  | replication | all          | trust
         128 | host  | replication | all          | trust
         132 | host  | all         | all          | trust
(8 rows)

This is a container’s own configuration and it is deliberately permissive, which makes it a good illustration of the shape of the answer rather than of a sensible policy. What matters is the method: every rule listed adds one log line per connection that matches it after the upgrade, and the ones matching a pooled application are the ones that matter, because a pool that reconnects per request turns a per-connection line into a per-request line.

Multiply the count of connections matching those rules by your log line length and you have the extra volume, and it is worth doing that arithmetic before the upgrade rather than during the incident where log shipping falls behind. On a cluster fronted by a pool holding its sessions the answer is nearly nothing. On a cluster where an application connects directly and briefly, the answer can be a material share of the log.

What the new line is worth watching for

• Any connection whose method is the one requiring no proof, from a rule you did not expect to be matched. Before 17 this was unanswerable from the log; it is now a filter on one field.
• The rule file and line number in the new line, when a cluster’s configuration is managed by something that rewrites it. A rule matching on a line you did not think existed is the cheapest possible detection of a bad deploy.
• The ratio of authenticated lines to authorized lines, which should now be one on a 17 cluster. Anything less means a code path you have not accounted for.

There is no exporter metric for any of this and there should not be. These are events with attribution attached, and flattening them into a counter throws away the attribution that made the change worth having.

What it costs to have

The setting that gates it is the one that was already gating the other two lines, so there is no new switch to find and no restart: turning connection logging on and reloading is the whole of it. The cost is the log, and the log is charged twice, once to the disk it is written to and once to whatever ships and indexes it.

The other cost is the prefix. A line is only evidence if it can be tied to a session, and the connection lines carry a process id in the prefix rather than in the message, so a log line prefix that omits it turns three related lines into three unrelated ones. Check the prefix before you trust the new line in a report, because the upgrade adds the line whether or not the prefix makes it joinable.

One thing not to do: treat the appearance of the new line as evidence that nothing changed in your authentication configuration. It is the same configuration, described more completely. The rules that required no proof required no proof last week too, and the only thing 17 changed is that you can now count them.