public inbox for [email protected]  

help / color / mirror / Atom feed

[PATCH 4/8] wal_compression_method: default to zlib..
6+ messages / 5 participants
[nested] [flat]

* [PATCH 4/8] wal_compression_method: default to zlib..
@ 2021-03-11 23:36  Justin Pryzby <[email protected]>
  0 siblings, 0 replies; 6+ messages in thread

From: Justin Pryzby @ 2021-03-11 23:36 UTC (permalink / raw)

this is meant to exercise the CIs, and not meant to be merged
---
 src/backend/access/transam/xlog.c | 2 +-
 src/backend/utils/misc/guc.c      | 4 ++--
 2 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 0183589b4d..8bae73b4ec 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -99,7 +99,7 @@ bool		EnableHotStandby = false;
 bool		fullPageWrites = true;
 bool		wal_log_hints = false;
 bool		wal_compression = false;
-int			wal_compression_method = WAL_COMPRESSION_PGLZ;
+int			wal_compression_method = WAL_COMPRESSION_ZLIB;
 char	   *wal_consistency_checking_string = NULL;
 bool	   *wal_consistency_checking = NULL;
 bool		wal_init_zero = true;
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index 8084027465..c37a8313d3 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -1269,7 +1269,7 @@ static struct config_bool ConfigureNamesBool[] =
 			NULL
 		},
 		&wal_compression,
-		false,
+		true,
 		NULL, NULL, NULL
 	},
 
@@ -4728,7 +4728,7 @@ static struct config_enum ConfigureNamesEnum[] =
 			NULL
 		},
 		&wal_compression_method,
-		WAL_COMPRESSION_PGLZ, wal_compression_options,
+		WAL_COMPRESSION_ZLIB, wal_compression_options,
 		NULL, NULL, NULL
 	},
 
-- 
2.17.0


--f0KYrhQ4vYSV2aJu
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="0005-re-add-wal_compression_method-lz4.patch"



^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible
@ 2024-06-30 17:48  Noah Misch <[email protected]>
  0 siblings, 2 replies; 6+ messages in thread

From: Noah Misch @ 2024-06-30 17:48 UTC (permalink / raw)
  To: Jacob Champion <[email protected]>; +Cc: pgsql-hackers; Euler Taveira <[email protected]>

On Mon, May 06, 2024 at 02:23:38PM -0700, Jacob Champion wrote:
>     =# select * from pg_stat_activity where state = 'authenticating';
>     -[ RECORD 1 ]----+------------------------------
>     datid            |
>     datname          |
>     pid              | 745662
>     leader_pid       |
>     usesysid         |
>     usename          |
>     application_name |
>     client_addr      | 127.0.0.1
>     client_hostname  |
>     client_port      | 38304
>     backend_start    | 2024-05-06 11:25:23.905923-07
>     xact_start       |
>     query_start      |
>     state_change     |
>     wait_event_type  | Client
>     wait_event       | ClientRead
>     state            | authenticating
>     backend_xid      |
>     backend_xmin     | 784
>     query_id         |
>     query            |
>     backend_type     | client backend

That looks like a reasonable user experience.  Is any field newly-nullable?

> = Open Issues, Idle Thoughts =
> 
> Maybe it's wishful thinking, but it'd be cool if a misbehaving
> authentication exchange did not impact replicas in any way. Is there a
> way to make that opening transaction lighterweight?

You could release the xmin before calling PAM or LDAP.  If you've copied all
relevant catalog content to local memory, that's fine to do.  That said, it
may be more fruitful to arrange for authentication timeout to cut through PAM
etc.  Hanging connection slots hurt even if they lack an xmin.  I assume it
takes an immediate shutdown to fix them?

> Would anyone like me to be more aggressive, and create a pgstat entry
> as soon as we have the opening transaction? Or... as soon as a
> connection is made?

All else being equal, I'd like backends to have one before taking any lmgr
lock or snapshot.

> I haven't decided how to test these patches. Seems like a potential
> use case for injection points, but I think I'd need to preload an
> injection library rather than using the existing extension. Does that
> seem like an okay way to go?

Yes.

Thanks,
nm






^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible
@ 2024-07-08 21:09  Jacob Champion <[email protected]>
  parent: Noah Misch <[email protected]>
  1 sibling, 0 replies; 6+ messages in thread

From: Jacob Champion @ 2024-07-08 21:09 UTC (permalink / raw)
  To: Noah Misch <[email protected]>; +Cc: pgsql-hackers; Euler Taveira <[email protected]>

On Sun, Jun 30, 2024 at 10:48 AM Noah Misch <[email protected]> wrote:
> That looks like a reasonable user experience.  Is any field newly-nullable?

Technically I think the answer is no, since backends such as walwriter
already have null database and user fields. It's new for a client
backend to have nulls there, though.

> That said, it
> may be more fruitful to arrange for authentication timeout to cut through PAM
> etc.

That seems mostly out of our hands -- the misbehaving modules are free
to ignore our signals (and do). Is there another way to force the
issue?

> Hanging connection slots hurt even if they lack an xmin.

Oh, would releasing the xmin not really move the needle, then?

> I assume it
> takes an immediate shutdown to fix them?

That's my understanding, yeah.

> > Would anyone like me to be more aggressive, and create a pgstat entry
> > as soon as we have the opening transaction? Or... as soon as a
> > connection is made?
>
> All else being equal, I'd like backends to have one before taking any lmgr
> lock or snapshot.

I can look at this for the next patchset version.

> > I haven't decided how to test these patches. Seems like a potential
> > use case for injection points, but I think I'd need to preload an
> > injection library rather than using the existing extension. Does that
> > seem like an okay way to go?
>
> Yes.

I misunderstood how injection points worked. No preload module needed,
so v2 adds a waitpoint and a test along with a couple of needed tweaks
to BackgroundPsql. I think 0001 should probably be applied
independently.

Thanks,
--Jacob


Attachments:

  [application/octet-stream] v2-0001-BackgroundPsql-handle-empty-query-results.patch (2.6K, ../../CAOYmi+n9tn3xMQk+wqvmBW_4_7xVJQ8DKhHKj4eCYVNnw1=jVA@mail.gmail.com/2-v2-0001-BackgroundPsql-handle-empty-query-results.patch)
  download | inline diff:
From 014f42c62659dbf302b85b9265ab0d6b081b08b3 Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Mon, 8 Jul 2024 10:11:56 -0700
Subject: [PATCH v2 1/4] BackgroundPsql: handle empty query results

There won't be a newline at the end of an empty query result. (Before
this fix, the $banner showed up in the result, leading to confusing
debugging sessions.)

recovery/t/037_invalid_database was relying on the non-empty query
results, so I have switched those cases to use "bare" calls to
query_safe() instead.
---
 src/test/perl/PostgreSQL/Test/BackgroundPsql.pm |  2 +-
 src/test/recovery/t/037_invalid_database.pl     | 12 ++++--------
 2 files changed, 5 insertions(+), 9 deletions(-)

diff --git a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
index 3c2aca1c5d..2760e4bc8d 100644
--- a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
+++ b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
@@ -223,7 +223,7 @@ sub query
 	$output = $self->{stdout};
 
 	# remove banner again, our caller doesn't care
-	$output =~ s/\n$banner\n$//s;
+	$output =~ s/\n?$banner\n$//s;
 
 	# clear out output for the next query
 	$self->{stdout} = '';
diff --git a/src/test/recovery/t/037_invalid_database.pl b/src/test/recovery/t/037_invalid_database.pl
index 47f524be4c..954c3684a9 100644
--- a/src/test/recovery/t/037_invalid_database.pl
+++ b/src/test/recovery/t/037_invalid_database.pl
@@ -93,13 +93,12 @@ my $bgpsql = $node->background_psql('postgres', on_error_stop => 0);
 my $pid = $bgpsql->query('SELECT pg_backend_pid()');
 
 # create the database, prevent drop database via lock held by a 2PC transaction
