Hello,

The problem we face is excessive logging of connection information
that clutters the logs and in corner cases with many short-lived
connections leads to disk space exhaustion.

Current connection log lines share significant parts of the
information - host, port, very close timestamps etc. - in the common
case of a successful connection:

2022-07-12 12:17:39.369
UTC,,,12875,"10.2.101.63:35616",62cd6663.324b,1,"",2022-07-12 12:17:39
UTC,,0,LOG,00000,"connection received: host=10.2.101.63
port=35616",,,,,,,,,"","not initialized"
2022-07-12 12:17:39.374
UTC,"some_user","postgres",12875,"10.2.101.63:35616",62cd6663.324b,2,"authentication",2022-07-12
12:17:39 UTC,18/4571,0,LOG,00000,"connection authorized:
user=some_user database=postgres SSL enabled (protocol=, cipher=,
compression=)",,,,,,,,,"","client backend"
2022-07-12 12:17:39.430
UTC,"some_user","postgres",12875,"10.2.101.63:35616",62cd6663.324b,3,"idle",2022-07-12
12:17:39 UTC,,0,LOG,00000,"disconnection: session time: 0:00:00.060
user=some_user database=postgres host=10.2.101.63
port=35616",,,,,,,,,"","client backend"

Removing some of the lines should not harm log-based investigations in
most cases, but will shrink the logs improving readability and space
consumption.

I would like to get feedback on the following idea:

Add the `log_connection_stages` setting of type “string” with possible
values "received", "authorized", "authenticated", "disconnected", and
"all", with "all" being the default.
The setting would have effect only when `log_connections` is on.
Example: log_connection_stages=’authorized,disconnected’.
That also implies there would be no need for a separate
"log_disconnection" setting.

For the sake of completeness I have to mention omitting ‘received’
from `log_connection_stages` would lead to absence in logs info about
connections that do not complete initialization: for them only the
“connection received” line is currently logged. The attachment
contains a log excerpt to clarify the situation I am talking about.

Regards,
Sergey.
2022-07-11 15:44:53.126 UTC,,,75,,62cbfa36.4b,3148,,2022-07-11 10:23:50 
UTC,,0,DEBUG,00000,"forked new backend, pid=270675 
socket=12",,,,,,,,,"","postmaster"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,1,"",2022-07-11 15:44:53 
UTC,,0,LOG,00000,"connection received: host=10.2.80.0 
port=1094",,,,,,,,,"","not initialized"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,2,"",2022-07-11 15:44:53 
UTC,,0,DEBUG,00000,"shmem_exit(0): 0 before_shmem_exit callbacks to 
make",,,,,,,,,"","not initialized"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,3,"",2022-07-11 15:44:53 
UTC,,0,DEBUG,00000,"shmem_exit(0): 0 on_shmem_exit callbacks to 
make",,,,,,,,,"","not initialized"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,4,"",2022-07-11 15:44:53 
UTC,,0,DEBUG,00000,"proc_exit(0): 1 callbacks to make",,,,,,,,,"","not 
initialized"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,5,"",2022-07-11 15:44:53 
UTC,,0,DEBUG,00000,"exit(0)",,,,,,,,,"","not initialized"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,6,"",2022-07-11 15:44:53 
UTC,,0,DEBUG,00000,"shmem_exit(-1): 0 before_shmem_exit callbacks to 
make",,,,,,,,,"","not initialized"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,7,"",2022-07-11 15:44:53 
UTC,,0,DEBUG,00000,"shmem_exit(-1): 0 on_shmem_exit callbacks to 
make",,,,,,,,,"","not initialized"
2022-07-11 15:44:53.127 
UTC,,,270675,"10.2.80.0:1094",62cc4575.42153,8,"",2022-07-11 15:44:53 
UTC,,0,DEBUG,00000,"proc_exit(-1): 0 callbacks to make",,,,,,,,,"","not 
initialized"
2022-07-11 15:44:53.129 UTC,,,75,,62cbfa36.4b,3158,,2022-07-11 10:23:50 
UTC,,0,DEBUG,00000,"reaping dead processes ",,,,,,,,,"","postmaster"
2022-07-11 15:44:53.129 UTC,,,75,,62cbfa36.4b,3159,,2022-07-11 10:23:50 
UTC,,0,DEBUG,00000,"server process (PID 270675) exited with exit code 
0",,,,,,,,,"","postmaster"

Reply via email to