From 7e12b52bfbf2b00f8e632c3888892253d060c641 Mon Sep 17 00:00:00 2001 From: Zsolt Parragi Date: Wed, 11 Feb 2026 19:28:05 +0100 Subject: [PATCH] Improve OAuth discovery logging Currently when the client sends an empty OAuth token to request the issuer URL, the server logs the attempt with FATAL: OAuth bearer authentication failed for user Which is quite confusing, as this is an expected part of the OAuth authentication flow and not an error at all. This in practice results in the server spamming the log with these messages, which are difficult to separate from real (OAuth) authentication failures. This patch improves this by handling the situation properly in the SASL/Oauth code, by introducing a new SASL authentication status, PG_SASL_EXCHANGE_RESTART. The expectation is that authentication mechanisms can set this if they request a restart of the authentication flow. Restart currently requires starting with a new connection, so this simply sets STATUS_EOF. The above prevents logging a fatal error at the end, so instead the OAuth exchange code outputs a simple log message instead. --- src/backend/libpq/auth-oauth.c | 17 +++++++++++++++-- src/backend/libpq/auth-sasl.c | 5 ++++- src/include/libpq/sasl.h | 1 + .../modules/oauth_validator/t/001_server.pl | 8 ++++++-- 4 files changed, 26 insertions(+), 5 deletions(-) diff --git a/src/backend/libpq/auth-oauth.c b/src/backend/libpq/auth-oauth.c index 11365048951..c8bc90fd8cb 100644 --- a/src/backend/libpq/auth-oauth.c +++ b/src/backend/libpq/auth-oauth.c @@ -68,6 +68,7 @@ struct oauth_ctx Port *port; const char *issuer; const char *scope; + bool discovery; }; static char *sanitize_char(char c); @@ -194,6 +195,15 @@ oauth_exchange(void *opaq, const char *input, int inputlen, /* The (failed) handshake is now complete. */ ctx->state = OAUTH_STATE_FINISHED; + + if (ctx->discovery) + { + ereport(LOG, + errmsg("OAuth issuer discovery requested by user \"%s\"", + ctx->port->user_name)); + return PG_SASL_EXCHANGE_RESTART; + } + return PG_SASL_EXCHANGE_FAILURE; default: @@ -279,6 +289,9 @@ oauth_exchange(void *opaq, const char *input, int inputlen, errmsg("malformed OAUTHBEARER message"), errdetail("Message contains additional data after the final terminator.")); + if (auth[0] == '\0') + ctx->discovery = true; + if (!validate(ctx->port, auth)) { generate_error_response(ctx, output, outputlen); @@ -572,8 +585,8 @@ validate_token_format(const char *header) * authentication parameters. The client expects it to fail; there's * no need to make any extra noise in the logs. * - * TODO: should we find a way to return STATUS_EOF at the top level, - * to suppress the authentication error entirely? + * The caller detects this case and returns + * PG_SASL_EXCHANGE_RESTART to suppress the authentication FATAL. */ return NULL; } diff --git a/src/backend/libpq/auth-sasl.c b/src/backend/libpq/auth-sasl.c index 36cb748d927..29f3839453b 100644 --- a/src/backend/libpq/auth-sasl.c +++ b/src/backend/libpq/auth-sasl.c @@ -167,7 +167,7 @@ CheckSASLAuth(const pg_be_sasl_mech *mech, Port *port, char *shadow_pass, * PG_SASL_EXCHANGE_FAILURE with some output is forbidden by SASL. * Make sure here that the mechanism used got that right. */ - if (result == PG_SASL_EXCHANGE_FAILURE) + if (result == PG_SASL_EXCHANGE_FAILURE || result == PG_SASL_EXCHANGE_RESTART) elog(ERROR, "output message found after SASL exchange failure"); /* @@ -184,6 +184,9 @@ CheckSASLAuth(const pg_be_sasl_mech *mech, Port *port, char *shadow_pass, } } while (result == PG_SASL_EXCHANGE_CONTINUE); + if (result == PG_SASL_EXCHANGE_RESTART) + return STATUS_EOF; + /* Oops, Something bad happened */ if (result != PG_SASL_EXCHANGE_SUCCESS) { diff --git a/src/include/libpq/sasl.h b/src/include/libpq/sasl.h index 1e8ec7d6293..4d96afde198 100644 --- a/src/include/libpq/sasl.h +++ b/src/include/libpq/sasl.h @@ -25,6 +25,7 @@ #define PG_SASL_EXCHANGE_CONTINUE 0 #define PG_SASL_EXCHANGE_SUCCESS 1 #define PG_SASL_EXCHANGE_FAILURE 2 +#define PG_SASL_EXCHANGE_RESTART 3 /* * Maximum accepted size of SASL messages. diff --git a/src/test/modules/oauth_validator/t/001_server.pl b/src/test/modules/oauth_validator/t/001_server.pl index 6b649c0b06f..9d96692312f 100644 --- a/src/test/modules/oauth_validator/t/001_server.pl +++ b/src/test/modules/oauth_validator/t/001_server.pl @@ -114,11 +114,13 @@ $node->connect_ok( expected_stderr => qr@Visit https://example\.com/ and enter the code: postgresuser@, log_like => [ + qr/OAuth issuer discovery requested by user "$user"/, qr/oauth_validator: token="9243959234", role="$user"/, qr/oauth_validator: issuer="\Q$issuer\E", scope="openid postgres"/, qr/connection authenticated: identity="test" method=oauth/, qr/connection authorized/, - ]); + ], + log_unlike => [qr/FATAL.*OAuth bearer authentication failed/]); # The /alternate issuer uses slightly different parameters, along with an # OAuth-style discovery document. @@ -129,11 +131,13 @@ $node->connect_ok( expected_stderr => qr@Visit https://example\.org/ and enter the code: postgresuser@, log_like => [ + qr/OAuth issuer discovery requested by user "$user"/, qr/oauth_validator: token="9243959234-alt", role="$user"/, qr|oauth_validator: issuer="\Q$issuer/.well-known/oauth-authorization-server/alternate\E", scope="openid postgres alt"|, qr/connection authenticated: identity="testalt" method=oauth/, qr/connection authorized/, - ]); + ], + log_unlike => [qr/FATAL.*OAuth bearer authentication failed/]); # The issuer linked by the server must match the client's oauth_issuer setting. $node->connect_fails( -- 2.43.0