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 <sergey.dudola...@gmail.com> 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: <programlisting> # 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 <command>postgres</command> command via the <option>-c</option> command-line parameter. For example, <programlisting> -postgres -c log_connections=yes -c log_destination='syslog' +postgres -c log_connection_messages=all -c log_destination='syslog' </programlisting> Settings provided in this way override those set via <filename>postgresql.conf</filename> or <command>ALTER SYSTEM</command>, @@ -6978,23 +6978,65 @@ local0.* /var/log/postgresql </listitem> </varlistentry> - <varlistentry id="guc-log-connections" xreflabel="log_connections"> - <term><varname>log_connections</varname> (<type>boolean</type>) + <varlistentry id="guc-log-connection-messages" xreflabel="log_connection_messages"> + <term><varname>log_connection_messages</varname> (<type>string</type>) <indexterm> - <primary><varname>log_connections</varname> configuration parameter</primary> + <primary><varname>log_connection_messages</varname> configuration parameter</primary> </indexterm> </term> <listitem> <para> - 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: <literal>authorized,disconnected</literal>. + The default is the empty string meaning nothing is logged. Only superusers and users with the appropriate <literal>SET</literal> privilege can change this parameter at session start, and it cannot be changed at all within a session. - The default is <literal>off</literal>. </para> + <table id="connection-messages"> + <title>Connection messages</title> + <tgroup cols="2"> + <colspec colname="col1" colwidth="1*"/> + <colspec colname="col2" colwidth="2*"/> + <thead> + <row> + <entry>Name</entry> + <entry>Description</entry> + </row> + </thead> + <tbody> + <row> + <entry><literal>received</literal></entry> + <entry>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.</entry> + </row> + + <row> + <entry><literal>authenticated</literal></entry> + <entry>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.</entry> + </row> + + <row> + <entry><literal>authorized</literal></entry> + <entry>Logs successful completion of authorization. At this point the connection has been fully established.</entry> + </row> + + <row> + <entry><literal>disconnected</literal></entry> + <entry>Logs session termination. The log output provides information similar to <literal>authorized</literal>, + plus the duration of the session.</entry> + </row> + + <row> + <entry><literal>all</literal></entry> + <entry>A convenience alias. When present, must be the only value in the list.</entry> + </row> + + </tbody> + </tgroup> + </table> + <note> <para> Some client programs, like <application>psql</application>, attempt @@ -7006,26 +7048,6 @@ local0.* /var/log/postgresql </listitem> </varlistentry> - <varlistentry id="guc-log-disconnections" xreflabel="log_disconnections"> - <term><varname>log_disconnections</varname> (<type>boolean</type>) - <indexterm> - <primary><varname>log_disconnections</varname> configuration parameter</primary> - </indexterm> - </term> - <listitem> - <para> - Causes session terminations to be logged. The log output - provides information similar to <varname>log_connections</varname>, - plus the duration of the session. - Only superusers and users with the appropriate <literal>SET</literal> - privilege can change this parameter at session start, - and it cannot be changed at all within a session. - The default is <literal>off</literal>. - </para> - </listitem> - </varlistentry> - - <varlistentry id="guc-log-duration" xreflabel="log_duration"> <term><varname>log_duration</varname> (<type>boolean</type>) <indexterm> diff --git a/src/backend/commands/variable.c b/src/backend/commands/variable.c index 791bac6715..8b6798175b 100644 --- a/src/backend/commands/variable.c +++ b/src/backend/commands/variable.c @@ -993,6 +993,79 @@ show_role(void) } +/* 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)); + if (!myextra) + return false; + memset(myextra, 0, 4 * sizeof(bool)); + *extra = (void *) myextra; + if (log_connection_messages == NULL || log_connection_messages[0] == '\0') { + return true; + } + + if (pg_strcasecmp(*newval, "all") == 0) + { + myextra[0] = true; + myextra[1] = true; + myextra[2] = true; + myextra[3] = true; + return true; + } + + /* Need a modifiable copy of string */ + rawname = pstrdup(*newval); + /* Parse string into list of identifiers */ + /* We rely on SplitIdentifierString to downcase and strip whitespace */ + if (!SplitIdentifierString(rawname, ',', &namelist)) + { + /* syntax error in name list */ + GUC_check_errdetail("List syntax is invalid."); + pfree(rawname); + list_free(namelist); + return false; + } + + foreach(l, namelist) + { + char *stage = (char *) lfirst(l); + + if (pg_strcasecmp(stage, "received") == 0) + myextra[0] = true; + else if (pg_strcasecmp(stage, "authenticated") == 0) + myextra[1] = true; + else if (pg_strcasecmp(stage, "authorized") == 0) + myextra[2] = true; + else if (pg_strcasecmp(stage, "disconnected") == 0) + myextra[3] = true; + 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 'received', 'authenticated', 'authorized', 'disconnected', and 'all'." + "If 'all' is present, it must be the only value in the list."); + pfree(rawname); + list_free(namelist); + return false; + } + } + + pfree(rawname); + list_free(namelist); + + return true; +} + /* * PATH VARIABLES * @@ -1015,6 +1088,21 @@ check_canonical_path(char **newval, void **extra, GucSource source) /* + * assign_log_connection_messages: GUC assign_hook for log_connection_messages + */ +void +assign_log_connection_messages(const char *newval, void *extra) +{ + + bool *myextra = (bool *) extra; + + Log_received = myextra[0]; + Log_authenticated = myextra[1]; + Log_authorized = myextra[2]; + Log_disconnected = myextra[3]; +} + + /* * MISCELLANEOUS */ diff --git a/src/backend/libpq/auth.c b/src/backend/libpq/auth.c index e2f723d188..9a0cdc0c59 100644 --- a/src/backend/libpq/auth.c +++ b/src/backend/libpq/auth.c @@ -327,7 +327,8 @@ auth_failed(Port *port, int status, const char *logdetail) /* * Sets the authenticated identity for the current user. The provided string * will be stored into MyClientConnectionInfo, alongside the current HBA - * method in use. The ID will be logged if log_connections is enabled. + * method in use. The ID will be logged if + * log_connection_messages contains the 'authenticated' value. * * Auth methods should call this routine exactly once, as soon as the user is * successfully authenticated, even if they have reasons to know that @@ -359,7 +360,7 @@ set_authn_id(Port *port, const char *id) MyClientConnectionInfo.authn_id = MemoryContextStrdup(TopMemoryContext, id); MyClientConnectionInfo.auth_method = port->hba->auth_method; - if (Log_connections) + if (Log_authenticated) { ereport(LOG, errmsg("connection authenticated: identity=\"%s\" method=%s " diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c index 0b637ba6a2..6cc574012a 100644 --- a/src/backend/postmaster/postmaster.c +++ b/src/backend/postmaster/postmaster.c @@ -236,7 +236,6 @@ int PreAuthDelay = 0; int AuthenticationTimeout = 60; bool log_hostname; /* for ps display and logging */ -bool Log_connections = false; bool Db_user_namespace = false; bool enable_bonjour = false; @@ -4364,8 +4363,8 @@ BackendInitialize(Port *port) port->remote_host = strdup(remote_host); port->remote_port = strdup(remote_port); - /* And now we can issue the Log_connections message, if wanted */ - if (Log_connections) + /* And now we can issue the Log_received message, if wanted */ + if (Log_received) { if (remote_port[0]) ereport(LOG, diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 3082093d1e..81a27e4844 100644 --- 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; int log_statement = LOGSTMT_NONE; @@ -3582,8 +3585,7 @@ set_debug_options(int debug_flag, GucContext context, GucSource source) if (debug_flag >= 1 && context == PGC_POSTMASTER) { - SetConfigOption("log_connections", "true", context, source); - SetConfigOption("log_disconnections", "true", context, source); + SetConfigOption("log_connection_messages", "all", context, source); } if (debug_flag >= 2) SetConfigOption("log_statement", "all", context, source); @@ -4153,9 +4155,9 @@ PostgresMain(const char *dbname, const char *username) /* * Also set up handler to log session end; we have to wait till now to be - * sure Log_disconnections has its final value. + * sure Log_disconnected has its final value. */ - if (IsUnderPostmaster && Log_disconnections) + if (IsUnderPostmaster && Log_disconnected) on_proc_exit(log_disconnections, 0); pgstat_report_connect(MyDatabaseId); diff --git a/src/backend/utils/init/postinit.c b/src/backend/utils/init/postinit.c index 31b7e1de5d..ff2ce4bcf1 100644 --- a/src/backend/utils/init/postinit.c +++ b/src/backend/utils/init/postinit.c @@ -250,7 +250,7 @@ PerformAuthentication(Port *port) */ disable_timeout(STATEMENT_TIMEOUT, false); - if (Log_connections) + if (Log_authorized) { StringInfoData logmsg; diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index 836b49484a..6dcf54da33 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -579,6 +579,7 @@ static char *recovery_target_string; static char *recovery_target_xid_string; static char *recovery_target_name_string; static char *recovery_target_lsn_string; +static char *log_connection_messages_string; /* should be static, but commands/variable.c needs to get at this */ char *role_string; @@ -1161,24 +1162,6 @@ struct config_bool ConfigureNamesBool[] = true, NULL, NULL, NULL }, - { - {"log_connections", PGC_SU_BACKEND, LOGGING_WHAT, - gettext_noop("Logs each successful connection."), - NULL - }, - &Log_connections, - false, - NULL, NULL, NULL - }, - { - {"log_disconnections", PGC_SU_BACKEND, LOGGING_WHAT, - gettext_noop("Logs end of a session, including duration."), - NULL - }, - &Log_disconnections, - false, - NULL, NULL, NULL - }, { {"log_replication_commands", PGC_SUSET, LOGGING_WHAT, gettext_noop("Logs each replication command."), @@ -4097,6 +4080,16 @@ struct config_string ConfigureNamesString[] = check_session_authorization, assign_session_authorization, NULL }, + { + {"log_connection_messages", PGC_SU_BACKEND, LOGGING_WHAT, + gettext_noop("Lists connection stages to log."), + NULL, + GUC_LIST_INPUT | GUC_LIST_QUOTE + }, + &log_connection_messages_string, + "", + check_log_connection_messages, assign_log_connection_messages, NULL + }, { {"log_destination", PGC_SIGHUP, LOGGING_WHERE, gettext_noop("Sets the destination for server log output."), diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 868d21c351..d34316d11c 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -21,7 +21,7 @@ # require a server shutdown and restart to take effect. # # Any parameter can also be given as a command-line option to the server, e.g., -# "postgres -c log_connections=on". Some parameters can be changed at run time +# "postgres -c log_connection_messages=all". Some parameters can be changed at run time # with the "SET" SQL command. # # Memory units: B = bytes Time units: us = microseconds @@ -551,8 +551,7 @@ # actions running at least this number # of milliseconds. #log_checkpoints = on -#log_connections = off -#log_disconnections = off +#log_connection_messages = '' #log_duration = off #log_error_verbosity = default # terse, default, or verbose messages #log_hostname = off diff --git a/src/include/postgres.h b/src/include/postgres.h index 54730dfb38..9ad1a781e8 100644 --- a/src/include/postgres.h +++ b/src/include/postgres.h @@ -924,4 +924,9 @@ extern Datum Float8GetDatum(float8 X); #define NON_EXEC_STATIC static #endif +extern PGDLLIMPORT bool Log_received; +extern PGDLLIMPORT bool Log_authenticated; +extern PGDLLIMPORT bool Log_authorized; +extern PGDLLIMPORT bool Log_disconnected; + #endif /* POSTGRES_H */ diff --git a/src/include/postmaster/postmaster.h b/src/include/postmaster/postmaster.h index 90e333ccd2..3bd9a5bfcd 100644 --- a/src/include/postmaster/postmaster.h +++ b/src/include/postmaster/postmaster.h @@ -24,7 +24,6 @@ extern PGDLLIMPORT char *ListenAddresses; extern PGDLLIMPORT bool ClientAuthInProgress; extern PGDLLIMPORT int PreAuthDelay; extern PGDLLIMPORT int AuthenticationTimeout; -extern PGDLLIMPORT bool Log_connections; extern PGDLLIMPORT bool log_hostname; extern PGDLLIMPORT bool enable_bonjour; extern PGDLLIMPORT char *bonjour_name; diff --git a/src/include/utils/guc_hooks.h b/src/include/utils/guc_hooks.h index f1a9a183b4..af5bef31ea 100644 --- a/src/include/utils/guc_hooks.h +++ b/src/include/utils/guc_hooks.h @@ -67,6 +67,8 @@ extern bool check_locale_numeric(char **newval, void **extra, GucSource source); extern void assign_locale_numeric(const char *newval, void *extra); extern bool check_locale_time(char **newval, void **extra, GucSource source); extern void assign_locale_time(const char *newval, void *extra); +extern bool check_log_connection_messages(char **newval, void **extra, GucSource source); +extern void assign_log_connection_messages(const char *newval, void *extra); extern bool check_log_destination(char **newval, void **extra, GucSource source); extern void assign_log_destination(const char *newval, void *extra); @@ -155,4 +157,5 @@ extern bool check_wal_consistency_checking(char **newval, void **extra, extern void assign_wal_consistency_checking(const char *newval, void *extra); extern void assign_xlog_sync_method(int new_sync_method, void *extra); + #endif /* GUC_HOOKS_H */ diff --git a/src/test/authentication/t/001_password.pl b/src/test/authentication/t/001_password.pl index 42d3d4c79b..be457c4d68 100644 --- a/src/test/authentication/t/001_password.pl +++ b/src/test/authentication/t/001_password.pl @@ -63,7 +63,7 @@ sub test_conn # Initialize primary node my $node = PostgreSQL::Test::Cluster->new('primary'); $node->init; -$node->append_conf('postgresql.conf', "log_connections = on\n"); +$node->append_conf('postgresql.conf', "log_connection_messages = all\n"); $node->start; # Create 3 roles with different password methods for each one. The same diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl index a2bc8a5351..c9dd2d3546 100644 --- a/src/test/kerberos/t/001_auth.pl +++ b/src/test/kerberos/t/001_auth.pl @@ -173,7 +173,7 @@ $node->append_conf( 'postgresql.conf', qq{ listen_addresses = '$hostaddr' krb_server_keyfile = '$keytab' -log_connections = on +log_connection_messages = all lc_messages = 'C' }); $node->start; diff --git a/src/test/ldap/t/001_auth.pl b/src/test/ldap/t/001_auth.pl index fd90832b75..94ceb3c267 100644 --- a/src/test/ldap/t/001_auth.pl +++ b/src/test/ldap/t/001_auth.pl @@ -169,7 +169,7 @@ note "setting up PostgreSQL instance"; my $node = PostgreSQL::Test::Cluster->new('node'); $node->init; -$node->append_conf('postgresql.conf', "log_connections = on\n"); +$node->append_conf('postgresql.conf', "log_connection_messages = all\n"); $node->start; $node->safe_psql('postgres', 'CREATE USER test0;'); diff --git a/src/test/recovery/t/013_crash_restart.pl b/src/test/recovery/t/013_crash_restart.pl index c22844d39c..d005676891 100644 --- a/src/test/recovery/t/013_crash_restart.pl +++ b/src/test/recovery/t/013_crash_restart.pl @@ -27,7 +27,7 @@ $node->start(); $node->safe_psql( 'postgres', q[ALTER SYSTEM SET restart_after_crash = 1; - ALTER SYSTEM SET log_connections = 1; + ALTER SYSTEM SET log_connection_messages = all; SELECT pg_reload_conf();]); # Run psql, keeping session alive, so we have an alive backend to kill. diff --git a/src/test/recovery/t/022_crash_temp_files.pl b/src/test/recovery/t/022_crash_temp_files.pl index 53a55c7a8a..e756a0f33c 100644 --- a/src/test/recovery/t/022_crash_temp_files.pl +++ b/src/test/recovery/t/022_crash_temp_files.pl @@ -26,7 +26,7 @@ $node->start(); $node->safe_psql( 'postgres', q[ALTER SYSTEM SET remove_temp_files_after_crash = on; - ALTER SYSTEM SET log_connections = 1; + ALTER SYSTEM SET log_connection_messages = all; ALTER SYSTEM SET work_mem = '64kB'; ALTER SYSTEM SET restart_after_crash = on; SELECT pg_reload_conf();]); diff --git a/src/test/recovery/t/032_relfilenode_reuse.pl b/src/test/recovery/t/032_relfilenode_reuse.pl index 499ec34a7a..b0a0d19840 100644 --- a/src/test/recovery/t/032_relfilenode_reuse.pl +++ b/src/test/recovery/t/032_relfilenode_reuse.pl @@ -18,7 +18,7 @@ $node_primary->init(allows_streaming => 1); $node_primary->append_conf( 'postgresql.conf', q[ allow_in_place_tablespaces = true -log_connections=on +log_connection_messages=all # to avoid "repairing" corruption full_page_writes=off log_min_messages=debug2 diff --git a/src/test/ssl/t/SSL/Server.pm b/src/test/ssl/t/SSL/Server.pm index 9520578e7d..2114efb2c7 100644 --- a/src/test/ssl/t/SSL/Server.pm +++ b/src/test/ssl/t/SSL/Server.pm @@ -193,7 +193,7 @@ sub configure_test_server_for_ssl # enable logging etc. open my $conf, '>>', "$pgdata/postgresql.conf"; print $conf "fsync=off\n"; - print $conf "log_connections=on\n"; + print $conf "log_connection_messages=all\n"; print $conf "log_hostname=on\n"; print $conf "listen_addresses='$serverhost'\n"; print $conf "log_statement=all\n"; diff --git a/src/tools/ci/pg_ci_base.conf b/src/tools/ci/pg_ci_base.conf index d8faa9c26c..7596d515aa 100644 --- a/src/tools/ci/pg_ci_base.conf +++ b/src/tools/ci/pg_ci_base.conf @@ -8,7 +8,6 @@ max_prepared_transactions = 10 # Settings that make logs more useful log_autovacuum_min_duration = 0 log_checkpoints = true -log_connections = true -log_disconnections = true +log_connection_messages = all log_line_prefix = '%m [%p][%b] %q[%a][%v:%x] ' log_lock_waits = true -- 2.34.1