On Thu, Feb 27, 2025 at 11:30 AM Andres Freund <and...@anarazel.de> wrote:
>
> On 2025-02-27 11:08:04 -0500, Melanie Plageman wrote:
>
> > However, since that is a bigger project (with more refactoring, etc),
> > he suggested that we change log_connections to a GUC_LIST
> > (ConfigureNamesString) with options like "none", "received,
> > "authenticated", "authorized", "all".
>
> Yep.
I've done a draft of this in attached v7 (see 0001). It still needs
polishing (e.g. I need to figure out where to put the new guc hook
functions and enums and such), but I want to see if this is a viable
direction forward.
I'm worried the list of possible connection log messages could get
unwieldy if we add many more.
- Melanie
From 6f7f1a2e3ea660596bee0348691e192b8c2fce24 Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplage...@gmail.com>
Date: Thu, 27 Feb 2025 17:33:38 -0500
Subject: [PATCH v7 2/2] Add connection establishment duration logging
Add durations for several key parts of connection establishment when
log_connections is enabled.
For a new incoming connection, starting from when the postmaster gets a
socket from accept() and ending when the forked child backend is first
ready for query, there are multiple steps that could each take longer
than expected due to external factors. Provide visibility into
authentication and fork duration as well as the end-to-end connection
establishment time with logging.
To make this portable, the timestamps captured in the postmaster (socket
creation time, fork initiation time) are passed through the ClientSocket
and BackendStartupData structures instead of simply saved in backend
local memory inherited by the child process.
Reviewed-by: Bertrand Drouvot <bertranddrouvot...@gmail.com>
Reviewed-by: Fujii Masao <masao.fu...@oss.nttdata.com>
Reviewed-by: Jelte Fennema-Nio <postg...@jeltef.nl>
Reviewed-by: Jacob Champion <jacob.champ...@enterprisedb.com>
Reviewed-by: Guillaume Lelarge <guillaume.lela...@dalibo.com>
Discussion: https://postgr.es/m/flat/CAAKRu_b_smAHK0ZjrnL5GRxnAVWujEXQWpLXYzGbmpcZd3nLYw%40mail.gmail.com
---
doc/src/sgml/config.sgml | 2 +-
src/backend/postmaster/launch_backend.c | 23 +++++++++++++++++++++++
src/backend/postmaster/postmaster.c | 12 +++++++++++-
src/backend/tcop/postgres.c | 21 +++++++++++++++++++++
src/backend/utils/init/globals.c | 2 ++
src/backend/utils/init/postinit.c | 12 ++++++++++++
src/include/libpq/libpq-be.h | 2 ++
src/include/miscadmin.h | 2 ++
src/include/portability/instr_time.h | 9 +++++++++
src/include/postmaster/postmaster.h | 8 ++++++++
src/include/tcop/backend_startup.h | 5 +++++
src/tools/pgindent/typedefs.list | 1 +
12 files changed, 97 insertions(+), 2 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index c927efd22d1..82b06179a38 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7324,7 +7324,7 @@ local0.* /var/log/postgresql
<para>
Causes each attempted connection to the server to be logged, as well as
successful completion of both client authentication (if necessary) and
- authorization.
+ authorization. Also logs connection establishment component durations.
</para>
<para>
diff --git a/src/backend/postmaster/launch_backend.c b/src/backend/postmaster/launch_backend.c
index 47375e5bfaa..3fe68601899 100644
--- a/src/backend/postmaster/launch_backend.c
+++ b/src/backend/postmaster/launch_backend.c
@@ -232,6 +232,11 @@ postmaster_child_launch(BackendType child_type, int child_slot,
Assert(IsPostmasterEnvironment && !IsUnderPostmaster);
+ /* Capture time Postmaster initiates fork for logging */
+ if ((log_connections & LOG_CONNECTION_TIMINGS) &&
+ (child_type == B_BACKEND || child_type == B_WAL_SENDER))
+ INSTR_TIME_SET_CURRENT(((BackendStartupData *) startup_data)->fork_time);
+
#ifdef EXEC_BACKEND
pid = internal_forkexec(child_process_kinds[child_type].name, child_slot,
startup_data, startup_data_len, client_sock);
@@ -240,6 +245,15 @@ postmaster_child_launch(BackendType child_type, int child_slot,
pid = fork_process();
if (pid == 0) /* child */
{
+ /* Calculate total fork duration in child backend for logging */
+ if ((log_connections & LOG_CONNECTION_TIMINGS) &&
+ (child_type == B_BACKEND || child_type == B_WAL_SENDER))
+ {
+ instr_time fork_time = ((BackendStartupData *) startup_data)->fork_time;
+
+ conn_timing.fork_duration = INSTR_TIME_GET_DURATION_SINCE(fork_time);
+ }
+
/* Close the postmaster's sockets */
ClosePostmasterPorts(child_type == B_LOGGER);
@@ -618,6 +632,15 @@ SubPostmasterMain(int argc, char *argv[])
/* Read in the variables file */
read_backend_variables(argv[2], &startup_data, &startup_data_len);
+ /* Calculate total fork duration in child backend for logging */
+ if ((log_connections & LOG_CONNECTION_READY) &&
+ (child_type == B_BACKEND || child_type == B_WAL_SENDER))
+ {
+ instr_time fork_time = ((BackendStartupData *) startup_data)->fork_time;
+
+ conn_timing.fork_duration = INSTR_TIME_GET_DURATION_SINCE(fork_time);
+ }
+
/* Close the postmaster's sockets (as soon as we know them) */
ClosePostmasterPorts(child_type == B_LOGGER);
diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index aef63793aa7..71aa47c8d36 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -1536,7 +1536,7 @@ check_log_connections(char **newval, void **extra, GucSource source)
if (pg_strcasecmp(*newval, "none") == 0)
effval = "";
else if (pg_strcasecmp(*newval, "all") == 0)
- effval = "received, authenticated, authorized";
+ effval = "received, authenticated, authorized, timings";
/* Need a modifiable copy of string */
rawstring = pstrdup(effval);
@@ -1558,6 +1558,8 @@ check_log_connections(char **newval, void **extra, GucSource source)
flags |= LOG_CONNECTION_AUTHENTICATED;
else if (pg_strcasecmp(item, "authorized") == 0)
flags |= LOG_CONNECTION_AUTHORIZED;
+ else if (pg_strcasecmp(item, "timings") == 0)
+ flags |= LOG_CONNECTION_TIMINGS;
else if (pg_strcasecmp(item, "none") == 0 || pg_strcasecmp(item, "all") == 0)
{
GUC_check_errdetail("Cannot specify \"%s\" in a list of other log_connections options.", item);
@@ -1759,7 +1761,14 @@ ServerLoop(void)
ClientSocket s;
if (AcceptConnection(events[i].fd, &s) == STATUS_OK)
+ {
+ /*
+ * Capture time that Postmaster got a socket from accept
+ * (for logging connection establishment duration)
+ */
+ INSTR_TIME_SET_CURRENT(s.creation_time);
BackendStartup(&s);
+ }
/* We no longer need the open socket in this process */
if (s.sock != PGINVALID_SOCKET)
@@ -3585,6 +3594,7 @@ BackendStartup(ClientSocket *client_sock)
/* Pass down canAcceptConnections state */
startup_data.canAcceptConnections = cac;
+ INSTR_TIME_SET_ZERO(startup_data.fork_time);
bn->rw = NULL;
/* Hasn't asked to be notified about any bgworkers yet */
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index f2f75aa0f88..d753c6bbd5b 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -4153,6 +4153,7 @@ PostgresMain(const char *dbname, const char *username)
volatile bool send_ready_for_query = true;
volatile bool idle_in_transaction_timeout_enabled = false;
volatile bool idle_session_timeout_enabled = false;
+ bool reported_first_ready_for_query = false;
Assert(dbname != NULL);
Assert(username != NULL);
@@ -4607,6 +4608,26 @@ PostgresMain(const char *dbname, const char *username)
/* Report any recently-changed GUC options */
ReportChangedGUCOptions();
+ /*
+ * The first time this backend is ready for query, log the
+ * durations of the different components of connection
+ * establishment.
+ */
+ if (!reported_first_ready_for_query &&
+ (log_connections & LOG_CONNECTION_TIMINGS) &&
+ (AmRegularBackendProcess() || AmWalSenderProcess()))
+ {
+ instr_time total_duration =
+ INSTR_TIME_GET_DURATION_SINCE(MyClientSocket->creation_time);
+
+ ereport(LOG,
+ errmsg("connection establishment times (ms): total: %ld, fork: %ld, authentication: %ld",
+ (long int) INSTR_TIME_GET_MILLISEC(total_duration),
+ (long int) INSTR_TIME_GET_MILLISEC(conn_timing.fork_duration),
+ (long int) INSTR_TIME_GET_MILLISEC(conn_timing.auth_duration)));
+
+ reported_first_ready_for_query = true;
+ }
ReadyForQuery(whereToSendOutput);
send_ready_for_query = false;
}
diff --git a/src/backend/utils/init/globals.c b/src/backend/utils/init/globals.c
index b844f9fdaef..3c7b14dd57d 100644
--- a/src/backend/utils/init/globals.c
+++ b/src/backend/utils/init/globals.c
@@ -43,6 +43,8 @@ volatile uint32 InterruptHoldoffCount = 0;
volatile uint32 QueryCancelHoldoffCount = 0;
volatile uint32 CritSectionCount = 0;
+ConnectionTiming conn_timing = {0};
+
int MyProcPid;
pg_time_t MyStartTime;
TimestampTz MyStartTimestamp;
diff --git a/src/backend/utils/init/postinit.c b/src/backend/utils/init/postinit.c
index 8811f2ba3e6..44e086ceca7 100644
--- a/src/backend/utils/init/postinit.c
+++ b/src/backend/utils/init/postinit.c
@@ -190,9 +190,16 @@ GetDatabaseTupleByOid(Oid dboid)
static void
PerformAuthentication(Port *port)
{
+ instr_time auth_start_time;
+
/* This should be set already, but let's make sure */
ClientAuthInProgress = true; /* limit visibility of log messages */
+ /* Capture authentication start time for logging */
+ if ((log_connections & LOG_CONNECTION_TIMINGS) &&
+ (AmRegularBackendProcess() || AmWalSenderProcess()))
+ INSTR_TIME_SET_CURRENT(auth_start_time);
+
/*
* In EXEC_BACKEND case, we didn't inherit the contents of pg_hba.conf
* etcetera from the postmaster, and have to load them ourselves.
@@ -251,6 +258,11 @@ PerformAuthentication(Port *port)
*/
disable_timeout(STATEMENT_TIMEOUT, false);
+ /* Calculate authentication duration for logging */
+ if ((log_connections & LOG_CONNECTION_TIMINGS) &&
+ (AmRegularBackendProcess() || AmWalSenderProcess()))
+ conn_timing.auth_duration = INSTR_TIME_GET_DURATION_SINCE(auth_start_time);
+
if (log_connections & LOG_CONNECTION_AUTHORIZED)
{
StringInfoData logmsg;
diff --git a/src/include/libpq/libpq-be.h b/src/include/libpq/libpq-be.h
index 7fe92b15477..b16ad69efff 100644
--- a/src/include/libpq/libpq-be.h
+++ b/src/include/libpq/libpq-be.h
@@ -58,6 +58,7 @@ typedef struct
#include "datatype/timestamp.h"
#include "libpq/hba.h"
#include "libpq/pqcomm.h"
+#include "portability/instr_time.h"
/*
@@ -252,6 +253,7 @@ typedef struct ClientSocket
{
pgsocket sock; /* File descriptor */
SockAddr raddr; /* remote addr (client) */
+ instr_time creation_time;
} ClientSocket;
#ifdef USE_SSL
diff --git a/src/include/miscadmin.h b/src/include/miscadmin.h
index a2b63495eec..9dd18a2c74f 100644
--- a/src/include/miscadmin.h
+++ b/src/include/miscadmin.h
@@ -178,6 +178,8 @@ extern PGDLLIMPORT int MaxConnections;
extern PGDLLIMPORT int max_worker_processes;
extern PGDLLIMPORT int max_parallel_workers;
+extern PGDLLIMPORT struct ConnectionTiming conn_timing;
+
extern PGDLLIMPORT int commit_timestamp_buffers;
extern PGDLLIMPORT int multixact_member_buffers;
extern PGDLLIMPORT int multixact_offset_buffers;
diff --git a/src/include/portability/instr_time.h b/src/include/portability/instr_time.h
index f71a851b18d..48d7ff1bfad 100644
--- a/src/include/portability/instr_time.h
+++ b/src/include/portability/instr_time.h
@@ -184,6 +184,15 @@ GetTimerFrequency(void)
#define INSTR_TIME_ACCUM_DIFF(x,y,z) \
((x).ticks += (y).ticks - (z).ticks)
+static inline instr_time
+INSTR_TIME_GET_DURATION_SINCE(instr_time start_time)
+{
+ instr_time now;
+
+ INSTR_TIME_SET_CURRENT(now);
+ INSTR_TIME_SUBTRACT(now, start_time);
+ return now;
+}
#define INSTR_TIME_GET_DOUBLE(t) \
((double) INSTR_TIME_GET_NANOSEC(t) / NS_PER_S)
diff --git a/src/include/postmaster/postmaster.h b/src/include/postmaster/postmaster.h
index adc693a6b2b..dae7551e7ad 100644
--- a/src/include/postmaster/postmaster.h
+++ b/src/include/postmaster/postmaster.h
@@ -15,6 +15,7 @@
#include "lib/ilist.h"
#include "miscadmin.h"
+#include "portability/instr_time.h"
/*
* A struct representing an active postmaster child process. This is used
@@ -127,6 +128,12 @@ extern PMChild *AllocDeadEndChild(void);
extern bool ReleasePostmasterChildSlot(PMChild *pmchild);
extern PMChild *FindPostmasterChildByPid(int pid);
+typedef struct ConnectionTiming
+{
+ instr_time fork_duration;
+ instr_time auth_duration;
+} ConnectionTiming;
+
/*
* These values correspond to the special must-be-first options for dispatching
* to various subprograms. parse_dispatch_option() can be used to convert an
@@ -149,6 +156,7 @@ typedef enum ConnectionLogType
LOG_CONNECTION_RECEIVED,
LOG_CONNECTION_AUTHENTICATED,
LOG_CONNECTION_AUTHORIZED,
+ LOG_CONNECTION_TIMINGS,
} ConnectionLogType;
#endif /* _POSTMASTER_H */
diff --git a/src/include/tcop/backend_startup.h b/src/include/tcop/backend_startup.h
index 73285611203..7d9c43ce77b 100644
--- a/src/include/tcop/backend_startup.h
+++ b/src/include/tcop/backend_startup.h
@@ -14,6 +14,8 @@
#ifndef BACKEND_STARTUP_H
#define BACKEND_STARTUP_H
+#include "portability/instr_time.h"
+
/* GUCs */
extern PGDLLIMPORT bool Trace_connection_negotiation;
@@ -37,6 +39,9 @@ typedef enum CAC_state
typedef struct BackendStartupData
{
CAC_state canAcceptConnections;
+
+ /* Time at which the postmaster initiates a fork of a backend process */
+ instr_time fork_time;
} BackendStartupData;
extern void BackendMain(const void *startup_data, size_t startup_data_len) pg_attribute_noreturn();
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 59839013d28..ea7163fdada 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -485,6 +485,7 @@ ConnStatusType
ConnType
ConnectionLogType
ConnectionStateEnum
+ConnectionTiming
ConsiderSplitContext
Const
ConstrCheck
--
2.34.1
From 6178535e0be8e25e4209f42d52c8402b6d1e4724 Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplage...@gmail.com>
Date: Thu, 27 Feb 2025 17:32:17 -0500
Subject: [PATCH v7 1/2] Make log_connections a list
Instead of a boolean, make log_connections a list of the possible log
connections events to log. all and none mimic current behavior of on and
off. This is in response to feedback that log_connections logs too many
messages.
---
doc/src/sgml/config.sgml | 25 ++++--
src/backend/libpq/auth.c | 5 +-
src/backend/postmaster/postmaster.c | 76 ++++++++++++++++++-
src/backend/tcop/backend_startup.c | 2 +-
src/backend/utils/init/postinit.c | 2 +-
src/backend/utils/misc/guc_tables.c | 20 ++---
src/backend/utils/misc/postgresql.conf.sample | 4 +-
src/include/postmaster/postmaster.h | 10 ++-
src/include/utils/guc_hooks.h | 2 +
.../libpq/t/005_negotiate_encryption.pl | 2 +-
src/test/authentication/t/001_password.pl | 2 +-
src/test/authentication/t/003_peer.pl | 2 +-
src/test/authentication/t/005_sspi.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 +-
.../t/001_mutated_bindpasswd.pl | 2 +-
.../modules/oauth_validator/t/001_server.pl | 2 +-
.../modules/oauth_validator/t/002_client.pl | 2 +-
.../postmaster/t/002_connection_limits.pl | 2 +-
src/test/postmaster/t/003_start_stop.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/recovery/t/037_invalid_database.pl | 2 +-
src/test/ssl/t/SSL/Server.pm | 2 +-
src/tools/ci/pg_ci_base.conf | 2 +-
src/tools/pgindent/typedefs.list | 1 +
28 files changed, 141 insertions(+), 42 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index e55700f35b8..c927efd22d1 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_connections = '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_connections='all' --log-destination='syslog'
</programlisting>
Settings provided in this way override those set via
<filename>postgresql.conf</filename> or <command>ALTER SYSTEM</command>,
@@ -7315,20 +7315,31 @@ local0.* /var/log/postgresql
</varlistentry>
<varlistentry id="guc-log-connections" xreflabel="log_connections">
- <term><varname>log_connections</varname> (<type>boolean</type>)
+ <term><varname>log_connections</varname> (<type>string</type>)
<indexterm>
<primary><varname>log_connections</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 each attempted connection to the server to be logged, as well as
+ successful completion of both client authentication (if necessary) and
+ authorization.
+ </para>
+
+ <para>
+ May be set to <literal>none</literal> to disable this logging,
+ <literal>all</literal> to enable all connection log message types, or a
+ comma-separated list of the specific connection log message types to
+ emit. The valid options are <literal>received</literal>,
+ <literal>authenticated</literal>, and <literal>authorized</literal>.
+ </para>
+
+ <para>
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>.
+ The default is <literal>'none'</literal>.
</para>
<note>
diff --git a/src/backend/libpq/auth.c b/src/backend/libpq/auth.c
index 81e2f8184e3..b4cc8cb4dd1 100644
--- a/src/backend/libpq/auth.c
+++ b/src/backend/libpq/auth.c
@@ -349,7 +349,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_connections & LOG_CONNECTION_AUTHENTICATED)
{
ereport(LOG,
errmsg("connection authenticated: identity=\"%s\" method=%s "
@@ -633,7 +633,8 @@ ClientAuthentication(Port *port)
#endif
}
- if (Log_connections && status == STATUS_OK &&
+ if ((log_connections & LOG_CONNECTION_AUTHENTICATED) &&
+ status == STATUS_OK &&
!MyClientConnectionInfo.authn_id)
{
/*
diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index 5dd3b6a4fd4..aef63793aa7 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -118,6 +118,7 @@
#include "utils/pidfile.h"
#include "utils/timestamp.h"
#include "utils/varlena.h"
+#include "utils/guc_hooks.h"
#ifdef EXEC_BACKEND
#include "common/file_utils.h"
@@ -237,7 +238,8 @@ int PreAuthDelay = 0;
int AuthenticationTimeout = 60;
bool log_hostname; /* for ps display and logging */
-bool Log_connections = false;
+char *log_connections_string = NULL;
+int log_connections = 0;
bool enable_bonjour = false;
char *bonjour_name;
@@ -1517,6 +1519,78 @@ checkControlFile(void)
FreeFile(fp);
}
+bool
+check_log_connections(char **newval, void **extra, GucSource source)
+{
+ int flags = 0;
+ char *rawstring = NULL;
+ List *elemlist;
+ ListCell *l;
+
+ char *effval = *newval;
+
+ /*
+ * log_connections can be "all" or "none" or a list of comma separated
+ * options
+ */
+ if (pg_strcasecmp(*newval, "none") == 0)
+ effval = "";
+ else if (pg_strcasecmp(*newval, "all") == 0)
+ effval = "received, authenticated, authorized";
+
+ /* Need a modifiable copy of string */
+ rawstring = pstrdup(effval);
+
+ if (!SplitGUCList(rawstring, ',', &elemlist))
+ {
+ GUC_check_errdetail("Invalid list syntax in parameter \"%s\".",
+ "log_connections");
+ goto error;
+ }
+
+ foreach(l, elemlist)
+ {
+ char *item = (char *) lfirst(l);
+
+ if (pg_strcasecmp(item, "received") == 0)
+ flags |= LOG_CONNECTION_RECEIVED;
+ else if (pg_strcasecmp(item, "authenticated") == 0)
+ flags |= LOG_CONNECTION_AUTHENTICATED;
+ else if (pg_strcasecmp(item, "authorized") == 0)
+ flags |= LOG_CONNECTION_AUTHORIZED;
+ else if (pg_strcasecmp(item, "none") == 0 || pg_strcasecmp(item, "all") == 0)
+ {
+ GUC_check_errdetail("Cannot specify \"%s\" in a list of other log_connections options.", item);
+ goto error;
+ }
+ else
+ {
+ GUC_check_errdetail("Invalid option \"%s\".", item);
+ goto error;
+ }
+ }
+
+ pfree(rawstring);
+ list_free(elemlist);
+
+ /* Save the flags in *extra, for use by assign_log_connections */
+ *extra = guc_malloc(ERROR, sizeof(int));
+ *((int *) *extra) = flags;
+
+ return true;
+
+error:
+ pfree(rawstring);
+ list_free(elemlist);
+ return false;
+}
+
+void
+assign_log_connections(const char *newval, void *extra)
+{
+ log_connections = *((int *) extra);
+}
+
/*
* Determine how long should we let ServerLoop sleep, in milliseconds.
*
diff --git a/src/backend/tcop/backend_startup.c b/src/backend/tcop/backend_startup.c
index c70746fa562..2c208c25356 100644
--- a/src/backend/tcop/backend_startup.c
+++ b/src/backend/tcop/backend_startup.c
@@ -202,7 +202,7 @@ BackendInitialize(ClientSocket *client_sock, CAC_state cac)
port->remote_port = MemoryContextStrdup(TopMemoryContext, remote_port);
/* And now we can issue the Log_connections message, if wanted */
- if (Log_connections)
+ if (log_connections & LOG_CONNECTION_RECEIVED)
{
if (remote_port[0])
ereport(LOG,
diff --git a/src/backend/utils/init/postinit.c b/src/backend/utils/init/postinit.c
index 318600d6d02..8811f2ba3e6 100644
--- a/src/backend/utils/init/postinit.c
+++ b/src/backend/utils/init/postinit.c
@@ -251,7 +251,7 @@ PerformAuthentication(Port *port)
*/
disable_timeout(STATEMENT_TIMEOUT, false);
- if (Log_connections)
+ if (log_connections & LOG_CONNECTION_AUTHORIZED)
{
StringInfoData logmsg;
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index ad25cbb39c5..7dfa11810a8 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -1219,15 +1219,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."),
@@ -4850,6 +4841,17 @@ struct config_string ConfigureNamesString[] =
check_debug_io_direct, assign_debug_io_direct, NULL
},
+ {
+ {"log_connections", PGC_SU_BACKEND, LOGGING_WHAT,
+ gettext_noop("Logs information about successful connection."),
+ NULL,
+ GUC_LIST_INPUT
+ },
+ &log_connections_string,
+ "none",
+ check_log_connections, assign_log_connections, NULL
+ },
+
{
{"synchronized_standby_slots", PGC_SIGHUP, REPLICATION_PRIMARY,
gettext_noop("Lists streaming replication standby server replication slot "
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index 5362ff80519..4f54719dd9e 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_connections='all'". Some parameters can be changed at run time
# with the "SET" SQL command.
#
# Memory units: B = bytes Time units: us = microseconds
@@ -578,7 +578,7 @@
# actions running at least this number
# of milliseconds.
#log_checkpoints = on
-#log_connections = off
+#log_connections = 'none'
#log_disconnections = off
#log_duration = off
#log_error_verbosity = default # terse, default, or verbose messages
diff --git a/src/include/postmaster/postmaster.h b/src/include/postmaster/postmaster.h
index b6a3f275a1b..adc693a6b2b 100644
--- a/src/include/postmaster/postmaster.h
+++ b/src/include/postmaster/postmaster.h
@@ -63,7 +63,8 @@ extern PGDLLIMPORT char *ListenAddresses;
extern PGDLLIMPORT bool ClientAuthInProgress;
extern PGDLLIMPORT int PreAuthDelay;
extern PGDLLIMPORT int AuthenticationTimeout;
-extern PGDLLIMPORT bool Log_connections;
+extern PGDLLIMPORT int log_connections;
+extern PGDLLIMPORT char *log_connections_string;
extern PGDLLIMPORT bool log_hostname;
extern PGDLLIMPORT bool enable_bonjour;
extern PGDLLIMPORT char *bonjour_name;
@@ -143,4 +144,11 @@ typedef enum DispatchOption
extern DispatchOption parse_dispatch_option(const char *name);
+typedef enum ConnectionLogType
+{
+ LOG_CONNECTION_RECEIVED,
+ LOG_CONNECTION_AUTHENTICATED,
+ LOG_CONNECTION_AUTHORIZED,
+} ConnectionLogType;
+
#endif /* _POSTMASTER_H */
diff --git a/src/include/utils/guc_hooks.h b/src/include/utils/guc_hooks.h
index 951451a9765..9a0d8ec85c7 100644
--- a/src/include/utils/guc_hooks.h
+++ b/src/include/utils/guc_hooks.h
@@ -51,6 +51,8 @@ extern bool check_datestyle(char **newval, void **extra, GucSource source);
extern void assign_datestyle(const char *newval, void *extra);
extern bool check_debug_io_direct(char **newval, void **extra, GucSource source);
extern void assign_debug_io_direct(const char *newval, void *extra);
+extern bool check_log_connections(char **newval, void **extra, GucSource source);
+extern void assign_log_connections(const char *newval, void *extra);
extern bool check_default_table_access_method(char **newval, void **extra,
GucSource source);
extern bool check_default_tablespace(char **newval, void **extra,
diff --git a/src/interfaces/libpq/t/005_negotiate_encryption.pl b/src/interfaces/libpq/t/005_negotiate_encryption.pl
index c834fa5149a..cb56e09d50b 100644
--- a/src/interfaces/libpq/t/005_negotiate_encryption.pl
+++ b/src/interfaces/libpq/t/005_negotiate_encryption.pl
@@ -107,7 +107,7 @@ $node->append_conf(
listen_addresses = '$hostaddr'
# Capturing the EVENTS that occur during tests requires these settings
-log_connections = on
+log_connections = 'all'
log_disconnections = on
trace_connection_negotiation = on
lc_messages = 'C'
diff --git a/src/test/authentication/t/001_password.pl b/src/test/authentication/t/001_password.pl
index 4ce22ccbdf2..72c187fbdc0 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_connections = 'all'\n");
$node->start;
# could fail in FIPS mode
diff --git a/src/test/authentication/t/003_peer.pl b/src/test/authentication/t/003_peer.pl
index 69ba73bd2b9..8e1b0477d6b 100644
--- a/src/test/authentication/t/003_peer.pl
+++ b/src/test/authentication/t/003_peer.pl
@@ -71,7 +71,7 @@ sub test_role
my $node = PostgreSQL::Test::Cluster->new('node');
$node->init;
-$node->append_conf('postgresql.conf', "log_connections = on\n");
+$node->append_conf('postgresql.conf', "log_connections = 'all'\n");
$node->start;
# Set pg_hba.conf with the peer authentication.
diff --git a/src/test/authentication/t/005_sspi.pl b/src/test/authentication/t/005_sspi.pl
index b480b702590..f9b61babcd7 100644
--- a/src/test/authentication/t/005_sspi.pl
+++ b/src/test/authentication/t/005_sspi.pl
@@ -18,7 +18,7 @@ if (!$windows_os || $use_unix_sockets)
# 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_connections = 'all'\n");
$node->start;
my $huge_pages_status =
diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl
index 6748b109dec..afc3130e720 100644
--- a/src/test/kerberos/t/001_auth.pl
+++ b/src/test/kerberos/t/001_auth.pl
@@ -65,7 +65,7 @@ $node->append_conf(
'postgresql.conf', qq{
listen_addresses = '$hostaddr'
krb_server_keyfile = '$krb->{keytab}'
-log_connections = on
+log_connections = '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 352b0fc1fa7..b6ee386679d 100644
--- a/src/test/ldap/t/001_auth.pl
+++ b/src/test/ldap/t/001_auth.pl
@@ -47,7 +47,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_connections = 'all'\n");
$node->start;
$node->safe_psql('postgres', 'CREATE USER test0;');
diff --git a/src/test/ldap/t/002_bindpasswd.pl b/src/test/ldap/t/002_bindpasswd.pl
index f8beba2b279..2acf96aeb6d 100644
--- a/src/test/ldap/t/002_bindpasswd.pl
+++ b/src/test/ldap/t/002_bindpasswd.pl
@@ -43,7 +43,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_connections = 'all'\n");
$node->start;
$node->safe_psql('postgres', 'CREATE USER test0;');
diff --git a/src/test/modules/ldap_password_func/t/001_mutated_bindpasswd.pl b/src/test/modules/ldap_password_func/t/001_mutated_bindpasswd.pl
index 9b062e1c800..4591b5568a8 100644
--- a/src/test/modules/ldap_password_func/t/001_mutated_bindpasswd.pl
+++ b/src/test/modules/ldap_password_func/t/001_mutated_bindpasswd.pl
@@ -42,7 +42,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_connections = 'all'\n");
$node->append_conf('postgresql.conf',
"shared_preload_libraries = 'ldap_password_func'");
$node->start;
diff --git a/src/test/modules/oauth_validator/t/001_server.pl b/src/test/modules/oauth_validator/t/001_server.pl
index 6fa59fbeb25..27829680439 100644
--- a/src/test/modules/oauth_validator/t/001_server.pl
+++ b/src/test/modules/oauth_validator/t/001_server.pl
@@ -43,7 +43,7 @@ if ($ENV{with_python} ne 'yes')
my $node = PostgreSQL::Test::Cluster->new('primary');
$node->init;
-$node->append_conf('postgresql.conf', "log_connections = on\n");
+$node->append_conf('postgresql.conf', "log_connections = 'all'\n");
$node->append_conf('postgresql.conf',
"oauth_validator_libraries = 'validator'\n");
$node->start;
diff --git a/src/test/modules/oauth_validator/t/002_client.pl b/src/test/modules/oauth_validator/t/002_client.pl
index ab83258d736..aa944ba5f2f 100644
--- a/src/test/modules/oauth_validator/t/002_client.pl
+++ b/src/test/modules/oauth_validator/t/002_client.pl
@@ -26,7 +26,7 @@ if (!$ENV{PG_TEST_EXTRA} || $ENV{PG_TEST_EXTRA} !~ /\boauth\b/)
my $node = PostgreSQL::Test::Cluster->new('primary');
$node->init;
-$node->append_conf('postgresql.conf', "log_connections = on\n");
+$node->append_conf('postgresql.conf', "log_connections = 'all'\n");
$node->append_conf('postgresql.conf',
"oauth_validator_libraries = 'validator'\n");
$node->start;
diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..a221501c206 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -19,7 +19,7 @@ $node->init(
$node->append_conf('postgresql.conf', "max_connections = 6");
$node->append_conf('postgresql.conf', "reserved_connections = 2");
$node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
-$node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_connections = 'all'");
$node->start;
$node->safe_psql(
diff --git a/src/test/postmaster/t/003_start_stop.pl b/src/test/postmaster/t/003_start_stop.pl
index 036b296f72b..08cd7a4857e 100644
--- a/src/test/postmaster/t/003_start_stop.pl
+++ b/src/test/postmaster/t/003_start_stop.pl
@@ -29,7 +29,7 @@ $node->append_conf('postgresql.conf', "max_connections = 5");
$node->append_conf('postgresql.conf', "max_wal_senders = 0");
$node->append_conf('postgresql.conf', "autovacuum_max_workers = 1");
$node->append_conf('postgresql.conf', "max_worker_processes = 1");
-$node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_connections = 'all'");
$node->append_conf('postgresql.conf', "log_min_messages = debug2");
$node->append_conf('postgresql.conf',
"authentication_timeout = '$authentication_timeout s'");
diff --git a/src/test/recovery/t/013_crash_restart.pl b/src/test/recovery/t/013_crash_restart.pl
index cd848918d00..2b6ec94cd75 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_connections = '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 483a416723f..5d4b695c193 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_connections = '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 ddb7223b337..388a50add7a 100644
--- a/src/test/recovery/t/032_relfilenode_reuse.pl
+++ b/src/test/recovery/t/032_relfilenode_reuse.pl
@@ -14,7 +14,7 @@ $node_primary->init(allows_streaming => 1);
$node_primary->append_conf(
'postgresql.conf', q[
allow_in_place_tablespaces = true
-log_connections=on
+log_connections='all'
# to avoid "repairing" corruption
full_page_writes=off
log_min_messages=debug2
diff --git a/src/test/recovery/t/037_invalid_database.pl b/src/test/recovery/t/037_invalid_database.pl
index bdf39397397..ea62650b767 100644
--- a/src/test/recovery/t/037_invalid_database.pl
+++ b/src/test/recovery/t/037_invalid_database.pl
@@ -15,7 +15,7 @@ $node->append_conf(
autovacuum = off
max_prepared_transactions=5
log_min_duration_statement=0
-log_connections=on
+log_connections='all'
log_disconnections=on
));
diff --git a/src/test/ssl/t/SSL/Server.pm b/src/test/ssl/t/SSL/Server.pm
index 447469d8937..7bc45ee7611 100644
--- a/src/test/ssl/t/SSL/Server.pm
+++ b/src/test/ssl/t/SSL/Server.pm
@@ -200,7 +200,7 @@ sub configure_test_server_for_ssl
$node->append_conf(
'postgresql.conf', <<EOF
fsync=off
-log_connections=on
+log_connections='all'
log_hostname=on
listen_addresses='$serverhost'
log_statement=all
diff --git a/src/tools/ci/pg_ci_base.conf b/src/tools/ci/pg_ci_base.conf
index d8faa9c26c1..5593827eb4f 100644
--- a/src/tools/ci/pg_ci_base.conf
+++ b/src/tools/ci/pg_ci_base.conf
@@ -8,7 +8,7 @@ max_prepared_transactions = 10
# Settings that make logs more useful
log_autovacuum_min_duration = 0
log_checkpoints = true
-log_connections = true
+log_connections = 'all'
log_disconnections = true
log_line_prefix = '%m [%p][%b] %q[%a][%v:%x] '
log_lock_waits = true
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index cfbab589d61..59839013d28 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -483,6 +483,7 @@ ConnCacheKey
ConnParams
ConnStatusType
ConnType
+ConnectionLogType
ConnectionStateEnum
ConsiderSplitContext
Const
--
2.34.1