-ok( $bgpsql->query_safe(
+$bgpsql->query_safe(
 		qq(
   CREATE DATABASE regression_invalid_interrupt;
   BEGIN;
   LOCK pg_tablespace;
-  PREPARE TRANSACTION 'lock_tblspc';)),
-	"blocked DROP DATABASE completion");
+  PREPARE TRANSACTION 'lock_tblspc';));
 
 # Try to drop. This will wait due to the still held lock.
 $bgpsql->query_until(qr//, "DROP DATABASE regression_invalid_interrupt;\n");
@@ -126,11 +125,8 @@ is($node->psql('regression_invalid_interrupt', ''),
 
 # To properly drop the database, we need to release the lock previously preventing
 # doing so.
-ok($bgpsql->query_safe(qq(ROLLBACK PREPARED 'lock_tblspc')),
-	"unblock DROP DATABASE");
-
-ok($bgpsql->query(qq(DROP DATABASE regression_invalid_interrupt)),
-	"DROP DATABASE invalid_interrupt");
+$bgpsql->query_safe(qq(ROLLBACK PREPARED 'lock_tblspc'));
+$bgpsql->query_safe(qq(DROP DATABASE regression_invalid_interrupt));
 
 $bgpsql->quit();
 
-- 
2.34.1



  [application/octet-stream] v2-0002-Test-Cluster-let-background_psql-work-asynchronou.patch (3.1K, ../../CAOYmi+n9tn3xMQk+wqvmBW_4_7xVJQ8DKhHKj4eCYVNnw1=jVA@mail.gmail.com/3-v2-0002-Test-Cluster-let-background_psql-work-asynchronou.patch)
  download | inline diff:
From 592ef05d30505c4c7a1a84084f80c807fce57476 Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Mon, 8 Jul 2024 10:46:55 -0700
Subject: [PATCH v2 2/4] Test::Cluster: let background_psql() work
 asynchronously

Specifying `wait => 0` as a parameter to background_psql() causes it to
return immediately, which lets the client run code during connection.
(This is useful if, for example, connections are blocked on injected
waitpoints.) Clients later call ->wait_connect() manually to complete
the asynchronous connection.
---
 .../perl/PostgreSQL/Test/BackgroundPsql.pm    | 23 ++++++++++++++-----
 src/test/perl/PostgreSQL/Test/Cluster.pm      | 10 +++++++-
 2 files changed, 26 insertions(+), 7 deletions(-)

diff --git a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
index 2760e4bc8d..13489ee95e 100644
--- a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
+++ b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
@@ -81,7 +81,7 @@ string. For C<interactive> sessions, IO::Pty is required.
 sub new
 {
 	my $class = shift;
-	my ($interactive, $psql_params, $timeout) = @_;
+	my ($interactive, $psql_params, $timeout, $wait) = @_;
 	my $psql = {
 		'stdin' => '',
 		'stdout' => '',
@@ -119,14 +119,25 @@ sub new
 
 	my $self = bless $psql, $class;
 
-	$self->_wait_connect();
+	$wait = 1 unless defined($wait);
+	if ($wait)
+	{
+		$self->wait_connect();
+	}
 
 	return $self;
 }
 
-# Internal routine for awaiting psql starting up and being ready to consume
-# input.
-sub _wait_connect
+=pod
+
+=item $session->wait_connect
+
+Returns once psql has started up and is ready to consume input.  This is called
+automatically for clients unless requested otherwise in the constructor.
+
+=cut
+
+sub wait_connect
 {
 	my ($self) = @_;
 
@@ -187,7 +198,7 @@ sub reconnect_and_clear
 	$self->{stdin} = '';
 	$self->{stdout} = '';
 
-	$self->_wait_connect();
+	$self->wait_connect();
 }
 
 =pod
diff --git a/src/test/perl/PostgreSQL/Test/Cluster.pm b/src/test/perl/PostgreSQL/Test/Cluster.pm
index 0135c5a795..759c9d93c2 100644
--- a/src/test/perl/PostgreSQL/Test/Cluster.pm
+++ b/src/test/perl/PostgreSQL/Test/Cluster.pm
@@ -2182,6 +2182,12 @@ connection.
 
 If given, it must be an array reference containing additional parameters to B<psql>.
 
+=item wait => 1
+
+By default, this method will not return until connection has completed (or
+failed).  Set B<wait> to 0 to return immediately instead.  (Clients can call the
+session's C<wait_connect> method manually when needed.)
+
 =back
 
 =cut
@@ -2205,13 +2211,15 @@ sub background_psql
 		'-');
 
 	$params{on_error_stop} = 1 unless defined $params{on_error_stop};
+	$params{wait} = 1 unless defined $params{wait};
 	$timeout = $params{timeout} if defined $params{timeout};
 
 	push @psql_params, '-v', 'ON_ERROR_STOP=1' if $params{on_error_stop};
 	push @psql_params, @{ $params{extra_params} }
 	  if defined $params{extra_params};
 
-	return PostgreSQL::Test::BackgroundPsql->new(0, \@psql_params, $timeout);
+	return PostgreSQL::Test::BackgroundPsql->new(0, \@psql_params, $timeout,
+		$params{wait});
 }
 
 =pod
-- 
2.34.1



  [application/octet-stream] v2-0004-WIP-report-external-auth-calls-as-wait-events.patch (7.5K, ../../CAOYmi+n9tn3xMQk+wqvmBW_4_7xVJQ8DKhHKj4eCYVNnw1=jVA@mail.gmail.com/4-v2-0004-WIP-report-external-auth-calls-as-wait-events.patch)
  download | inline diff:
From 059f856892fb9e9f75d8ce36bad6533457b0711d Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Fri, 3 May 2024 15:58:23 -0700
Subject: [PATCH v2 4/4] WIP: report external auth calls as wait events

Introduce new WAIT_EVENT_AUTHN_* types for various external
authentication systems, to make it obvious what's going wrong if one of
those systems hangs.

TODO:
- don't abuse the IPC wait event group like this
- test
---
 src/backend/libpq/auth.c                      | 54 +++++++++++++++----
 .../utils/activity/wait_event_names.txt       |  5 ++
 2 files changed, 49 insertions(+), 10 deletions(-)

diff --git a/src/backend/libpq/auth.c b/src/backend/libpq/auth.c
index 2b607c5270..bda80e88f9 100644
--- a/src/backend/libpq/auth.c
+++ b/src/backend/libpq/auth.c
@@ -38,6 +38,7 @@
 #include "replication/walsender.h"
 #include "storage/ipc.h"
 #include "utils/memutils.h"
+#include "utils/wait_event.h"
 
 /*----------------------------------------------------------------
  * Global authentication functions
@@ -1000,6 +1001,7 @@ pg_GSS_recvauth(Port *port)
 		elog(DEBUG4, "processing received GSS token of length %u",
 			 (unsigned int) gbuf.length);
 
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_GSSAPI);
 		maj_stat = gss_accept_sec_context(&min_stat,
 										  &port->gss->ctx,
 										  port->gss->cred,
@@ -1011,6 +1013,7 @@ pg_GSS_recvauth(Port *port)
 										  &gflags,
 										  NULL,
 										  pg_gss_accept_delegation ? &delegated_creds : NULL);
+		pgstat_report_wait_end();
 
 		/* gbuf no longer used */
 		pfree(buf.data);
@@ -1222,6 +1225,7 @@ pg_SSPI_recvauth(Port *port)
 	/*
 	 * Acquire a handle to the server credentials.
 	 */
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
 	r = AcquireCredentialsHandle(NULL,
 								 "negotiate",
 								 SECPKG_CRED_INBOUND,
@@ -1231,6 +1235,8 @@ pg_SSPI_recvauth(Port *port)
 								 NULL,
 								 &sspicred,
 								 &expiry);
+	pgstat_report_wait_end();
+
 	if (r != SEC_E_OK)
 		pg_SSPI_error(ERROR, _("could not acquire SSPI credentials"), r);
 
@@ -1296,6 +1302,7 @@ pg_SSPI_recvauth(Port *port)
 		elog(DEBUG4, "processing received SSPI token of length %u",
 			 (unsigned int) buf.len);
 
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
 		r = AcceptSecurityContext(&sspicred,
 								  sspictx,
 								  &inbuf,
@@ -1305,6 +1312,7 @@ pg_SSPI_recvauth(Port *port)
 								  &outbuf,
 								  &contextattr,
 								  NULL);
+		pgstat_report_wait_end();
 
 		/* input buffer no longer used */
 		pfree(buf.data);
@@ -1402,19 +1410,25 @@ pg_SSPI_recvauth(Port *port)
 
 	CloseHandle(token);
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
 	if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize,
 						  domainname, &domainnamesize, &accountnameuse))
 		ereport(ERROR,
 				(errmsg_internal("could not look up account SID: error code %lu",
 								 GetLastError())));
