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

Author: Sergey Dudoladov

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
@@ -337,7 +337,7 @@ UPDATE pg_settings SET setting = reset_val WHERE name = 'configuration_parameter
        <option>-c name=value</option> command-line parameter, or its equivalent
        <option>--name=value</option> variation.  For example,
 <programlisting>
-postgres -c log_connections=yes --log-destination='syslog'
+postgres -c log_connection_messages=all --log-destination='syslog'
 </programlisting>
        Settings provided in this way override those set via
        <filename>postgresql.conf</filename> or <command>ALTER SYSTEM</command>,
@@ -7314,23 +7314,75 @@ 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 the specified stages of each connection attempt to be logged.
+        Example: <literal>authorized,disconnected</literal>.
+        The default is the empty string, which means that 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 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.</entry>
+       </row>
+
+       <row>
+        <entry><literal>authenticated</literal></entry>
+        <entry>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.
+        </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. If present, it must be the only value in the
+        list.</entry>
+       </row>
+
+      </tbody>
+     </tgroup>
+    </table>
+
        <note>
         <para>
          Some client programs, like <application>psql</application>, attempt
@@ -7342,26 +7394,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>

src/backend/commands/variable.c

@@ -1048,6 +1048,78 @@ show_role(void)
 }
 
 
+/* check_hook: validate new log_connection_messages value
+ *
+ * The implementation follows the check_log_destination hook.
+ */
+bool
+check_log_connection_messages(char **newval, void **extra, GucSource source)
+{
+	char		*rawname;
+	List		*namelist;
+	ListCell	*l;
+	int			newlogconnect = 0;
+	int			*myextra;
+
+	if (pg_strcasecmp(*newval, "all") == 0)
+	{
+		newlogconnect |= LOG_CONNECTION_ALL;
+		myextra = (int *) guc_malloc(LOG, sizeof(int));
+		if (!myextra)
+			return false;
+		*myextra = newlogconnect;
+		*extra = (void *) myextra;
+		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)
+			newlogconnect |= LOG_CONNECTION_RECEIVED;
+		else if (pg_strcasecmp(stage, "authenticated") == 0)
+			newlogconnect |= LOG_CONNECTION_AUTHENTICATED;
+		else if (pg_strcasecmp(stage, "authorized") == 0)
+			newlogconnect |= LOG_CONNECTION_AUTHORIZED;
+		else if (pg_strcasecmp(stage, "disconnected") == 0)
+			newlogconnect |= LOG_CONNECTION_DISCONNECTED;
+		else {
+			GUC_check_errcode(ERRCODE_INVALID_PARAMETER_VALUE);
+			GUC_check_errmsg("invalid value for parameter '%s'", stage);
+			GUC_check_errdetail("Valid values to use in the list are 'all', 'received', 'authenticated', 'authorized', and 'disconnected'."
+			" 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);
+
+	myextra = (int *) guc_malloc(LOG, sizeof(int));
+	if (!myextra)
+		return false;
+	*myextra = newlogconnect;
+	*extra = (void *) myextra;
+
+	return true;
+}
+
 /*
  * PATH VARIABLES
  *
@@ -1070,6 +1142,15 @@ 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)
+{
+	Log_connection_messages = *((int *) extra);
+}
+
+ /*
  * MISCELLANEOUS
  */
 

src/backend/libpq/auth.c

@@ -317,7 +317,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
@@ -349,7 +350,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_connection_messages & LOG_CONNECTION_AUTHENTICATED)
 	{
 		ereport(LOG,
 				errmsg("connection authenticated: identity=\"%s\" method=%s "
@@ -633,11 +634,11 @@ ClientAuthentication(Port *port)
 #endif
 	}
 
-	if (Log_connections && status == STATUS_OK &&
+	if (Log_connection_messages && LOG_CONNECTION_AUTHENTICATED && status == STATUS_OK &&
 		!MyClientConnectionInfo.authn_id)
 	{
 		/*
-		 * Normally, if log_connections is set, the call to set_authn_id()
+		 * Normally, if log_connection_messages is set, the call to set_authn_id()
 		 * will log the connection.  However, if that function is never
 		 * called, perhaps because the trust method is in use, then we handle
 		 * the logging here instead.

src/backend/postmaster/postmaster.c

@@ -237,7 +237,6 @@ int			PreAuthDelay = 0;
 int			AuthenticationTimeout = 60;
 
 bool		log_hostname;		/* for ps display and logging */
-bool		Log_connections = false;
 
 bool		enable_bonjour = false;
 char	   *bonjour_name;

src/backend/tcop/backend_startup.c

@@ -201,8 +201,8 @@ BackendInitialize(ClientSocket *client_sock, CAC_state cac)
 	port->remote_host = MemoryContextStrdup(TopMemoryContext, remote_host);
 	port->remote_port = MemoryContextStrdup(TopMemoryContext, remote_port);
 
-	/* And now we can issue the Log_connections message, if wanted */
-	if (Log_connections)
+	/* And now we can issue the "connection received" message, if wanted */
+	if (Log_connection_messages & LOG_CONNECTION_RECEIVED)
 	{
 		if (remote_port[0])
 			ereport(LOG,

src/backend/tcop/postgres.c

@@ -89,8 +89,8 @@ 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 */
+int			Log_connection_messages = 0;
 
 int			log_statement = LOGSTMT_NONE;
 
@@ -3654,8 +3654,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);
@@ -4271,9 +4270,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_connection_messages has its final value.
 	 */
-	if (IsUnderPostmaster && Log_disconnections)
+	if (IsUnderPostmaster && (Log_connection_messages & LOG_CONNECTION_DISCONNECTED))
 		on_proc_exit(log_disconnections, 0);
 
 	pgstat_report_connect(MyDatabaseId);

src/backend/utils/init/postinit.c

@@ -252,7 +252,7 @@ PerformAuthentication(Port *port)
 	 */
 	disable_timeout(STATEMENT_TIMEOUT, false);
 
-	if (Log_connections)
+	if (Log_connection_messages & LOG_CONNECTION_AUTHORIZED)
 	{
 		StringInfoData logmsg;
 

src/backend/utils/misc/guc_tables.c

@@ -616,6 +616,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;
@@ -1219,15 +1220,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
-	},
 	{
 		{"trace_connection_negotiation", PGC_POSTMASTER, DEVELOPER_OPTIONS,
 			gettext_noop("Logs details of pre-authentication connection handshake."),
@@ -1238,15 +1230,6 @@ struct config_bool ConfigureNamesBool[] =
 		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."),
@@ -4467,6 +4450,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
+		},
+		&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."),

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
@@ -578,8 +578,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