Re: Introduce "log_connection_stages" setting.
> On 3 Jul 2023, at 15:57, Daniel Gustafsson wrote: > >> On 16 May 2023, at 20:51, Sergey Dudoladov >> wrote: > >> I have attached the fourth version of the patch. > > This version fails the ldap_password test on all platforms on pg_ctl failing > to start: > > [14:48:10.544] --- stdout --- > [14:48:10.544] # executing test in > /tmp/cirrus-ci-build/build/testrun/ldap_password_func/001_mutated_bindpasswd > group ldap_password_func test 001_mutated_bindpasswd > [14:48:10.544] # waiting for slapd to accept requests... > [14:48:10.544] # setting up PostgreSQL instance > [14:48:10.544] Bail out! pg_ctl start failed > [14:48:10.544] # test failed > > Updating src/test/modules/ldap_password_func/t/001_mutated_bindpasswd.pl with > the new GUC might solve the problem from skimming this. > > Please send a fixed version, I'm marking the patch Waiting on Author in the > meantime. With the patch failing tests and the thread stalled with no update I am marking this returned with feedback. Please feel free to resubmit to a future CF. -- Daniel Gustafsson
Re: Introduce "log_connection_stages" setting.
> On 16 May 2023, at 20:51, Sergey Dudoladov wrote: > I have attached the fourth version of the patch. This version fails the ldap_password test on all platforms on pg_ctl failing to start: [14:48:10.544] --- stdout --- [14:48:10.544] # executing test in /tmp/cirrus-ci-build/build/testrun/ldap_password_func/001_mutated_bindpasswd group ldap_password_func test 001_mutated_bindpasswd [14:48:10.544] # waiting for slapd to accept requests... [14:48:10.544] # setting up PostgreSQL instance [14:48:10.544] Bail out! pg_ctl start failed [14:48:10.544] # test failed Updating src/test/modules/ldap_password_func/t/001_mutated_bindpasswd.pl with the new GUC might solve the problem from skimming this. Please send a fixed version, I'm marking the patch Waiting on Author in the meantime. -- Daniel Gustafsson
Re: Introduce "log_connection_stages" setting.
Hello, I have attached the fourth version of the patch. Regards, Sergey. From 0303df03496ec9aafd6e69fa798177ad06a85bee Mon Sep 17 00:00:00 2001 From: Sergey Dudoladov Date: Tue, 8 Nov 2022 18:56:26 +0100 Subject: [PATCH] Introduce 'log_connection_messages' This patch removes 'log_connections' and 'log_disconnections' in favor of 'log_connection_messages', thereby introducing incompatibility Author: Sergey Dudoladov Reviewed-by: Justin Pryzby, Jacob Champion Discussion: https://www.postgresql.org/message-id/flat/CAA8Fd-qCB96uwfgMKrzfNs32mqqysi53yZFNVaRNJ6xDthZEgA%40mail.gmail.com --- doc/src/sgml/config.sgml | 90 +-- src/backend/commands/variable.c | 81 + src/backend/libpq/auth.c | 5 +- src/backend/postmaster/postmaster.c | 5 +- src/backend/tcop/postgres.c | 11 ++- src/backend/utils/init/postinit.c | 2 +- src/backend/utils/misc/guc_tables.c | 30 +++ src/backend/utils/misc/postgresql.conf.sample | 5 +- src/include/postgres.h| 9 ++ src/include/postmaster/postmaster.h | 1 - src/include/utils/guc_hooks.h | 2 + src/test/authentication/t/001_password.pl | 2 +- src/test/authentication/t/003_peer.pl | 2 +- src/test/kerberos/t/001_auth.pl | 2 +- src/test/ldap/t/001_auth.pl | 2 +- src/test/ldap/t/002_bindpasswd.pl | 2 +- src/test/recovery/t/013_crash_restart.pl | 2 +- src/test/recovery/t/022_crash_temp_files.pl | 2 +- src/test/recovery/t/032_relfilenode_reuse.pl | 2 +- src/test/ssl/t/SSL/Server.pm | 2 +- src/tools/ci/pg_ci_base.conf | 3 +- 21 files changed, 187 insertions(+), 75 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 2073bafa1f..42c0a1f3db 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -140,7 +140,7 @@ An example of what this file might look like is: # This is a comment -log_connections = yes +log_connection_messages = all log_destination = 'syslog' search_path = '"$user", public' shared_buffers = 128MB @@ -335,7 +335,7 @@ UPDATE pg_settings SET setting = reset_val WHERE name = 'configuration_parameter passed to the postgres command via the -c command-line parameter. For example, -postgres -c log_connections=yes -c log_destination='syslog' +postgres -c log_connection_messages=all -c log_destination='syslog' Settings provided in this way override those set via postgresql.conf or ALTER SYSTEM, @@ -7124,23 +7124,75 @@ local0.*/var/log/postgresql - - log_connections (boolean) + + log_connection_messages (string) - log_connections configuration parameter + log_connection_messages configuration parameter -Causes each attempted connection to the server to be logged, -as well as successful completion of both client authentication (if -necessary) and authorization. +Causes the specified stages of each connection attempt to be logged. +Example: authorized,disconnected. +The default is the empty string, which means that nothing is logged. Only superusers and users with the appropriate SET privilege can change this parameter at session start, and it cannot be changed at all within a session. -The default is off. + + Connection messages + + + + + +Name +Description + + + + +received +Logs receipt of a connection. At this point a connection has been +received, but no further work has been done: PostgreSQL is about to start +interacting with a client. + + + +authenticated +Logs the original identity used by an authentication method +to identify a user. In most cases, the identity string matches the +PostgreSQL username, but some third-party authentication methods may +alter the original user identifier before the server stores it. Failed +authentication is always logged regardless of the value of this setting. + + + + +authorized +Logs successful completion of authorization. At this point the +connection has been fully established. + + + + +disconnected +Logs session termination. The log output provides information +similar to authorized, plus the duration of the session. + + + + +all +A convenience alias. If present, it must be the only value in the +list. + + + + + + Some client programs, like psql, attempt @@ -7152,26 +7204,6 @@ local0.*
Re: Introduce "log_connection_stages" setting.
On 3/2/23 14:56, Tom Lane wrote: > Jacob Champion writes: >> If I've understood Tom correctly in [1], both of these guc_mallocs >> should be using a loglevel less than ERROR, to avoid forcing a >> postmaster exit when out of memory. (I used WARNING in that thread >> instead, which seemed to be acceptable.) > > Actually, preferred practice is as seen in e.g. check_datestyle: > > myextra = (int *) guc_malloc(LOG, 2 * sizeof(int)); > if (!myextra) > return false; > myextra[0] = newDateStyle; > myextra[1] = newDateOrder; > *extra = (void *) myextra; > > which gives the guc.c functions an opportunity to manage the > failure. Ah, thanks for the correction. (My guc_strdup(WARNING, ...) calls may need to be cleaned up too, then.) --Jacob
Re: Introduce "log_connection_stages" setting.
Jacob Champion writes: > This is looking very good. One bigger comment: >> +myextra = (int *) guc_malloc(ERROR, sizeof(int)); >> +*myextra = newlogconnect; > If I've understood Tom correctly in [1], both of these guc_mallocs > should be using a loglevel less than ERROR, to avoid forcing a > postmaster exit when out of memory. (I used WARNING in that thread > instead, which seemed to be acceptable.) Actually, preferred practice is as seen in e.g. check_datestyle: myextra = (int *) guc_malloc(LOG, 2 * sizeof(int)); if (!myextra) return false; myextra[0] = newDateStyle; myextra[1] = newDateOrder; *extra = (void *) myextra; which gives the guc.c functions an opportunity to manage the failure. A quick grep shows that there are existing check functions that did not get that memo, e.g. check_recovery_target_lsn. We ought to clean them up. This is, of course, not super important unless you're allocating something quite large; the odds of going OOM in the postmaster should be pretty small. regards, tom lane
Re: Introduce "log_connection_stages" setting.
On 2/1/23 11:59, Sergey Dudoladov wrote:
> Justin, thank you for the fast review. The new version is attached.
This is looking very good. One bigger comment:
> + myextra = (int *) guc_malloc(ERROR, sizeof(int));
> + *myextra = newlogconnect;
If I've understood Tom correctly in [1], both of these guc_mallocs
should be using a loglevel less than ERROR, to avoid forcing a
postmaster exit when out of memory. (I used WARNING in that thread
instead, which seemed to be acceptable.)
And a couple of nitpicks:
> +Causes the specified stages of each connection attempt to the server
> to be logged. Example: authorized,disconnected.
Long line; should be rewrapped.
> + else {
>
> + GUC_check_errcode(ERRCODE_INVALID_PARAMETER_VALUE);
>
> + GUC_check_errmsg("invalid value '%s'", stage);
>
> + GUC_check_errdetail("Valid values to use in the list are 'all',
> 'received', 'authenticate
> + " If 'all' is present, it must be the only value in the list.");
I think the errmsg here should reuse the standard message format
invalid value for parameter "%s": "%s"
both for consistency and ease of translation.
Thanks!
--Jacob
[1] https://www.postgresql.org/message-id/2012342.1658356951%40sss.pgh.pa.us
Re: Introduce "log_connection_stages" setting.
Hi again, Justin, thank you for the fast review. The new version is attached. Regards, Sergey Dudoladov From 994a86e6ac3abb647d93bdaf0f42be76f42b83a8 Mon Sep 17 00:00:00 2001 From: Sergey Dudoladov Date: Tue, 8 Nov 2022 18:56:26 +0100 Subject: [PATCH] Introduce 'log_connection_messages' This patch removes 'log_connections' and 'log_disconnections' in favor of 'log_connection_messages', thereby introducing incompatibility Author: Sergey Dudoladov Reviewed-by: Justin Pryzby Discussion: https://www.postgresql.org/message-id/flat/CAA8Fd-qCB96uwfgMKrzfNs32mqqysi53yZFNVaRNJ6xDthZEgA%40mail.gmail.com --- doc/src/sgml/config.sgml | 89 +-- src/backend/commands/variable.c | 77 src/backend/libpq/auth.c | 5 +- src/backend/postmaster/postmaster.c | 5 +- src/backend/tcop/postgres.c | 11 ++- src/backend/utils/init/postinit.c | 2 +- src/backend/utils/misc/guc_tables.c | 30 +++ src/backend/utils/misc/postgresql.conf.sample | 5 +- src/include/postgres.h| 9 ++ src/include/postmaster/postmaster.h | 1 - src/include/utils/guc_hooks.h | 2 + src/test/authentication/t/001_password.pl | 2 +- src/test/authentication/t/003_peer.pl | 2 +- src/test/kerberos/t/001_auth.pl | 2 +- src/test/ldap/t/001_auth.pl | 2 +- src/test/ldap/t/002_bindpasswd.pl | 2 +- src/test/recovery/t/013_crash_restart.pl | 2 +- src/test/recovery/t/022_crash_temp_files.pl | 2 +- src/test/recovery/t/032_relfilenode_reuse.pl | 2 +- src/test/ssl/t/SSL/Server.pm | 2 +- src/tools/ci/pg_ci_base.conf | 3 +- 21 files changed, 182 insertions(+), 75 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 1cf53c74ea..ccefe144c3 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -140,7 +140,7 @@ An example of what this file might look like is: # This is a comment -log_connections = yes +log_connection_messages = all log_destination = 'syslog' search_path = '"$user", public' shared_buffers = 128MB @@ -335,7 +335,7 @@ UPDATE pg_settings SET setting = reset_val WHERE name = 'configuration_parameter passed to the postgres command via the -c command-line parameter. For example, -postgres -c log_connections=yes -c log_destination='syslog' +postgres -c log_connection_messages=all -c log_destination='syslog' Settings provided in this way override those set via postgresql.conf or ALTER SYSTEM, @@ -7085,23 +7085,74 @@ local0.*/var/log/postgresql - - log_connections (boolean) + + log_connection_messages (string) - log_connections configuration parameter + log_connection_messages configuration parameter -Causes each attempted connection to the server to be logged, -as well as successful completion of both client authentication (if -necessary) and authorization. +Causes the specified stages of each connection attempt to the server to be logged. Example: authorized,disconnected. +The default is the empty string, which means that nothing is logged. Only superusers and users with the appropriate SET privilege can change this parameter at session start, and it cannot be changed at all within a session. -The default is off. + + Connection messages + + + + + +Name +Description + + + + +received +Logs receipt of a connection. At this point a connection has been +received, but no further work has been done: PostgreSQL is about to start +interacting with a client. + + + +authenticated +Logs the original identity used by an authentication method +to identify a user. In most cases, the identity string matches the +PostgreSQL username, but some third-party authentication methods may +alter the original user identifier before the server stores it. Failed +authentication is always logged regardless of the value of this setting. + + + + +authorized +Logs successful completion of authorization. At this point the +connection has been fully established. + + + + +disconnected +Logs session termination. The log output provides information +similar to authorized, plus the duration of the session. + + + + +all +A convenience alias. If present, it must be the only value in the +list. + + + + + + Some client programs, like psql, attempt @@ -7113,26
Re: Introduce "log_connection_stages" setting.
Thanks for updating the patch. It's currently failing check-world, due
to a test that was added on January 23 (a9dc7f941):
http://cfbot.cputube.org/sergey-dudoladov.html
[19:15:57.101] Summary of Failures:
[19:15:57.101] [19:15:57.101] 250/251 postgresql:ldap / ldap/002_bindpasswd
ERROR 1.38s
2023-01-30 19:15:52.427 GMT [56038] LOG: unrecognized configuration parameter
"log_connections" in file
"/tmp/cirrus-ci-build/build/testrun/ldap/002_bindpasswd/data/t_002_bindpasswd_node_data/pgdata/postgresql.conf"
line 839
> +received, but no further work has been done: Postgres is about to
> start
say "PostgreSQL" to match the rest of the docs.
> + GUC_check_errmsg("Invalid value '%s'", stage);
This message shouldn't be uppercased.
> + GUC_check_errdetail("Valid values to use in the list
> are 'received', 'authenticated', 'authorized', 'disconnected', and 'all'."
> + "If 'all' is present, it must be the only value in the
> list.");
Maybe "all" should be first ?
There's no spaces before "If":
| 2023-01-31 00:17:48.906 GMT [5676] DETALLE: Valid values to use in the list
are 'received', 'authenticated', 'authorized', 'disconnected', and 'all'.If
'all' is present, it must be the only value in the list.
> +/* flags for logging information about session state */
> +int Log_connection_messages = LOG_CONNECTION_ALL;
The initial value here is overwritten by the GUC default during startup.
For consistency, the integer should be initialized to 0.
> +extern PGDLLIMPORT int Log_connection_messages;
> +
> +/* Bitmap for logging connection messages */
> +#define LOG_CONNECTION_RECEIVED 1
> +#define LOG_CONNECTION_AUTHENTICATED 2
> +#define LOG_CONNECTION_AUTHORIZED 4
> +#define LOG_CONNECTION_DISCONNECTED 8
> +#define LOG_CONNECTION_ALL15
Maybe the integers should be written like (1<<0)..
And maybe ALL should be 0x ?
More nitpicks:
> +Causes stages of each attempted connection to the server to be
> logged. Example: authorized,disconnected.
"Causes the specified stages of each connection attempt .."
> +The default is the empty string meaning nothing is logged.
".. string, which means that nothing is logged"
> +Logs the original identity that an authentication method
> employs
> +to identify a user. In most cases, the identity string matches the
".. original identity used by an authentication method ..'
--
Justin
Re: Introduce "log_connection_stages" setting.
Hello, hackers Thank you for the reviews. I've modified the patch to incorporate your suggestions: + flag bits are now used to encode different connection stages + failing tests are now fixed. It was not a keyword issue but rather "check_log_connection_messages" not allocating memory properly in the special case log_connection_messages = 'all' + the GUC option is now only GUC_LIST_INPUT + typo fixes and line rewrapping in the docs Regards, Sergey From 4bf99bccb4b278188dbc679f00d506cd35b025f5 Mon Sep 17 00:00:00 2001 From: Sergey Dudoladov Date: Tue, 8 Nov 2022 18:56:26 +0100 Subject: [PATCH] Introduce 'log_connection_messages' This patch removes 'log_connections' and 'log_disconnections' in favor of 'log_connection_messages', thereby introducing incompatibility Author: Sergey Dudoladov Reviewed-by: Discussion: https://www.postgresql.org/message-id/flat/CAA8Fd-qCB96uwfgMKrzfNs32mqqysi53yZFNVaRNJ6xDthZEgA%40mail.gmail.com --- doc/src/sgml/config.sgml | 89 +-- src/backend/commands/variable.c | 77 src/backend/libpq/auth.c | 5 +- src/backend/postmaster/postmaster.c | 5 +- src/backend/tcop/postgres.c | 11 ++- src/backend/utils/init/postinit.c | 2 +- src/backend/utils/misc/guc_tables.c | 29 +++--- src/backend/utils/misc/postgresql.conf.sample | 5 +- src/include/postgres.h| 9 ++ src/include/postmaster/postmaster.h | 1 - src/include/utils/guc_hooks.h | 2 + src/test/authentication/t/001_password.pl | 2 +- src/test/authentication/t/003_peer.pl | 2 +- src/test/kerberos/t/001_auth.pl | 2 +- src/test/ldap/t/001_auth.pl | 2 +- src/test/recovery/t/013_crash_restart.pl | 2 +- src/test/recovery/t/022_crash_temp_files.pl | 2 +- src/test/recovery/t/032_relfilenode_reuse.pl | 2 +- src/test/ssl/t/SSL/Server.pm | 2 +- src/tools/ci/pg_ci_base.conf | 3 +- 20 files changed, 181 insertions(+), 73 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 1cf53c74ea..8b60e814e9 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -140,7 +140,7 @@ An example of what this file might look like is: # This is a comment -log_connections = yes +log_connection_messages = all log_destination = 'syslog' search_path = '"$user", public' shared_buffers = 128MB @@ -335,7 +335,7 @@ UPDATE pg_settings SET setting = reset_val WHERE name = 'configuration_parameter passed to the postgres command via the -c command-line parameter. For example, -postgres -c log_connections=yes -c log_destination='syslog' +postgres -c log_connection_messages=all -c log_destination='syslog' Settings provided in this way override those set via postgresql.conf or ALTER SYSTEM, @@ -7085,23 +7085,74 @@ local0.*/var/log/postgresql - - log_connections (boolean) + + log_connection_messages (string) - log_connections configuration parameter + log_connection_messages configuration parameter -Causes each attempted connection to the server to be logged, -as well as successful completion of both client authentication (if -necessary) and authorization. +Causes stages of each attempted connection to the server to be logged. Example: authorized,disconnected. +The default is the empty string meaning nothing is logged. Only superusers and users with the appropriate SET privilege can change this parameter at session start, and it cannot be changed at all within a session. -The default is off. + + Connection messages + + + + + +Name +Description + + + + +received +Logs receipt of a connection. At this point a connection has been +received, but no further work has been done: Postgres is about to start +interacting with a client. + + + +authenticated +Logs the original identity that an authentication method employs +to identify a user. In most cases, the identity string matches the +PostgreSQL username, but some third-party authentication methods may +alter the original user identifier before the server stores it. Failed +authentication is always logged regardless of the value of this setting. + + + + +authorized +Logs successful completion of authorization. At this point the +connection has been fully established. + + + + +disconnected +Logs session termination. The log output provides information +similar to authorized, plus the duration of the
Re: Introduce "log_connection_stages" setting.
Hi, +1 for the idea! > +authenticated > +Logs the original identity that an authentication method > employs to identify a user. In most cases, the identity string equals the > PostgreSQL username, > +but some third-party authentication methods may alter the original > user identifier before the server stores it. Failed authentication is always > logged regardless of the value of this setting. I think the documentation needs to be rewrapped; those are very long lines. On 11/17/22 07:36, Justin Pryzby wrote: > This function hardcodes each of the 4 connections: > >> +if (pg_strcasecmp(stage, "received") == 0) >> +myextra[0] = true; > > It'd be better to use #defines or enums for these. Hardcoding seems reasonable to me, if this is the only place we're doing string comparison. >> --- a/src/backend/tcop/postgres.c >> +++ b/src/backend/tcop/postgres.c >> @@ -84,8 +84,11 @@ const char *debug_query_string; /* client-supplied query >> string */ >> /* Note: whereToSendOutput is initialized for the bootstrap/standalone case >> */ >> CommandDest whereToSendOutput = DestDebug; >> >> -/* flag for logging end of session */ >> -boolLog_disconnections = false; >> +/* flags for logging information about session state */ >> +boolLog_disconnected = false; >> +boolLog_authenticated = false; >> +boolLog_authorized = false; >> +boolLog_received = false; > > I think this ought to be an integer with flag bits, rather than 4 > booleans (I don't know, but there might be more later?). Then, the > implementation follows the user-facing GUC and also follows > log_destination. Agreed. Or at the very least, follow what's done with wal_consistency_checking? But I think flag bits would be better. The tests should be expanded for cases other than 'all'. As to the failing test cases: it looks like there's a keyword issue with ALTER SYSTEM and 'all', but trying to fix it by quoting also fails. I think it's because of GUC_LIST_QUOTE -- is there a reason that's used here? I don't think we'd need any special characters in future option names. wal_consistency_checking is very similar, and it just uses GUC_LIST_INPUT. Thanks, --Jacob
Re: Introduce "log_connection_stages" setting.
On Thu, Nov 17, 2022 at 09:36:29AM -0600, Justin Pryzby wrote: > On Tue, Nov 08, 2022 at 07:30:38PM +0100, Sergey Dudoladov wrote: ... Also (I didn't realize there was a CF entry), this is failing tests. http://cfbot.cputube.org/sergey-dudoladov.html -- Justin
Re: Introduce "log_connection_stages" setting.
On Tue, Nov 08, 2022 at 07:30:38PM +0100, Sergey Dudoladov wrote:
> +Logs reception of a connection. At this point a connection
> has been received, but no further work has been done:
receipt
> +Logs the original identity that an authentication method
> employs to identify a user. In most cases, the identity string equals the
> PostgreSQL username,
s/equals/matches
> +/* check_hook: validate new log_connection_messages value */
> +bool
> +check_log_connection_messages(char **newval, void **extra, GucSource source)
> +{
> + char*rawname;
> + List*namelist;
> + ListCell*l;
> + char*log_connection_messages = *newval;
> + bool*myextra;
> +
> + /*
> + * Set up the "extra" struct actually used by
> assign_log_connection_messages.
> + */
> + myextra = (bool *) guc_malloc(LOG, 4 * sizeof(bool));
This function hardcodes each of the 4 connections:
> + if (pg_strcasecmp(stage, "received") == 0)
> + myextra[0] = true;
It'd be better to use #defines or enums for these.
> --- a/src/backend/tcop/postgres.c
> +++ b/src/backend/tcop/postgres.c
> @@ -84,8 +84,11 @@ const char *debug_query_string; /* client-supplied query
> string */
> /* Note: whereToSendOutput is initialized for the bootstrap/standalone case
> */
> CommandDest whereToSendOutput = DestDebug;
>
> -/* flag for logging end of session */
> -bool Log_disconnections = false;
> +/* flags for logging information about session state */
> +bool Log_disconnected = false;
> +bool Log_authenticated = false;
> +bool Log_authorized = false;
> +bool Log_received = false;
I think this ought to be an integer with flag bits, rather than 4
booleans (I don't know, but there might be more later?). Then, the
implementation follows the user-facing GUC and also follows
log_destination.
--
Justin
Re: Introduce "log_connection_stages" setting.
Hi hackers, I've sketched an initial patch version; feedback is welcome. Regards, Sergey Dudoladov From be2e6b5c2d6fff1021f52f150b4d849dfbd26ec7 Mon Sep 17 00:00:00 2001 From: Sergey Dudoladov Date: Tue, 8 Nov 2022 18:56:26 +0100 Subject: [PATCH] Introduce 'log_connection_messages' This patch removes 'log_connections' and 'log_disconnections' in favor of 'log_connection_messages', thereby introducing incompatibility Author: Sergey Dudoladov Reviewed-by: Discussion: https://www.postgresql.org/message-id/flat/CAA8Fd-qCB96uwfgMKrzfNs32mqqysi53yZFNVaRNJ6xDthZEgA%40mail.gmail.com --- doc/src/sgml/config.sgml | 80 +++-- src/backend/commands/variable.c | 88 +++ src/backend/libpq/auth.c | 5 +- src/backend/postmaster/postmaster.c | 5 +- src/backend/tcop/postgres.c | 14 +-- src/backend/utils/init/postinit.c | 2 +- src/backend/utils/misc/guc_tables.c | 29 +++--- src/backend/utils/misc/postgresql.conf.sample | 5 +- src/include/postgres.h| 5 ++ src/include/postmaster/postmaster.h | 1 - src/include/utils/guc_hooks.h | 3 + src/test/authentication/t/001_password.pl | 2 +- src/test/kerberos/t/001_auth.pl | 2 +- src/test/ldap/t/001_auth.pl | 2 +- src/test/recovery/t/013_crash_restart.pl | 2 +- src/test/recovery/t/022_crash_temp_files.pl | 2 +- src/test/recovery/t/032_relfilenode_reuse.pl | 2 +- src/test/ssl/t/SSL/Server.pm | 2 +- src/tools/ci/pg_ci_base.conf | 3 +- 19 files changed, 182 insertions(+), 72 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 559eb898a9..ab9d118c12 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -140,7 +140,7 @@ An example of what this file might look like is: # This is a comment -log_connections = yes +log_connection_messages = all log_destination = 'syslog' search_path = '"$user", public' shared_buffers = 128MB @@ -335,7 +335,7 @@ UPDATE pg_settings SET setting = reset_val WHERE name = 'configuration_parameter passed to the postgres command via the -c command-line parameter. For example, -postgres -c log_connections=yes -c log_destination='syslog' +postgres -c log_connection_messages=all -c log_destination='syslog' Settings provided in this way override those set via postgresql.conf or ALTER SYSTEM, @@ -6978,23 +6978,65 @@ local0.*/var/log/postgresql - - log_connections (boolean) + + log_connection_messages (string) - log_connections configuration parameter + log_connection_messages configuration parameter -Causes each attempted connection to the server to be logged, -as well as successful completion of both client authentication (if -necessary) and authorization. +Causes stages of each attempted connection to the server to be logged. Example: authorized,disconnected. +The default is the empty string meaning nothing is logged. Only superusers and users with the appropriate SET privilege can change this parameter at session start, and it cannot be changed at all within a session. -The default is off. + + Connection messages + + + + + +Name +Description + + + + +received +Logs reception of a connection. At this point a connection has been received, but no further work has been done: +Postgres is about to start interacting with a client. + + + +authenticated +Logs the original identity that an authentication method employs to identify a user. In most cases, the identity string equals the PostgreSQL username, +but some third-party authentication methods may alter the original user identifier before the server stores it. Failed authentication is always logged regardless of the value of this setting. + + + +authorized +Logs successful completion of authorization. At this point the connection has been fully established. + + + +disconnected +Logs session termination. The log output provides information similar to authorized, +plus the duration of the session. + + + +all +A convenience alias. When present, must be the only value in the list. + + + + + + Some client programs, like psql, attempt @@ -7006,26 +7048,6 @@ local0.*/var/log/postgresql - - log_disconnections (boolean) - - log_disconnections configuration parameter - - - - -Causes session terminations to
Re: Introduce "log_connection_stages" setting.
On Thu, Jul 14, 2022, at 8:20 AM, Sergey Dudoladov wrote: > I've taken connection stages and terminology from the existing log messages. > The reason I have separated "authorized" and "authenticated" are [1] > and [2] usages of "log_connections"; > "received" is mentioned at [3]. After checking the commit 9afffcb833d, I agree that you need 4 stages: connected, authorized, authenticated, and disconnected. > I have thought about enums too, but we need to cover arbitrary > combinations of message types, for example log only "received" and > "disconnected". > Hence the proposed type "string" with individual values within the > string really drawn from an enum. Ooops. I said enum but I meant string list. > Are there any specific deprecation guidelines ? I have not found any > after a quick search for GUC deprecation in Google and commit history. > A deprecation scheme could look like that: > 1. Mention in the docs "log_(dis)connections" are deprecated in favor > of "log_connection_stages" > 2. Map "log_(dis)connections" to relevant values of > "log_connection_stages" in code if the latter is unset. > 3. Complain in the logs if a conflict arises between the old params > and "log_connection_stages", with "log_connection_stages" > taking the precedence. No. AFAICS in this case, you just remove log_connections and log_disconnections and create the new one (see for example the commit 88e98230268 that replace checkpoint_segments with min_wal_size and max_wal_size). We don't generally keep ConfigureNames* entries for deprecated GUCs. Unless you are renaming a GUC -- see map_old_guc_names; that's not the case. When we remove a GUC, we are introducing an incompatibility so the only place it will be mentioned is the release notes (there is a section called "Migration to Version X" that lists all incompatibilities). From the developer's point of view, you only need to mention in the commit message that this commit is introducing an incompatibility. Hence, when it is time to write the release notes, the information about the removal and the new replacement will be added. -- Euler Taveira EDB https://www.enterprisedb.com/
Re: Introduce "log_connection_stages" setting.
Hello, Thank you for the constructive feedback. > Your proposal will add more confusion to the already-confused logging-related > GUCs. > I wouldn't introduce a new GUC that depends on the stage of other GUC as you > proposed. Agreed, coupling a new GUC with "log_connections" is likely to lead to extra confusion. > There are 3 stages: connect (received), authorized (authenticated), > disconnect. I've taken connection stages and terminology from the existing log messages. The reason I have separated "authorized" and "authenticated" are [1] and [2] usages of "log_connections"; "received" is mentioned at [3]. >> Example: log_connection_stages=’authorized,disconnected’. > would turn the boolean value into an enum value I have thought about enums too, but we need to cover arbitrary combinations of message types, for example log only "received" and "disconnected". Hence the proposed type "string" with individual values within the string really drawn from an enum. > merge log_connections and log_disconnections into a new GUC (?) and deprecate > them. Are there any specific deprecation guidelines ? I have not found any after a quick search for GUC deprecation in Google and commit history. A deprecation scheme could look like that: 1. Mention in the docs "log_(dis)connections" are deprecated in favor of "log_connection_stages" 2. Map "log_(dis)connections" to relevant values of "log_connection_stages" in code if the latter is unset. 3. Complain in the logs if a conflict arises between the old params and "log_connection_stages", with "log_connection_stages" taking the precedence. Regards, Sergey [1] https://github.com/postgres/postgres/blob/3f8148c256e067dc2e8929ed174671ba7dc3339c/src/backend/utils/init/postinit.c#L257-L262 [2] https://github.com/postgres/postgres/blob/02c408e21a6e78ff246ea7a1beb4669634fa9c4c/src/backend/libpq/auth.c#L372 [3] https://github.com/postgres/postgres/blob/master/src/backend/postmaster/postmaster.c#L4393
Re: Introduce "log_connection_stages" setting.
On Tue, Jul 12, 2022, at 10:52 AM, Sergey Dudoladov wrote: > 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. You are proposing a fine-grained control over connection stages reported when log_connections = on. It seems useful if you're only interested in (a) malicious access or (b) authorized access (for audit purposes). > 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. Your proposal will add more confusion to the already-confused logging-related GUCs. If you are proposing to introduce a fine-grained control, the first step should be merge log_connections and log_disconnections into a new GUC (?) and deprecate them. (I wouldn't introduce a new GUC that depends on the stage of other GUC as you proposed.) There are 3 stages: connect (received), authorized (authenticated), disconnect. You can also add 'all' that mimics log_connections / log_disconnections enabled. Another question is if we can reuse log_connections for this improvement instead of a new GUC. In this case, you would turn the boolean value into an enum value. Will it cause trouble while upgrading to this new version? It is one of the reasons to create a new GUC. I would suggest log_connection_messages or log_connection (with the 's' in the end -- since it is too similar to the current GUC name, I'm afraid it is not a good name for it). -- Euler Taveira EDB https://www.enterprisedb.com/
Introduce "log_connection_stages" setting.
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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"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,0,"server process (PID 270675) exited with exit code 0","","postmaster"