+	pgstat_report_wait_end();
 
 	free(tokenuser);
 
 	if (!port->hba->compat_realm)
 	{
-		int			status = pg_SSPI_make_upn(accountname, sizeof(accountname),
-											  domainname, sizeof(domainname),
-											  port->hba->upn_username);
+		int			status;
+
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
+		status = pg_SSPI_make_upn(accountname, sizeof(accountname),
+								  domainname, sizeof(domainname),
+								  port->hba->upn_username);
+		pgstat_report_wait_end();
 
 		if (status != STATUS_OK)
 			/* Error already reported from pg_SSPI_make_upn */
@@ -2114,7 +2128,9 @@ CheckPAMAuth(Port *port, const char *user, const char *password)
 		return STATUS_ERROR;
 	}
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_PAM);
 	retval = pam_authenticate(pamh, 0);
+	pgstat_report_wait_end();
 
 	if (retval != PAM_SUCCESS)
 	{
@@ -2127,7 +2143,9 @@ CheckPAMAuth(Port *port, const char *user, const char *password)
 		return pam_no_password ? STATUS_EOF : STATUS_ERROR;
 	}
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_PAM);
 	retval = pam_acct_mgmt(pamh, 0);
+	pgstat_report_wait_end();
 
 	if (retval != PAM_SUCCESS)
 	{
@@ -2478,7 +2496,11 @@ CheckLDAPAuth(Port *port)
 	if (passwd == NULL)
 		return STATUS_EOF;		/* client wouldn't send password */
 
-	if (InitializeLDAPConnection(port, &ldap) == STATUS_ERROR)
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
+	r = InitializeLDAPConnection(port, &ldap);
+	pgstat_report_wait_end();
+
+	if (r == STATUS_ERROR)
 	{
 		/* Error message already sent */
 		pfree(passwd);
@@ -2525,9 +2547,12 @@ CheckLDAPAuth(Port *port)
 		 * Bind with a pre-defined username/password (if available) for
 		 * searching. If none is specified, this turns into an anonymous bind.
 		 */
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
 		r = ldap_simple_bind_s(ldap,
 							   port->hba->ldapbinddn ? port->hba->ldapbinddn : "",
 							   port->hba->ldapbindpasswd ? ldap_password_hook(port->hba->ldapbindpasswd) : "");
+		pgstat_report_wait_end();
+
 		if (r != LDAP_SUCCESS)
 		{
 			ereport(LOG,
@@ -2550,6 +2575,8 @@ CheckLDAPAuth(Port *port)
 			filter = psprintf("(uid=%s)", port->user_name);
 
 		search_message = NULL;
+
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
 		r = ldap_search_s(ldap,
 						  port->hba->ldapbasedn,
 						  port->hba->ldapscope,
@@ -2557,6 +2584,7 @@ CheckLDAPAuth(Port *port)
 						  attributes,
 						  0,
 						  &search_message);
+		pgstat_report_wait_end();
 
 		if (r != LDAP_SUCCESS)
 		{
@@ -2625,7 +2653,9 @@ CheckLDAPAuth(Port *port)
 							port->user_name,
 							port->hba->ldapsuffix ? port->hba->ldapsuffix : "");
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
 	r = ldap_simple_bind_s(ldap, fulluser, passwd);
+	pgstat_report_wait_end();
 
 	if (r != LDAP_SUCCESS)
 	{
@@ -2885,12 +2915,16 @@ CheckRADIUSAuth(Port *port)
 	identifiers = list_head(port->hba->radiusidentifiers);
 	foreach(server, port->hba->radiusservers)
 	{
-		int			ret = PerformRadiusTransaction(lfirst(server),
-												   lfirst(secrets),
-												   radiusports ? lfirst(radiusports) : NULL,
-												   identifiers ? lfirst(identifiers) : NULL,
-												   port->user_name,
-												   passwd);
+		int			ret;
+
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_RADIUS);
+		ret = PerformRadiusTransaction(lfirst(server),
+									   lfirst(secrets),
+									   radiusports ? lfirst(radiusports) : NULL,
+									   identifiers ? lfirst(identifiers) : NULL,
+									   port->user_name,
+									   passwd);
+		pgstat_report_wait_end();
 
 		/*------
 		 * STATUS_OK = Login OK
diff --git a/src/backend/utils/activity/wait_event_names.txt b/src/backend/utils/activity/wait_event_names.txt
index db37beeaae..3edbfe4473 100644
--- a/src/backend/utils/activity/wait_event_names.txt
+++ b/src/backend/utils/activity/wait_event_names.txt
@@ -104,6 +104,11 @@ Section: ClassName - WaitEventIPC
 APPEND_READY	"Waiting for subplan nodes of an <literal>Append</literal> plan node to be ready."
 ARCHIVE_CLEANUP_COMMAND	"Waiting for <xref linkend="guc-archive-cleanup-command"/> to complete."
 ARCHIVE_COMMAND	"Waiting for <xref linkend="guc-archive-command"/> to complete."
+AUTHN_GSSAPI	"Waiting for a response from a Kerberos server via GSSAPI."
+AUTHN_LDAP	"Waiting for a response from an LDAP server."
+AUTHN_PAM	"Waiting for a response from the local PAM service."
+AUTHN_RADIUS	"Waiting for a response from a RADIUS server."
+AUTHN_SSPI	"Waiting for a response from a Windows security provider via SSPI."
 BACKEND_TERMINATION	"Waiting for the termination of another backend."
 BACKUP_WAIT_WAL_ARCHIVE	"Waiting for WAL files required for a backup to be successfully archived."
 BGWORKER_SHUTDOWN	"Waiting for background worker to shut down."
-- 
2.34.1



  [application/octet-stream] v2-0003-pgstat-report-in-earlier-with-STATE_AUTHENTICATIN.patch (8.6K, ../../CAOYmi+n9tn3xMQk+wqvmBW_4_7xVJQ8DKhHKj4eCYVNnw1=jVA@mail.gmail.com/5-v2-0003-pgstat-report-in-earlier-with-STATE_AUTHENTICATIN.patch)
  download | inline diff:
From 22ce00adebdd242e747036d46e1904307287feaa Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Fri, 3 May 2024 15:54:58 -0700
Subject: [PATCH v2 3/4] pgstat: report in earlier with STATE_AUTHENTICATING

Add pgstat_bestart_pre_auth(), which reports an 'authenticating' state
while waiting for client authentication to complete. Since we hold a
transaction open across that call, and some authentication methods call
out to external systems, having a pg_stat_activity entry helps DBAs
debug when things go badly wrong.
---
 src/backend/utils/activity/backend_status.c   | 37 +++++++++-
 src/backend/utils/adt/pgstatfuncs.c           |  3 +
 src/backend/utils/init/postinit.c             | 11 +++
 src/include/utils/backend_status.h            |  2 +
 src/test/authentication/Makefile              |  2 +
 src/test/authentication/meson.build           |  4 +
 .../authentication/t/007_injection_points.pl  | 73 +++++++++++++++++++
 7 files changed, 128 insertions(+), 4 deletions(-)
 create mode 100644 src/test/authentication/t/007_injection_points.pl

diff --git a/src/backend/utils/activity/backend_status.c b/src/backend/utils/activity/backend_status.c
index 1ccf4c6d83..c996049bbe 100644
--- a/src/backend/utils/activity/backend_status.c
+++ b/src/backend/utils/activity/backend_status.c
@@ -71,6 +71,7 @@ static int	localNumBackends = 0;
 static MemoryContext backendStatusSnapContext;
 
 
+static void pgstat_bestart_internal(bool pre_auth);
 static void pgstat_beshutdown_hook(int code, Datum arg);
 static void pgstat_read_current_status(void);
 static void pgstat_setup_backend_status_context(void);
@@ -271,6 +272,34 @@ pgstat_beinit(void)
  */
 void
 pgstat_bestart(void)
+{
+	pgstat_bestart_internal(false);
+}
+
+
+/* ----------
+ * pgstat_bestart_pre_auth() -
+ *
+ *	Like pgstat_beinit(), above, but it's designed to be called before
+ *	authentication has been performed (so we have no user or database IDs).
+ *	Called from InitPostgres.
+ *----------
+ */
+void
+pgstat_bestart_pre_auth(void)
+{
+	pgstat_bestart_internal(true);
+}
+
+
+/* ----------
+ * pgstat_bestart_internal() -
+ *
+ *	Implementation of both flavors of pgstat_bestart().
+ *----------
+ */
+static void
+pgstat_bestart_internal(bool pre_auth)
 {
 	volatile PgBackendStatus *vbeentry = MyBEEntry;
 	PgBackendStatus lbeentry;
@@ -320,9 +349,9 @@ pgstat_bestart(void)
 	lbeentry.st_databaseid = MyDatabaseId;
 
 	/* We have userid for client-backends, wal-sender and bgworker processes */
-	if (lbeentry.st_backendType == B_BACKEND
-		|| lbeentry.st_backendType == B_WAL_SENDER
-		|| lbeentry.st_backendType == B_BG_WORKER)
+	if (!pre_auth && (lbeentry.st_backendType == B_BACKEND
+					  || lbeentry.st_backendType == B_WAL_SENDER
+					  || lbeentry.st_backendType == B_BG_WORKER))
 		lbeentry.st_userid = GetSessionUserId();
 	else
 		lbeentry.st_userid = InvalidOid;
@@ -377,7 +406,7 @@ pgstat_bestart(void)
 	lbeentry.st_gss = false;
 #endif
 
-	lbeentry.st_state = STATE_UNDEFINED;
+	lbeentry.st_state = pre_auth ? STATE_AUTHENTICATING : STATE_UNDEFINED;
 	lbeentry.st_progress_command = PROGRESS_COMMAND_INVALID;
 	lbeentry.st_progress_command_target = InvalidOid;
 	lbeentry.st_query_id = UINT64CONST(0);
diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c
index 3876339ee1..f34e4a1643 100644
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -366,6 +366,9 @@ pg_stat_get_activity(PG_FUNCTION_ARGS)
 
 			switch (beentry->st_state)
 			{
+				case STATE_AUTHENTICATING:
+					values[4] = CStringGetTextDatum("authenticating");
+					break;
 				case STATE_IDLE:
 					values[4] = CStringGetTextDatum("idle");
 					break;
diff --git a/src/backend/utils/init/postinit.c b/src/backend/utils/init/postinit.c
index 25867c8bd5..83da2790b2 100644
--- a/src/backend/utils/init/postinit.c
+++ b/src/backend/utils/init/postinit.c
@@ -58,6 +58,7 @@
 #include "utils/builtins.h"
 #include "utils/fmgroids.h"
 #include "utils/guc_hooks.h"
+#include "utils/injection_point.h"
 #include "utils/memutils.h"
 #include "utils/pg_locale.h"
 #include "utils/portal.h"
@@ -878,6 +879,16 @@ InitPostgres(const char *in_dbname, Oid dboid,
 	{
 		/* normal multiuser case */
 		Assert(MyProcPort != NULL);
+
+		/*
+		 * Authentication can take a while, during which time we're holding a
+		 * transaction open. Fill in enough of a backend status so that DBAs can
+		 * observe what's going on. (The later call to pgstat_bestart() will
+		 * fill in the rest of the status after we've authenticated.)
+		 */
+		pgstat_bestart_pre_auth();
+		INJECTION_POINT("init-pre-auth");
+
 		PerformAuthentication(MyProcPort);
 		InitializeSessionUserId(username, useroid, false);
 		/* ensure that auth_method is actually valid, aka authn_id is not NULL */
diff --git a/src/include/utils/backend_status.h b/src/include/utils/backend_status.h
index 7b7f6f59d0..f673c6a6ac 100644
--- a/src/include/utils/backend_status.h
+++ b/src/include/utils/backend_status.h
@@ -24,6 +24,7 @@
 typedef enum BackendState
 {
 	STATE_UNDEFINED,
+	STATE_AUTHENTICATING,
 	STATE_IDLE,
 	STATE_RUNNING,
 	STATE_IDLEINTRANSACTION,
@@ -309,6 +310,7 @@ extern void CreateSharedBackendStatus(void);
 
 /* Initialization functions */
 extern void pgstat_beinit(void);
+extern void pgstat_bestart_pre_auth(void);
 extern void pgstat_bestart(void);
 
 extern void pgstat_clear_backend_activity_snapshot(void);
diff --git a/src/test/authentication/Makefile b/src/test/authentication/Makefile
index da0b71873a..7bbc3b6e57 100644
--- a/src/test/authentication/Makefile
+++ b/src/test/authentication/Makefile
@@ -13,6 +13,8 @@ subdir = src/test/authentication
 top_builddir = ../../..
 include $(top_builddir)/src/Makefile.global
 
+export enable_injection_points
+
 check:
 	$(prove_check)
 
diff --git a/src/test/authentication/meson.build b/src/test/authentication/meson.build
index 8f5688dcc1..09bad8f2b8 100644
--- a/src/test/authentication/meson.build
+++ b/src/test/authentication/meson.build
@@ -5,6 +5,9 @@ tests += {
   'sd': meson.current_source_dir(),
   'bd': meson.current_build_dir(),
   'tap': {
+    'env': {
+       'enable_injection_points': get_option('injection_points') ? 'yes' : 'no',
+    },
     'tests': [
       't/001_password.pl',
       't/002_saslprep.pl',
@@ -12,6 +15,7 @@ tests += {
       't/004_file_inclusion.pl',
       't/005_sspi.pl',
       't/006_login_trigger.pl',
+      't/007_injection_points.pl',
     ],
   },
 }
diff --git a/src/test/authentication/t/007_injection_points.pl b/src/test/authentication/t/007_injection_points.pl
new file mode 100644
index 0000000000..96ed691d93
--- /dev/null
+++ b/src/test/authentication/t/007_injection_points.pl
@@ -0,0 +1,73 @@
+
+# Copyright (c) 2021-2024, PostgreSQL Global Development Group
+
+# Tests requiring injection_points functionality, to check on behavior that
+# would otherwise race against authentication.
+
+use strict;
+use warnings FATAL => 'all';
+
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Time::HiRes qw(usleep);
+use Test::More;
+
+if ($ENV{enable_injection_points} ne 'yes')
+{
+	plan skip_all => 'Injection points not supported by this build';
+}
+
+my $node = PostgreSQL::Test::Cluster->new('primary');
+$node->init;
+$node->append_conf(
+	'postgresql.conf', q[
+log_connections = on
+]);
+
+$node->start;
+$node->safe_psql('postgres', 'CREATE EXTENSION injection_points');
+
+# Connect to the server and inject a waitpoint.
+my $psql = $node->background_psql('postgres');
+$psql->query_safe("SELECT injection_points_attach('init-pre-auth', 'wait')");
+
+# From this point on, all new connections will hang in authentication. Use the
+# $psql connection handle for server interaction.
+my $conn = $node->background_psql('postgres', wait => 0);
+
+# Wait for the connection to show up.
+my $pid;
+while (1)
+{
+	$pid = $psql->query(
+		"SELECT pid FROM pg_stat_activity WHERE state = 'authenticating';");
+	last if $pid ne "";
+
+	usleep(500_000);
+}
+
+note "backend $pid is authenticating";
+ok(1, 'authenticating connections are recorded in pg_stat_activity');
+
+# Detach the waitpoint and wait for the connection to complete.
+$psql->query_safe("SELECT injection_points_wakeup('init-pre-auth');");
+$conn->wait_connect();
+
+# Make sure the pgstat entry is updated eventually.
+while (1)
+{
+	my $state = $psql->query(
+		"SELECT state FROM pg_stat_activity WHERE pid = $pid;");
+	last if $state eq "idle";
+
+	note "state for backend $pid is '$state'; waiting for 'idle'...";
+	usleep(500_000);
+}
+
+ok(1, 'authenticated connections reach idle state in pg_stat_activity');
+
+$psql->query_safe("SELECT injection_points_detach('init-pre-auth');");
+$psql->quit();
+$conn->quit();
+
+done_testing();
-- 
2.34.1



^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible
@ 2024-08-29 20:44  Jacob Champion <[email protected]>
  parent: Noah Misch <[email protected]>
  1 sibling, 1 reply; 6+ messages in thread

From: Jacob Champion @ 2024-08-29 20:44 UTC (permalink / raw)
  To: Noah Misch <[email protected]>; +Cc: pgsql-hackers; Euler Taveira <[email protected]>

On Sun, Jun 30, 2024 at 10:48 AM Noah Misch <[email protected]> wrote:v
> > Would anyone like me to be more aggressive, and create a pgstat entry
> > as soon as we have the opening transaction? Or... as soon as a
> > connection is made?
>
> All else being equal, I'd like backends to have one before taking any lmgr
> lock or snapshot.

v3-0003 pushes the pgstat creation as far back as I felt comfortable,
right after the PGPROC registration by InitProcessPhase2(). That
function does lock the ProcArray, but if it gets held forever due to
some bug, you won't be able to use pg_stat_activity to debug it
anyway. And with this ordering, pg_stat_get_activity() will be able to
retrieve the proc entry by PID without a race.

This approach ends up registering an early entry for more cases than
the original patchset. For example, autovacuum and other background
workers will now briefly get their own "authenticating" state, which
seems like it could potentially confuse people. Should I rename the
state, or am I overthinking it?

> You could release the xmin before calling PAM or LDAP.  If you've copied all
> relevant catalog content to local memory, that's fine to do.

I played with the xmin problem a little bit, but I've shelved it for
now. There's probably a way to do that safely; I just don't understand
enough about the invariants to do it. For example, there's a comment
later on that says

     * We established a catalog snapshot while reading pg_authid and/or
     * pg_database;

and I'm a little nervous about invalidating the snapshot halfway
through that process. Even if PAM and LDAP don't rely on pg_authid or
other shared catalogs today, shouldn't they be allowed to in the
future, without being coupled to InitPostgres implementation order?
And I don't think we can move the pg_database checks before
authentication.

As for the other patches, I'll ping Andrew about 0001, and 0004
remains in its original WIP state. Anyone excited about that wait
event idea?

Thanks!
--Jacob


Attachments:

  [application/octet-stream] v3-0002-Test-Cluster-let-background_psql-work-asynchronou.patch (3.1K, ../../CAOYmi+=1Y4HKATADR=WYOMhxCkRQpoxH2rY0t1An6A5su1Cw-w@mail.gmail.com/2-v3-0002-Test-Cluster-let-background_psql-work-asynchronou.patch)
  download | inline diff:
From 7f404f5ee8aad2a4286d5251a2712ce978ee3fc2 Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Mon, 8 Jul 2024 10:46:55 -0700
Subject: [PATCH v3 2/4] Test::Cluster: let background_psql() work
 asynchronously

Specifying `wait => 0` as a parameter to background_psql() causes it to
return immediately, which lets the client run code during connection.
(This is useful if, for example, connections are blocked on injected
waitpoints.) Clients later call ->wait_connect() manually to complete
the asynchronous connection.
---
 .../perl/PostgreSQL/Test/BackgroundPsql.pm    | 23 ++++++++++++++-----
 src/test/perl/PostgreSQL/Test/Cluster.pm      | 10 +++++++-
 2 files changed, 26 insertions(+), 7 deletions(-)

diff --git a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
index 2760e4bc8d..13489ee95e 100644
--- a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
+++ b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
@@ -81,7 +81,7 @@ string. For C<interactive> sessions, IO::Pty is required.
 sub new
 {
 	my $class = shift;
-	my ($interactive, $psql_params, $timeout) = @_;
+	my ($interactive, $psql_params, $timeout, $wait) = @_;
 	my $psql = {
 		'stdin' => '',
 		'stdout' => '',
@@ -119,14 +119,25 @@ sub new
 
 	my $self = bless $psql, $class;
 
-	$self->_wait_connect();
+	$wait = 1 unless defined($wait);
+	if ($wait)
+	{
+		$self->wait_connect();
+	}
 
 	return $self;
 }
 
-# Internal routine for awaiting psql starting up and being ready to consume
-# input.
-sub _wait_connect
+=pod
+
+=item $session->wait_connect
+
+Returns once psql has started up and is ready to consume input.  This is called
+automatically for clients unless requested otherwise in the constructor.
+
+=cut
+
+sub wait_connect
 {
 	my ($self) = @_;
 
@@ -187,7 +198,7 @@ sub reconnect_and_clear
 	$self->{stdin} = '';
 	$self->{stdout} = '';
 
-	$self->_wait_connect();
+	$self->wait_connect();
 }
 
 =pod
diff --git a/src/test/perl/PostgreSQL/Test/Cluster.pm b/src/test/perl/PostgreSQL/Test/Cluster.pm
index fe6ebf10f7..134ddfaa70 100644
--- a/src/test/perl/PostgreSQL/Test/Cluster.pm
+++ b/src/test/perl/PostgreSQL/Test/Cluster.pm
@@ -2191,6 +2191,12 @@ connection.
 
 If given, it must be an array reference containing additional parameters to B<psql>.
 
+=item wait => 1
+
+By default, this method will not return until connection has completed (or
+failed).  Set B<wait> to 0 to return immediately instead.  (Clients can call the
+session's C<wait_connect> method manually when needed.)
+
 =back
 
 =cut
@@ -2214,13 +2220,15 @@ sub background_psql
 		'-');
 
 	$params{on_error_stop} = 1 unless defined $params{on_error_stop};
+	$params{wait} = 1 unless defined $params{wait};
 	$timeout = $params{timeout} if defined $params{timeout};
 
 	push @psql_params, '-v', 'ON_ERROR_STOP=1' if $params{on_error_stop};
 	push @psql_params, @{ $params{extra_params} }
 	  if defined $params{extra_params};
 
-	return PostgreSQL::Test::BackgroundPsql->new(0, \@psql_params, $timeout);
+	return PostgreSQL::Test::BackgroundPsql->new(0, \@psql_params, $timeout,
+		$params{wait});
 }
 
 =pod
-- 
2.34.1



  [application/octet-stream] v3-0001-BackgroundPsql-handle-empty-query-results.patch (2.6K, ../../CAOYmi+=1Y4HKATADR=WYOMhxCkRQpoxH2rY0t1An6A5su1Cw-w@mail.gmail.com/3-v3-0001-BackgroundPsql-handle-empty-query-results.patch)
  download | inline diff:
From 8f9315949e997e24f68e41d7450f7883f46bf54e Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Mon, 8 Jul 2024 10:11:56 -0700
Subject: [PATCH v3 1/4] BackgroundPsql: handle empty query results

There won't be a newline at the end of an empty query result. (Before
this fix, the $banner showed up in the result, leading to confusing
debugging sessions.)

recovery/t/037_invalid_database was relying on the non-empty query
results, so I have switched those cases to use "bare" calls to
query_safe() instead.
---
 src/test/perl/PostgreSQL/Test/BackgroundPsql.pm |  2 +-
 src/test/recovery/t/037_invalid_database.pl     | 12 ++++--------
 2 files changed, 5 insertions(+), 9 deletions(-)

diff --git a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
index 3c2aca1c5d..2760e4bc8d 100644
--- a/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
+++ b/src/test/perl/PostgreSQL/Test/BackgroundPsql.pm
@@ -223,7 +223,7 @@ sub query
 	$output = $self->{stdout};
 
 	# remove banner again, our caller doesn't care
-	$output =~ s/\n$banner\n$//s;
+	$output =~ s/\n?$banner\n$//s;
 
 	# clear out output for the next query
 	$self->{stdout} = '';
diff --git a/src/test/recovery/t/037_invalid_database.pl b/src/test/recovery/t/037_invalid_database.pl
index 47f524be4c..954c3684a9 100644
--- a/src/test/recovery/t/037_invalid_database.pl
+++ b/src/test/recovery/t/037_invalid_database.pl
@@ -93,13 +93,12 @@ my $bgpsql = $node->background_psql('postgres', on_error_stop => 0);
 my $pid = $bgpsql->query('SELECT pg_backend_pid()');
 
 # create the database, prevent drop database via lock held by a 2PC transaction
-ok( $bgpsql->query_safe(
+$bgpsql->query_safe(
 		qq(
   CREATE DATABASE regression_invalid_interrupt;
   BEGIN;
   LOCK pg_tablespace;
-  PREPARE TRANSACTION 'lock_tblspc';)),
-	"blocked DROP DATABASE completion");
+  PREPARE TRANSACTION 'lock_tblspc';));
 
 # Try to drop. This will wait due to the still held lock.
 $bgpsql->query_until(qr//, "DROP DATABASE regression_invalid_interrupt;\n");
@@ -126,11 +125,8 @@ is($node->psql('regression_invalid_interrupt', ''),
 
 # To properly drop the database, we need to release the lock previously preventing
 # doing so.
-ok($bgpsql->query_safe(qq(ROLLBACK PREPARED 'lock_tblspc')),
-	"unblock DROP DATABASE");
-
-ok($bgpsql->query(qq(DROP DATABASE regression_invalid_interrupt)),
-	"DROP DATABASE invalid_interrupt");
+$bgpsql->query_safe(qq(ROLLBACK PREPARED 'lock_tblspc'));
+$bgpsql->query_safe(qq(DROP DATABASE regression_invalid_interrupt));
 
 $bgpsql->quit();
 
-- 
2.34.1



  [application/octet-stream] v3-0003-pgstat-report-in-earlier-with-STATE_AUTHENTICATIN.patch (9.2K, ../../CAOYmi+=1Y4HKATADR=WYOMhxCkRQpoxH2rY0t1An6A5su1Cw-w@mail.gmail.com/4-v3-0003-pgstat-report-in-earlier-with-STATE_AUTHENTICATIN.patch)
  download | inline diff:
From a7a7551d09ccbd90bbbc26b75e3be718ec6a085e Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Fri, 3 May 2024 15:54:58 -0700
Subject: [PATCH v3 3/4] pgstat: report in earlier with STATE_AUTHENTICATING

Add pgstat_bestart_pre_auth(), which reports an 'authenticating' state
while waiting for backend initialization and client authentication to
complete. Since we hold a transaction open for a good amount of that,
and some authentication methods call out to external systems, having a
pg_stat_activity entry helps DBAs debug when things go badly wrong.
---
 src/backend/utils/activity/backend_status.c   | 37 +++++++++-
 src/backend/utils/adt/pgstatfuncs.c           |  3 +
 src/backend/utils/init/postinit.c             | 20 ++++-
 src/include/utils/backend_status.h            |  2 +
 src/test/authentication/Makefile              |  2 +
 src/test/authentication/meson.build           |  4 +
 .../authentication/t/007_injection_points.pl  | 73 +++++++++++++++++++
 7 files changed, 134 insertions(+), 7 deletions(-)
 create mode 100644 src/test/authentication/t/007_injection_points.pl

diff --git a/src/backend/utils/activity/backend_status.c b/src/backend/utils/activity/backend_status.c
index 34a55e2177..d693b2dff7 100644
--- a/src/backend/utils/activity/backend_status.c
+++ b/src/backend/utils/activity/backend_status.c
@@ -71,6 +71,7 @@ static int	localNumBackends = 0;
 static MemoryContext backendStatusSnapContext;
 
 
+static void pgstat_bestart_internal(bool pre_auth);
 static void pgstat_beshutdown_hook(int code, Datum arg);
 static void pgstat_read_current_status(void);
 static void pgstat_setup_backend_status_context(void);
@@ -271,6 +272,34 @@ pgstat_beinit(void)
  */
 void
 pgstat_bestart(void)
+{
+	pgstat_bestart_internal(false);
+}
+
+
+/* ----------
+ * pgstat_bestart_pre_auth() -
+ *
+ *	Like pgstat_beinit(), above, but it's designed to be called before
+ *	authentication has been performed (so we have no user or database IDs).
+ *	Called from InitPostgres.
+ *----------
+ */
+void
+pgstat_bestart_pre_auth(void)
+{
+	pgstat_bestart_internal(true);
+}
+
+
+/* ----------
+ * pgstat_bestart_internal() -
+ *
+ *	Implementation of both flavors of pgstat_bestart().
+ *----------
+ */
+static void
+pgstat_bestart_internal(bool pre_auth)
 {
 	volatile PgBackendStatus *vbeentry = MyBEEntry;
 	PgBackendStatus lbeentry;
@@ -320,9 +349,9 @@ pgstat_bestart(void)
 	lbeentry.st_databaseid = MyDatabaseId;
 
 	/* We have userid for client-backends, wal-sender and bgworker processes */
-	if (lbeentry.st_backendType == B_BACKEND
-		|| lbeentry.st_backendType == B_WAL_SENDER
-		|| lbeentry.st_backendType == B_BG_WORKER)
+	if (!pre_auth && (lbeentry.st_backendType == B_BACKEND
+					  || lbeentry.st_backendType == B_WAL_SENDER
+					  || lbeentry.st_backendType == B_BG_WORKER))
 		lbeentry.st_userid = GetSessionUserId();
 	else
 		lbeentry.st_userid = InvalidOid;
@@ -377,7 +406,7 @@ pgstat_bestart(void)
 	lbeentry.st_gss = false;
 #endif
 
-	lbeentry.st_state = STATE_UNDEFINED;
+	lbeentry.st_state = pre_auth ? STATE_AUTHENTICATING : STATE_UNDEFINED;
 	lbeentry.st_progress_command = PROGRESS_COMMAND_INVALID;
 	lbeentry.st_progress_command_target = InvalidOid;
 	lbeentry.st_query_id = UINT64CONST(0);
diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c
index 3221137123..b007f0d5a1 100644
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -366,6 +366,9 @@ pg_stat_get_activity(PG_FUNCTION_ARGS)
 
 			switch (beentry->st_state)
 			{
+				case STATE_AUTHENTICATING:
+					values[4] = CStringGetTextDatum("authenticating");
+					break;
 				case STATE_IDLE:
 					values[4] = CStringGetTextDatum("idle");
 					break;
diff --git a/src/backend/utils/init/postinit.c b/src/backend/utils/init/postinit.c
index 3b50ce19a2..e2034829e4 100644
--- a/src/backend/utils/init/postinit.c
+++ b/src/backend/utils/init/postinit.c
@@ -58,6 +58,7 @@
 #include "utils/builtins.h"
 #include "utils/fmgroids.h"
 #include "utils/guc_hooks.h"
+#include "utils/injection_point.h"
 #include "utils/memutils.h"
 #include "utils/pg_locale.h"
 #include "utils/portal.h"
@@ -680,6 +681,21 @@ InitPostgres(const char *in_dbname, Oid dboid,
 	 */
 	InitProcessPhase2();
 
+	/* Initialize status reporting */
+	pgstat_beinit();
+
+	/*
+	 * This is a convenient time to sketch in a partial pgstat entry. That way,
+	 * if LWLocks or third-party authentication should happen to hang, the DBA
+	 * will still be able to see what's going on. (A later call to
+	 * pgstat_bestart() will fill in the rest of the status.)
+	 */
+	if (!bootstrap)
+	{
+		pgstat_bestart_pre_auth();
+		INJECTION_POINT("init-pre-auth");
+	}
+
 	/*
 	 * Initialize my entry in the shared-invalidation manager's array of
 	 * per-backend data.
@@ -748,9 +764,6 @@ InitPostgres(const char *in_dbname, Oid dboid,
 	/* Initialize portal manager */
 	EnablePortalManager();
 
-	/* Initialize status reporting */
-	pgstat_beinit();
-
 	/*
 	 * Load relcache entries for the shared system catalogs.  This must create
 	 * at least entries for pg_database and catalogs used for authentication.
@@ -848,6 +861,7 @@ InitPostgres(const char *in_dbname, Oid dboid,
 	{
 		/* normal multiuser case */
 		Assert(MyProcPort != NULL);
+
 		PerformAuthentication(MyProcPort);
 		InitializeSessionUserId(username, useroid, false);
 		/* ensure that auth_method is actually valid, aka authn_id is not NULL */
diff --git a/src/include/utils/backend_status.h b/src/include/utils/backend_status.h
index 97874300c3..18f79bd3ad 100644
--- a/src/include/utils/backend_status.h
+++ b/src/include/utils/backend_status.h
@@ -24,6 +24,7 @@
 typedef enum BackendState
 {
 	STATE_UNDEFINED,
+	STATE_AUTHENTICATING,
 	STATE_IDLE,
 	STATE_RUNNING,
 	STATE_IDLEINTRANSACTION,
@@ -309,6 +310,7 @@ extern void BackendStatusShmemInit(void);
 
 /* Initialization functions */
 extern void pgstat_beinit(void);
+extern void pgstat_bestart_pre_auth(void);
 extern void pgstat_bestart(void);
 
 extern void pgstat_clear_backend_activity_snapshot(void);
diff --git a/src/test/authentication/Makefile b/src/test/authentication/Makefile
index da0b71873a..7bbc3b6e57 100644
--- a/src/test/authentication/Makefile
+++ b/src/test/authentication/Makefile
@@ -13,6 +13,8 @@ subdir = src/test/authentication
 top_builddir = ../../..
 include $(top_builddir)/src/Makefile.global
 
+export enable_injection_points
+
 check:
 	$(prove_check)
 
diff --git a/src/test/authentication/meson.build b/src/test/authentication/meson.build
index 8f5688dcc1..09bad8f2b8 100644
--- a/src/test/authentication/meson.build
+++ b/src/test/authentication/meson.build
@@ -5,6 +5,9 @@ tests += {
   'sd': meson.current_source_dir(),
   'bd': meson.current_build_dir(),
   'tap': {
+    'env': {
+       'enable_injection_points': get_option('injection_points') ? 'yes' : 'no',
+    },
     'tests': [
       't/001_password.pl',
       't/002_saslprep.pl',
@@ -12,6 +15,7 @@ tests += {
       't/004_file_inclusion.pl',
       't/005_sspi.pl',
       't/006_login_trigger.pl',
+      't/007_injection_points.pl',
     ],
   },
 }
diff --git a/src/test/authentication/t/007_injection_points.pl b/src/test/authentication/t/007_injection_points.pl
new file mode 100644
index 0000000000..96ed691d93
--- /dev/null
+++ b/src/test/authentication/t/007_injection_points.pl
@@ -0,0 +1,73 @@
+
+# Copyright (c) 2021-2024, PostgreSQL Global Development Group
+
+# Tests requiring injection_points functionality, to check on behavior that
+# would otherwise race against authentication.
+
+use strict;
+use warnings FATAL => 'all';
+
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Time::HiRes qw(usleep);
+use Test::More;
+
+if ($ENV{enable_injection_points} ne 'yes')
+{
+	plan skip_all => 'Injection points not supported by this build';
+}
+
+my $node = PostgreSQL::Test::Cluster->new('primary');
+$node->init;
+$node->append_conf(
+	'postgresql.conf', q[
+log_connections = on
+]);
+
+$node->start;
+$node->safe_psql('postgres', 'CREATE EXTENSION injection_points');
+
+# Connect to the server and inject a waitpoint.
+my $psql = $node->background_psql('postgres');
+$psql->query_safe("SELECT injection_points_attach('init-pre-auth', 'wait')");
+
+# From this point on, all new connections will hang in authentication. Use the
+# $psql connection handle for server interaction.
+my $conn = $node->background_psql('postgres', wait => 0);
+
+# Wait for the connection to show up.
+my $pid;
+while (1)
+{
+	$pid = $psql->query(
+		"SELECT pid FROM pg_stat_activity WHERE state = 'authenticating';");
+	last if $pid ne "";
+
+	usleep(500_000);
+}
+
+note "backend $pid is authenticating";
+ok(1, 'authenticating connections are recorded in pg_stat_activity');
+
+# Detach the waitpoint and wait for the connection to complete.
+$psql->query_safe("SELECT injection_points_wakeup('init-pre-auth');");
+$conn->wait_connect();
+
+# Make sure the pgstat entry is updated eventually.
+while (1)
+{
+	my $state = $psql->query(
+		"SELECT state FROM pg_stat_activity WHERE pid = $pid;");
+	last if $state eq "idle";
+
+	note "state for backend $pid is '$state'; waiting for 'idle'...";
+	usleep(500_000);
+}
+
+ok(1, 'authenticated connections reach idle state in pg_stat_activity');
+
+$psql->query_safe("SELECT injection_points_detach('init-pre-auth');");
+$psql->quit();
+$conn->quit();
+
+done_testing();
-- 
2.34.1



  [application/octet-stream] v3-0004-WIP-report-external-auth-calls-as-wait-events.patch (7.5K, ../../CAOYmi+=1Y4HKATADR=WYOMhxCkRQpoxH2rY0t1An6A5su1Cw-w@mail.gmail.com/5-v3-0004-WIP-report-external-auth-calls-as-wait-events.patch)
  download | inline diff:
From 5c85c3e0e99cfb2beaa4f0e0a4a7e1cc4ab91af3 Mon Sep 17 00:00:00 2001
From: Jacob Champion <[email protected]>
Date: Fri, 3 May 2024 15:58:23 -0700
Subject: [PATCH v3 4/4] WIP: report external auth calls as wait events

Introduce new WAIT_EVENT_AUTHN_* types for various external
authentication systems, to make it obvious what's going wrong if one of
those systems hangs.

TODO:
- don't abuse the IPC wait event group like this
- test
---
 src/backend/libpq/auth.c                      | 54 +++++++++++++++----
 .../utils/activity/wait_event_names.txt       |  5 ++
 2 files changed, 49 insertions(+), 10 deletions(-)

diff --git a/src/backend/libpq/auth.c b/src/backend/libpq/auth.c
index 2b607c5270..bda80e88f9 100644
--- a/src/backend/libpq/auth.c
+++ b/src/backend/libpq/auth.c
@@ -38,6 +38,7 @@
 #include "replication/walsender.h"
 #include "storage/ipc.h"
 #include "utils/memutils.h"
+#include "utils/wait_event.h"
 
 /*----------------------------------------------------------------
  * Global authentication functions
@@ -1000,6 +1001,7 @@ pg_GSS_recvauth(Port *port)
 		elog(DEBUG4, "processing received GSS token of length %u",
 			 (unsigned int) gbuf.length);
 
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_GSSAPI);
 		maj_stat = gss_accept_sec_context(&min_stat,
 										  &port->gss->ctx,
 										  port->gss->cred,
@@ -1011,6 +1013,7 @@ pg_GSS_recvauth(Port *port)
 										  &gflags,
 										  NULL,
 										  pg_gss_accept_delegation ? &delegated_creds : NULL);
+		pgstat_report_wait_end();
 
 		/* gbuf no longer used */
 		pfree(buf.data);
@@ -1222,6 +1225,7 @@ pg_SSPI_recvauth(Port *port)
 	/*
 	 * Acquire a handle to the server credentials.
 	 */
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
 	r = AcquireCredentialsHandle(NULL,
 								 "negotiate",
 								 SECPKG_CRED_INBOUND,
@@ -1231,6 +1235,8 @@ pg_SSPI_recvauth(Port *port)
 								 NULL,
 								 &sspicred,
 								 &expiry);
+	pgstat_report_wait_end();
+
 	if (r != SEC_E_OK)
 		pg_SSPI_error(ERROR, _("could not acquire SSPI credentials"), r);
 
@@ -1296,6 +1302,7 @@ pg_SSPI_recvauth(Port *port)
 		elog(DEBUG4, "processing received SSPI token of length %u",
 			 (unsigned int) buf.len);
 
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
 		r = AcceptSecurityContext(&sspicred,
 								  sspictx,
 								  &inbuf,
@@ -1305,6 +1312,7 @@ pg_SSPI_recvauth(Port *port)
 								  &outbuf,
 								  &contextattr,
 								  NULL);
+		pgstat_report_wait_end();
 
 		/* input buffer no longer used */
 		pfree(buf.data);
@@ -1402,19 +1410,25 @@ pg_SSPI_recvauth(Port *port)
 
 	CloseHandle(token);
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
 	if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize,
 						  domainname, &domainnamesize, &accountnameuse))
 		ereport(ERROR,
 				(errmsg_internal("could not look up account SID: error code %lu",
 								 GetLastError())));
+	pgstat_report_wait_end();
 
 	free(tokenuser);
 
 	if (!port->hba->compat_realm)
 	{
-		int			status = pg_SSPI_make_upn(accountname, sizeof(accountname),
-											  domainname, sizeof(domainname),
-											  port->hba->upn_username);
+		int			status;
+
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_SSPI);
+		status = pg_SSPI_make_upn(accountname, sizeof(accountname),
+								  domainname, sizeof(domainname),
+								  port->hba->upn_username);
+		pgstat_report_wait_end();
 
 		if (status != STATUS_OK)
 			/* Error already reported from pg_SSPI_make_upn */
@@ -2114,7 +2128,9 @@ CheckPAMAuth(Port *port, const char *user, const char *password)
 		return STATUS_ERROR;
 	}
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_PAM);
 	retval = pam_authenticate(pamh, 0);
+	pgstat_report_wait_end();
 
 	if (retval != PAM_SUCCESS)
 	{
@@ -2127,7 +2143,9 @@ CheckPAMAuth(Port *port, const char *user, const char *password)
 		return pam_no_password ? STATUS_EOF : STATUS_ERROR;
 	}
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_PAM);
 	retval = pam_acct_mgmt(pamh, 0);
+	pgstat_report_wait_end();
 
 	if (retval != PAM_SUCCESS)
 	{
@@ -2478,7 +2496,11 @@ CheckLDAPAuth(Port *port)
 	if (passwd == NULL)
 		return STATUS_EOF;		/* client wouldn't send password */
 
-	if (InitializeLDAPConnection(port, &ldap) == STATUS_ERROR)
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
+	r = InitializeLDAPConnection(port, &ldap);
+	pgstat_report_wait_end();
+
+	if (r == STATUS_ERROR)
 	{
 		/* Error message already sent */
 		pfree(passwd);
@@ -2525,9 +2547,12 @@ CheckLDAPAuth(Port *port)
 		 * Bind with a pre-defined username/password (if available) for
 		 * searching. If none is specified, this turns into an anonymous bind.
 		 */
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
 		r = ldap_simple_bind_s(ldap,
 							   port->hba->ldapbinddn ? port->hba->ldapbinddn : "",
 							   port->hba->ldapbindpasswd ? ldap_password_hook(port->hba->ldapbindpasswd) : "");
+		pgstat_report_wait_end();
+
 		if (r != LDAP_SUCCESS)
 		{
 			ereport(LOG,
@@ -2550,6 +2575,8 @@ CheckLDAPAuth(Port *port)
 			filter = psprintf("(uid=%s)", port->user_name);
 
 		search_message = NULL;
+
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
 		r = ldap_search_s(ldap,
 						  port->hba->ldapbasedn,
 						  port->hba->ldapscope,
@@ -2557,6 +2584,7 @@ CheckLDAPAuth(Port *port)
 						  attributes,
 						  0,
 						  &search_message);
+		pgstat_report_wait_end();
 
 		if (r != LDAP_SUCCESS)
 		{
@@ -2625,7 +2653,9 @@ CheckLDAPAuth(Port *port)
 							port->user_name,
 							port->hba->ldapsuffix ? port->hba->ldapsuffix : "");
 
+	pgstat_report_wait_start(WAIT_EVENT_AUTHN_LDAP);
 	r = ldap_simple_bind_s(ldap, fulluser, passwd);
+	pgstat_report_wait_end();
 
 	if (r != LDAP_SUCCESS)
 	{
@@ -2885,12 +2915,16 @@ CheckRADIUSAuth(Port *port)
 	identifiers = list_head(port->hba->radiusidentifiers);
 	foreach(server, port->hba->radiusservers)
 	{
-		int			ret = PerformRadiusTransaction(lfirst(server),
-												   lfirst(secrets),
-												   radiusports ? lfirst(radiusports) : NULL,
-												   identifiers ? lfirst(identifiers) : NULL,
-												   port->user_name,
-												   passwd);
+		int			ret;
+
+		pgstat_report_wait_start(WAIT_EVENT_AUTHN_RADIUS);
+		ret = PerformRadiusTransaction(lfirst(server),
+									   lfirst(secrets),
+									   radiusports ? lfirst(radiusports) : NULL,
+									   identifiers ? lfirst(identifiers) : NULL,
+									   port->user_name,
+									   passwd);
+		pgstat_report_wait_end();
 
 		/*------
 		 * STATUS_OK = Login OK
diff --git a/src/backend/utils/activity/wait_event_names.txt b/src/backend/utils/activity/wait_event_names.txt
index 8efb4044d6..6ce81edc33 100644
--- a/src/backend/utils/activity/wait_event_names.txt
+++ b/src/backend/utils/activity/wait_event_names.txt
@@ -105,6 +105,11 @@ Section: ClassName - WaitEventIPC
 APPEND_READY	"Waiting for subplan nodes of an <literal>Append</literal> plan node to be ready."
 ARCHIVE_CLEANUP_COMMAND	"Waiting for <xref linkend="guc-archive-cleanup-command"/> to complete."
 ARCHIVE_COMMAND	"Waiting for <xref linkend="guc-archive-command"/> to complete."
+AUTHN_GSSAPI	"Waiting for a response from a Kerberos server via GSSAPI."
+AUTHN_LDAP	"Waiting for a response from an LDAP server."
+AUTHN_PAM	"Waiting for a response from the local PAM service."
+AUTHN_RADIUS	"Waiting for a response from a RADIUS server."
+AUTHN_SSPI	"Waiting for a response from a Windows security provider via SSPI."
 BACKEND_TERMINATION	"Waiting for the termination of another backend."
 BACKUP_WAIT_WAL_ARCHIVE	"Waiting for WAL files required for a backup to be successfully archived."
 BGWORKER_SHUTDOWN	"Waiting for background worker to shut down."
-- 
2.34.1



^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible
@ 2024-08-30 20:10  Andrew Dunstan <[email protected]>
  parent: Jacob Champion <[email protected]>
  0 siblings, 1 reply; 6+ messages in thread

From: Andrew Dunstan @ 2024-08-30 20:10 UTC (permalink / raw)
  To: Jacob Champion <[email protected]>; Noah Misch <[email protected]>; +Cc: pgsql-hackers; Euler Taveira <[email protected]>


On 2024-08-29 Th 4:44 PM, Jacob Champion wrote:
> As for the other patches, I'll ping Andrew about 0001,


Patch 0001 looks sane to me.


cheers


andrew

--
Andrew Dunstan
EDB:https://www.enterprisedb.com


^ permalink  raw  reply  [nested|flat] 6+ messages in thread

* Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible
@ 2024-09-02 00:10  Michael Paquier <[email protected]>
  parent: Andrew Dunstan <[email protected]>
  0 siblings, 0 replies; 6+ messages in thread

From: Michael Paquier @ 2024-09-02 00:10 UTC (permalink / raw)
  To: Andrew Dunstan <[email protected]>; +Cc: Jacob Champion <[email protected]>; Noah Misch <[email protected]>; pgsql-hackers; Euler Taveira <[email protected]>

On Fri, Aug 30, 2024 at 04:10:32PM -0400, Andrew Dunstan wrote:
> 
> On 2024-08-29 Th 4:44 PM, Jacob Champion wrote:
> > As for the other patches, I'll ping Andrew about 0001,
> 
> 
> Patch 0001 looks sane to me.

So does 0002 to me.  I'm not much a fan of the addition of
pgstat_bestart_pre_auth(), which is just a shortcut to set a different
state in the backend entry to tell that it is authenticating.  Is
authenticating the term for this state of the process startups,
actually?  Could it be more transparent to use a "startup" or
"starting"" state instead that gets also used by pgstat_bestart() in
the case of the patch where !pre_auth?

The addition of the new wait event states in 0004 is a good idea,
indeed, and these can be seen in pg_stat_activity once we get out of
PGSTAT_END_WRITE_ACTIVITY() (err.. Right?).
--
Michael


Attachments:

  [application/pgp-signature] signature.asc (833B, ../../[email protected]/2-signature.asc)
  download

^ permalink  raw  reply  [nested|flat] 6+ messages in thread

end of thread, other threads:[~2024-09-02 00:10 UTC | newest]

Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2021-03-11 23:36 [PATCH 4/8] wal_compression_method: default to zlib.. Justin Pryzby <[email protected]>
2024-06-30 17:48 Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible Noah Misch <[email protected]>
2024-07-08 21:09 ` Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible Jacob Champion <[email protected]>
2024-08-29 20:44 ` Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible Jacob Champion <[email protected]>
2024-08-30 20:10   ` Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible Andrew Dunstan <[email protected]>
2024-09-02 00:10     ` Re: [PATCH] pg_stat_activity: make slow/hanging authentication more visible Michael Paquier <[email protected]>

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox