Postgres `log_disconnections = on` does not log disconnects

Question

I have surely a basic problem and am undoubtedly overlooking a simple issue..

I have configured Postgres 12.4 with log_disconnections, but the log file does not show any disconnects. (It is logging connections, as expected with log_connections = on.)

I have connected and disconnected with both psql (exiting psql with \quit) and the Ruby pg library. In both cases, no disconnect message was logged.

During testing, I used SELECT * FROM pg_stat_activity WHERE datname = 'foo' to verify a connection was present (idle) while I was connected, and gone when I quit psql or calling pg/Ruby conn.finish.

Why isn't the server logging disconnections?

The server configuration is basic:

max_connections = 100           # (change requires restart)

shared_buffers = 128MB          # min 128kB
dynamic_shared_memory_type = posix  # the default is the first option

max_wal_size = 1GB
min_wal_size = 80MB

log_connections = on
log_disconnections = on
log_timezone = 'America/Toronto'

datestyle = 'iso, mdy'
timezone = 'America/Toronto'

lc_messages = 'C'           # locale for system error message
lc_monetary = 'C'           # locale for monetary formatting
lc_numeric = 'C'            # locale for number formatting
lc_time = 'C'               # locale for time formatting

default_text_search_config = 'pg_catalog.english'

The server log file:

2021-01-18 09:36:18.774 EST [45512] LOG:  starting PostgreSQL 12.4 on x86_64-apple-darwin18.7.0, compiled by Apple clang version 11.0.0 (clang-1100.0.33.17), 64-bit
2021-01-18 09:36:18.777 EST [45512] LOG:  listening on IPv6 address "::1", port 5432
2021-01-18 09:36:18.777 EST [45512] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2021-01-18 09:36:18.778 EST [45512] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2021-01-18 09:36:18.825 EST [45513] LOG:  database system was shut down at 2021-01-18 09:35:38 EST
2021-01-18 09:36:18.828 EST [45512] LOG:  database system is ready to accept connections
2021-01-18 09:44:36.433 EST [45868] LOG:  connection received: host=[local]
2021-01-18 09:44:36.434 EST [45868] LOG:  connection authorized: user=testuser database=foo application_name=pry
2021-01-18 09:45:37.299 EST [45962] LOG:  connection received: host=[local]
2021-01-18 09:45:37.300 EST [45962] LOG:  connection authorized: user=testuser database=foo application_name=psql

Postgres started with pg_ctl -l path/to/log -D path/to/pgdir start.

Answer 1

To debug non-working configuration settings, you can verify at runtime what the value is, and where it came from by querying the view pg_settings

select setting, source, sourcefile, sourceline 
from pg_settings 
where name = 'log_disconnections'

The columns sourcefile and sourceline will tell you where the currently active value was taken from.

If you find a value from postgresql.auto.conf the value was applied through ALTER SYSTEM and the correct way to remove it, is to use ALTER SYSTEM again.