Re: [PATCH] Log details for client certificate failures

[Ranier Vilela]

Em qua., 5 de out. de 2022 às 09:19, Ranier Vilela 
escreveu:

> Hi,
> I think that 9d58bf
> ,
> left a tiny oversight.
>
> guc_strdup uses strdup, so must be cleaned by free not pfree.
> IMO, can be used once free call too.
>
Sorry, my fault.
Please ignore this.

regards,
Ranier Vilela

Re: [PATCH] Log details for client certificate failures

[Ranier Vilela]

Hi,
I think that 9d58bf
,
left a tiny oversight.

guc_strdup uses strdup, so must be cleaned by free not pfree.
IMO, can be used once free call too.

regards,
Ranier Vilela


simplifies_and_use_free_variable.patch
Description: Binary data

Re: [PATCH] Log details for client certificate failures

[Masahiko Sawada]

On Sat, Oct 1, 2022 at 7:53 PM Peter Eisentraut
 wrote:
>
> On 29.09.22 06:52, Masahiko Sawada wrote:
> > While this seems a future-proof idea, I wonder if it might be overkill
> > since we don't need to worry about accumulation of leaked memory in
> > this case. Given that only check_cluter_name is the case where we
> > found a small memory leak, I think it's adequate to fix it.
> >
> > Fixing this issue suppresses the valgrind's complaint but since the
> > boot value of cluster_name is "" the memory leak we can avoid is only
> > 1 byte.
>
> I have committed this.  I think it's better to keep the code locally
> robust and not to have to rely on complex analysis of how GUC memory
> management works.

Thanks! Agreed.

Regards,

-- 
Masahiko Sawada
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 29.09.22 06:52, Masahiko Sawada wrote:

While this seems a future-proof idea, I wonder if it might be overkill
since we don't need to worry about accumulation of leaked memory in
this case. Given that only check_cluter_name is the case where we
found a small memory leak, I think it's adequate to fix it.

Fixing this issue suppresses the valgrind's complaint but since the
boot value of cluster_name is "" the memory leak we can avoid is only
1 byte.


I have committed this.  I think it's better to keep the code locally 
robust and not to have to rely on complex analysis of how GUC memory 
management works.

Re: [PATCH] Log details for client certificate failures

[Masahiko Sawada]

On Thu, Sep 29, 2022 at 1:43 AM Jacob Champion  wrote:
>
> On Tue, Sep 27, 2022 at 6:14 PM Masahiko Sawada  wrote:
> > No. Since cluster_name is PGC_POSTMATER, we leak a little postmaster
> > memory only once when starting up. application_name is PGC_USERSET but
> > since we normally allocate memory in PortalMemoryContext we eventually
> > can free it.
>
> Oh, I see; thank you for the correction. And even if someone put an
> application_name into their postgresql.conf, and then changed it a
> bunch of times, we'd free the leaked memory from the config_cxt that's
> created in ProcessConfigFile().

Right.

>
> Is there a reason we don't provide a similar temporary context during
> InitializeGUCOptions()? Naively it seems like that would suppress any
> future one-time leaks, and maybe cut down on some Valgrind noise. Then
> again, maybe there's just not that much demand for pallocs during GUC
> hooks.

While this seems a future-proof idea, I wonder if it might be overkill
since we don't need to worry about accumulation of leaked memory in
this case. Given that only check_cluter_name is the case where we
found a small memory leak, I think it's adequate to fix it.

Fixing this issue suppresses the valgrind's complaint but since the
boot value of cluster_name is "" the memory leak we can avoid is only
1 byte.

Regards,

--
Masahiko Sawada
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Tue, Sep 27, 2022 at 6:14 PM Masahiko Sawada  wrote:
> No. Since cluster_name is PGC_POSTMATER, we leak a little postmaster
> memory only once when starting up. application_name is PGC_USERSET but
> since we normally allocate memory in PortalMemoryContext we eventually
> can free it.

Oh, I see; thank you for the correction. And even if someone put an
application_name into their postgresql.conf, and then changed it a
bunch of times, we'd free the leaked memory from the config_cxt that's
created in ProcessConfigFile().

Is there a reason we don't provide a similar temporary context during
InitializeGUCOptions()? Naively it seems like that would suppress any
future one-time leaks, and maybe cut down on some Valgrind noise. Then
again, maybe there's just not that much demand for pallocs during GUC
hooks.

Thanks,
--Jacob

Re: [PATCH] Log details for client certificate failures

[Masahiko Sawada]

On Wed, Sep 28, 2022 at 4:44 AM Jacob Champion  wrote:
>
> On Tue, Sep 27, 2022 at 1:51 AM Masahiko Sawada  wrote:
> > I think we can fix it by the attached patch but I'd like to discuss
> > whether it's worth fixing it.
>
> Whoops. So every time it's changed, we leak a little postmaster memory?

No. Since cluster_name is PGC_POSTMATER, we leak a little postmaster
memory only once when starting up. application_name is PGC_USERSET but
since we normally allocate memory in PortalMemoryContext we eventually
can free it. Since check_cluster_name and check_application_name are
similar, I changed both for consistency.

Regards,

-- 
Masahiko Sawada
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Tue, Sep 27, 2022 at 1:51 AM Masahiko Sawada  wrote:
> I think we can fix it by the attached patch but I'd like to discuss
> whether it's worth fixing it.

Whoops. So every time it's changed, we leak a little postmaster memory?

Your patch looks good to me and I see no reason not to fix it.

Thanks,
--Jacob

Re: [PATCH] Log details for client certificate failures

[Masahiko Sawada]

Hi,

On Tue, Sep 13, 2022 at 11:11 PM Peter Eisentraut
 wrote:
>
> On 09.09.22 00:32, Jacob Champion wrote:
> > On Thu, Jul 28, 2022 at 9:19 AM Jacob Champion  
> > wrote:
> >> On Thu, Jul 21, 2022 at 4:29 PM Jacob Champion  
> >> wrote:
> >>> v4 attempts to fix this by letting the check hooks pass
> >>> MCXT_ALLOC_NO_OOM to pg_clean_ascii(). (It's ignored in the frontend,
> >>> which just mallocs.)
> >>
> >> Ping -- should I add an open item somewhere so this isn't lost?
> >
> > Trying again. Peter, is this approach acceptable? Should I try something 
> > else?
>
> This looks fine to me.  Committed.

While looking at the recent changes for check_cluster_name() I found
this thread. Regarding the following change made by the commit
45b1a67a0fc, there is possibly small memory leak:

 static bool
 check_cluster_name(char **newval, void **extra, GucSource source)
 {
+   char   *clean;
+
/* Only allow clean ASCII chars in the cluster name */
-   pg_clean_ascii(*newval);
+   clean = pg_clean_ascii(*newval, MCXT_ALLOC_NO_OOM);
+   if (!clean)
+   return false;
+
+   clean = guc_strdup(WARNING, clean);
+   if (!clean)
+   return false;

+   *newval = clean;
return true;
 }

pg_clean_ascii() does palloc_extended() to allocate memory in
Postmaster context for the new characters and the clean is then
replaced with the new memory allocated by guc_strdup(). No-one
references the memory allocated by pg_clean_ascii() and it lasts for
postmaster lifetime. Valgrind memcheck also shows:

 1 bytes in 1 blocks are definitely lost in loss record 4 of 70
at 0xCD2A16: palloc_extended (mcxt.c:1239)
by 0xD09437: pg_clean_ascii (string.c:99)
by 0x7A5CF3: check_cluster_name (variable.c:1061)
by 0xCAF7CD: call_string_check_hook (guc.c:6365)
by 0xCAA724: InitializeOneGUCOption (guc.c:1439)
by 0xCAA0ED: InitializeGUCOptions (guc.c:1268)
by 0x99B245: PostmasterMain (postmaster.c:691)
by 0x858896: main (main.c:197)

I think we can fix it by the attached patch but I'd like to discuss
whether it's worth fixing it.

Regards,

--
Masahiko Sawada
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
diff --git a/src/backend/commands/variable.c b/src/backend/commands/variable.c
index c795cb7a29..e555fb3150 100644
--- a/src/backend/commands/variable.c
+++ b/src/backend/commands/variable.c
@@ -1025,17 +1025,22 @@ bool
 check_application_name(char **newval, void **extra, GucSource source)
 {
 	char	   *clean;
+	char	   *ret;
 
 	/* Only allow clean ASCII chars in the application name */
 	clean = pg_clean_ascii(*newval, MCXT_ALLOC_NO_OOM);
 	if (!clean)
 		return false;
 
-	clean = guc_strdup(WARNING, clean);
-	if (!clean)
+	ret = guc_strdup(WARNING, clean);
+	if (!ret)
+	{
+		pfree(clean);
 		return false;
+	}
 
-	*newval = clean;
+	pfree(clean);
+	*newval = ret;
 	return true;
 }
 
@@ -1056,17 +1061,22 @@ bool
 check_cluster_name(char **newval, void **extra, GucSource source)
 {
 	char	   *clean;
+	char	   *ret;
 
 	/* Only allow clean ASCII chars in the cluster name */
 	clean = pg_clean_ascii(*newval, MCXT_ALLOC_NO_OOM);
 	if (!clean)
 		return false;
 
-	clean = guc_strdup(WARNING, clean);
-	if (!clean)
+	ret = guc_strdup(WARNING, clean);
+	if (!ret)
+	{
+		pfree(clean);
 		return false;
+	}
 
-	*newval = clean;
+	pfree(clean);
+	*newval = ret;
 	return true;
 }
 

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Tue, Sep 13, 2022 at 7:11 AM Peter Eisentraut
 wrote:
> This looks fine to me.  Committed.

Thanks!

--Jacob

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 09.09.22 00:32, Jacob Champion wrote:

On Thu, Jul 28, 2022 at 9:19 AM Jacob Champion  wrote:

On Thu, Jul 21, 2022 at 4:29 PM Jacob Champion  wrote:

v4 attempts to fix this by letting the check hooks pass
MCXT_ALLOC_NO_OOM to pg_clean_ascii(). (It's ignored in the frontend,
which just mallocs.)


Ping -- should I add an open item somewhere so this isn't lost?


Trying again. Peter, is this approach acceptable? Should I try something else?


This looks fine to me.  Committed.

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Thu, Jul 28, 2022 at 9:19 AM Jacob Champion  wrote:
> On Thu, Jul 21, 2022 at 4:29 PM Jacob Champion  
> wrote:
> > v4 attempts to fix this by letting the check hooks pass
> > MCXT_ALLOC_NO_OOM to pg_clean_ascii(). (It's ignored in the frontend,
> > which just mallocs.)
>
> Ping -- should I add an open item somewhere so this isn't lost?

Trying again. Peter, is this approach acceptable? Should I try something else?

Thanks,
--Jacob

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Thu, Jul 21, 2022 at 4:29 PM Jacob Champion  wrote:
> v4 attempts to fix this by letting the check hooks pass
> MCXT_ALLOC_NO_OOM to pg_clean_ascii(). (It's ignored in the frontend,
> which just mallocs.)

Ping -- should I add an open item somewhere so this isn't lost?

--Jacob

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Wed, Jul 20, 2022 at 3:42 PM Tom Lane  wrote:
> Jacob Champion  writes:
> > I'm currently hardcoding an elevel of ERROR on the new guc_strdup()s,
> > because that seems to be a common case for the check hooks.
>
> Really?  That's almost certainly NOT okay.  As an example, if you
> have a problem with a new value loaded from postgresql.conf during
> SIGHUP processing, throwing ERROR will cause the postmaster to exit.

v4 attempts to fix this by letting the check hooks pass
MCXT_ALLOC_NO_OOM to pg_clean_ascii(). (It's ignored in the frontend,
which just mallocs.)

> I wouldn't be too surprised if there are isolated cases where people
> didn't understand what they were doing and wrote that, but that
> needs to be fixed not emulated.

I might be missing something, but in guc.c at least it appears to be
the rule and not the exception.

Thanks,
--Jacob
diff --git a/src/backend/libpq/be-secure-openssl.c 
b/src/backend/libpq/be-secure-openssl.c
index 5318719acb..1394ecaa2b 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -1116,7 +1116,7 @@ prepare_cert_name(char *name)
 
 #undef MAXLEN
 
-   return pg_clean_ascii(truncated);
+   return pg_clean_ascii(truncated, 0);
 }
 
 /*
diff --git a/src/backend/postmaster/postmaster.c 
b/src/backend/postmaster/postmaster.c
index 5e8cd770c0..52fb2e52f1 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -2284,7 +2284,7 @@ retry1:
 */
if (strcmp(nameptr, "application_name") == 0)
{
-   port->application_name = 
pg_clean_ascii(valptr);
+   port->application_name = 
pg_clean_ascii(valptr, 0);
}
}
offset = valoffset + strlen(valptr) + 1;
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index 60400752e5..2f99fe9a6d 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -12479,9 +12479,18 @@ assign_maintenance_io_concurrency(int newval, void 
*extra)
 static bool
 check_application_name(char **newval, void **extra, GucSource source)
 {
+   char   *clean;
+
/* Only allow clean ASCII chars in the application name */
-   *newval = guc_strdup(ERROR, pg_clean_ascii(*newval));
+   clean = pg_clean_ascii(*newval, MCXT_ALLOC_NO_OOM);
+   if (!clean)
+   return false;
+
+   clean = guc_strdup(WARNING, clean);
+   if (!clean)
+   return false;
 
+   *newval = clean;
return true;
 }
 
@@ -12495,9 +12504,18 @@ assign_application_name(const char *newval, void 
*extra)
 static bool
 check_cluster_name(char **newval, void **extra, GucSource source)
 {
+   char   *clean;
+
/* Only allow clean ASCII chars in the cluster name */
-   *newval = guc_strdup(ERROR, pg_clean_ascii(*newval));
+   clean = pg_clean_ascii(*newval, MCXT_ALLOC_NO_OOM);
+   if (!clean)
+   return false;
+
+   clean = guc_strdup(WARNING, clean);
+   if (!clean)
+   return false;
 
+   *newval = clean;
return true;
 }
 
diff --git a/src/common/string.c b/src/common/string.c
index db15324c62..97b3d45d36 100644
--- a/src/common/string.c
+++ b/src/common/string.c
@@ -62,7 +62,10 @@ strtoint(const char *pg_restrict str, char **pg_restrict 
endptr, int base)
 /*
  * pg_clean_ascii -- Replace any non-ASCII chars with a "\xXX" string
  *
- * Makes a palloc'd copy of the string passed in, which must be 
'\0'-terminated.
+ * Makes a newly allocated copy of the string passed in, which must be
+ * '\0'-terminated. In the backend, additional alloc_flags may be provided and
+ * will be passed as-is to palloc_extended(); in the frontend, alloc_flags is
+ * ignored and the copy is malloc'd.
  *
  * This function exists specifically to deal with filtering out
  * non-ASCII characters in a few places where the client can provide an almost
@@ -80,23 +83,46 @@ strtoint(const char *pg_restrict str, char **pg_restrict 
endptr, int base)
  * for now.
  */
 char *
-pg_clean_ascii(const char *str)
+pg_clean_ascii(const char *str, int alloc_flags)
 {
-   StringInfoData buf;
-   const char   *p;
+   size_t  dstlen;
+   char   *dst;
+   const char *p;
+   size_t  i = 0;
 
-   initStringInfo();
+   /* Worst case, each byte can become four bytes, plus a null terminator. 
*/
+   dstlen = strlen(str) * 4 + 1;
+
+#ifdef FRONTEND
+   dst = malloc(dstlen);
+#else
+   dst = palloc_extended(dstlen, alloc_flags);
+#endif
+
+   if (!dst)
+   return NULL;
 
for (p = str; *p != '\0'; p++)
{
+
/* Only allow clean ASCII chars in the string */
if (*p < 32 || *p > 126)
-   appendStringInfo(, 

Re: [PATCH] Log details for client certificate failures

[Tom Lane]

Jacob Champion  writes:
> I'm currently hardcoding an elevel of ERROR on the new guc_strdup()s,
> because that seems to be a common case for the check hooks.

Really?  That's almost certainly NOT okay.  As an example, if you
have a problem with a new value loaded from postgresql.conf during
SIGHUP processing, throwing ERROR will cause the postmaster to exit.

I wouldn't be too surprised if there are isolated cases where people
didn't understand what they were doing and wrote that, but that
needs to be fixed not emulated.

regards, tom lane

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Wed, Jul 20, 2022 at 3:15 PM Tom Lane  wrote:
> guc_malloc's behavior varies depending on elevel.  It's *not*
> equivalent to palloc.

Right, sorry -- a better way for me to ask the question:

I'm currently hardcoding an elevel of ERROR on the new guc_strdup()s,
because that seems to be a common case for the check hooks. If that's
okay, is there any reason not to use palloc() semantics for
pg_clean_ascii()? (And if it's not okay, why?)

--Jacob

Re: [PATCH] Log details for client certificate failures

[Tom Lane]

Jacob Champion  writes:
> The guc_strdup() approach really reduces the amount of code, so that's
> what I did in v3. I'm not following why we need to return NULL on
> failure, though -- both palloc() and guc_malloc() ERROR on failure, so
> is it okay to keep those semantics the same?

guc_malloc's behavior varies depending on elevel.  It's *not*
equivalent to palloc.

regards, tom lane

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Tue, Jul 19, 2022 at 3:38 PM Andres Freund  wrote:
> Or alternatively, perhaps we can just make pg_clean_ascii() return NULL
> if allocation failed and then guc_strdup() the result in guc.c?

The guc_strdup() approach really reduces the amount of code, so that's
what I did in v3. I'm not following why we need to return NULL on
failure, though -- both palloc() and guc_malloc() ERROR on failure, so
is it okay to keep those semantics the same?

> If we end up needing a two phase approach, why use the same function for
> both phases? That seems quite awkward.

Mostly so the byte counting always agrees between the two phases, no
matter how the implementation evolves. But it's hopefully moot now.

--Jacob
From dfd76f4dbcf3834371442d593d315797762bbd11 Mon Sep 17 00:00:00 2001
From: Jacob Champion 
Date: Tue, 19 Jul 2022 10:48:58 -0700
Subject: [PATCH v3 1/2] pg_clean_ascii(): escape bytes rather than lose them

Rather than replace each unprintable byte with a '?' character, replace
it with a hex escape instead. The API now allocates a copy rather than
modifying the input in place.
---
 src/backend/postmaster/postmaster.c |  6 +-
 src/backend/utils/misc/guc.c|  4 ++--
 src/common/string.c | 26 +-
 src/include/common/string.h |  2 +-
 4 files changed, 21 insertions(+), 17 deletions(-)

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index 1c25457526..5e8cd770c0 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -2284,11 +2284,7 @@ retry1:
  */
 if (strcmp(nameptr, "application_name") == 0)
 {
-	char	   *tmp_app_name = pstrdup(valptr);
-
-	pg_clean_ascii(tmp_app_name);
-
-	port->application_name = tmp_app_name;
+	port->application_name = pg_clean_ascii(valptr);
 }
 			}
 			offset = valoffset + strlen(valptr) + 1;
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index 0328029d43..60400752e5 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -12480,7 +12480,7 @@ static bool
 check_application_name(char **newval, void **extra, GucSource source)
 {
 	/* Only allow clean ASCII chars in the application name */
-	pg_clean_ascii(*newval);
+	*newval = guc_strdup(ERROR, pg_clean_ascii(*newval));
 
 	return true;
 }
@@ -12496,7 +12496,7 @@ static bool
 check_cluster_name(char **newval, void **extra, GucSource source)
 {
 	/* Only allow clean ASCII chars in the cluster name */
-	pg_clean_ascii(*newval);
+	*newval = guc_strdup(ERROR, pg_clean_ascii(*newval));
 
 	return true;
 }
diff --git a/src/common/string.c b/src/common/string.c
index 16940d1fa7..db15324c62 100644
--- a/src/common/string.c
+++ b/src/common/string.c
@@ -22,6 +22,7 @@
 #endif
 
 #include "common/string.h"
+#include "lib/stringinfo.h"
 
 
 /*
@@ -59,9 +60,9 @@ strtoint(const char *pg_restrict str, char **pg_restrict endptr, int base)
 
 
 /*
- * pg_clean_ascii -- Replace any non-ASCII chars with a '?' char
+ * pg_clean_ascii -- Replace any non-ASCII chars with a "\xXX" string
  *
- * Modifies the string passed in which must be '\0'-terminated.
+ * Makes a palloc'd copy of the string passed in, which must be '\0'-terminated.
  *
  * This function exists specifically to deal with filtering out
  * non-ASCII characters in a few places where the client can provide an almost
@@ -73,22 +74,29 @@ strtoint(const char *pg_restrict str, char **pg_restrict endptr, int base)
  * In general, this function should NOT be used- instead, consider how to handle
  * the string without needing to filter out the non-ASCII characters.
  *
- * Ultimately, we'd like to improve the situation to not require stripping out
- * all non-ASCII but perform more intelligent filtering which would allow UTF or
+ * Ultimately, we'd like to improve the situation to not require replacing all
+ * non-ASCII but perform more intelligent filtering which would allow UTF or
  * similar, but it's unclear exactly what we should allow, so stick to ASCII only
  * for now.
  */
-void
-pg_clean_ascii(char *str)
+char *
+pg_clean_ascii(const char *str)
 {
-	/* Only allow clean ASCII chars in the string */
-	char	   *p;
+	StringInfoData buf;
+	const char   *p;
+
+	initStringInfo();
 
 	for (p = str; *p != '\0'; p++)
 	{
+		/* Only allow clean ASCII chars in the string */
 		if (*p < 32 || *p > 126)
-			*p = '?';
+			appendStringInfo(, "\\x%02x", (unsigned char) *p);
+		else
+			appendStringInfoChar(, *p);
 	}
+
+	return buf.data;
 }
 
 
diff --git a/src/include/common/string.h b/src/include/common/string.h
index cf00fb53cd..d10d0c9cbf 100644
--- a/src/include/common/string.h
+++ b/src/include/common/string.h
@@ -24,7 +24,7 @@ typedef struct PromptInterruptContext
 extern bool pg_str_endswith(const char *str, const char *end);
 extern int	strtoint(const char *pg_restrict str, char **pg_restrict endptr,
 	 int base);
-extern void pg_clean_ascii(char *str);
+extern char 

Re: [PATCH] Log details for client certificate failures

[Andres Freund]

Hi,

On 2022-07-19 15:08:38 -0700, Jacob Champion wrote:
> v2 adds escaping to pg_clean_ascii(). My original attempt used
> StringInfo allocation, but that didn't play well with guc_malloc(), so
> I switched to a two-pass API where the caller allocates. Let me know
> if I'm missing something obvious; this way is more verbose than I'd
> like...

Hm, that's pretty awkward. Perhaps we can have a better API for
everything but guc.c?

Or alternatively, perhaps we can just make pg_clean_ascii() return NULL
if allocation failed and then guc_strdup() the result in guc.c?

If we end up needing a two phase approach, why use the same function for
both phases? That seems quite awkward.

Greetings,

Andres Freund

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Tue, Jul 19, 2022 at 10:09 AM Andres Freund  wrote:
> On 2022-07-19 12:39:43 -0400, Tom Lane wrote:
> > Having said that, I struggle to see why we are panicking about badly
> > encoded log data from this source while blithely ignoring the problems
> > posed by non-ASCII role names, database names, and tablespace names.
>
> I think we should fix these as well. I'm not as concerned about post-auth
> encoding issues (i.e. tablespace name) as about pre-auth data (role name,
> database name) - obviously being allowed to log in already is a pretty good
> filter...

v2 adds escaping to pg_clean_ascii(). My original attempt used
StringInfo allocation, but that didn't play well with guc_malloc(), so
I switched to a two-pass API where the caller allocates. Let me know
if I'm missing something obvious; this way is more verbose than I'd
like...

Thanks,
--Jacob
From d99b59652f0b8479a5df0bc50357b5c4617f9fc2 Mon Sep 17 00:00:00 2001
From: Jacob Champion 
Date: Tue, 19 Jul 2022 10:48:58 -0700
Subject: [PATCH v2 1/2] pg_clean_ascii(): escape bytes rather than lose them

Rather than replace each unprintable byte with a '?' character, replace
it with a hex escape instead. The API is now two-pass (one pass to get
the escaped length of the string, the second pass to perform the
escaping), in order to allow the use of guc_malloc'd buffers.
---
 src/backend/postmaster/postmaster.c |  4 +--
 src/backend/utils/misc/guc.c| 10 ++--
 src/common/string.c | 38 ++---
 src/include/common/string.h |  2 +-
 4 files changed, 40 insertions(+), 14 deletions(-)

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index 1c25457526..8f5cdf4380 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -2284,9 +2284,9 @@ retry1:
  */
 if (strcmp(nameptr, "application_name") == 0)
 {
-	char	   *tmp_app_name = pstrdup(valptr);
+	char	   *tmp_app_name = palloc(pg_clean_ascii(valptr, NULL));
 
-	pg_clean_ascii(tmp_app_name);
+	pg_clean_ascii(valptr, tmp_app_name);
 
 	port->application_name = tmp_app_name;
 }
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index 0328029d43..2e1a7af315 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -12480,7 +12480,10 @@ static bool
 check_application_name(char **newval, void **extra, GucSource source)
 {
 	/* Only allow clean ASCII chars in the application name */
-	pg_clean_ascii(*newval);
+	char *buf = guc_malloc(ERROR, pg_clean_ascii(*newval, NULL));
+
+	pg_clean_ascii(*newval, buf);
+	*newval = buf;
 
 	return true;
 }
@@ -12496,7 +12499,10 @@ static bool
 check_cluster_name(char **newval, void **extra, GucSource source)
 {
 	/* Only allow clean ASCII chars in the cluster name */
-	pg_clean_ascii(*newval);
+	char *buf = guc_malloc(ERROR, pg_clean_ascii(*newval, NULL));
+
+	pg_clean_ascii(*newval, buf);
+	*newval = buf;
 
 	return true;
 }
diff --git a/src/common/string.c b/src/common/string.c
index 16940d1fa7..82a8afa4a9 100644
--- a/src/common/string.c
+++ b/src/common/string.c
@@ -22,6 +22,7 @@
 #endif
 
 #include "common/string.h"
+#include "lib/stringinfo.h"
 
 
 /*
@@ -59,9 +60,11 @@ strtoint(const char *pg_restrict str, char **pg_restrict endptr, int base)
 
 
 /*
- * pg_clean_ascii -- Replace any non-ASCII chars with a '?' char
+ * pg_clean_ascii -- Replace any non-ASCII chars with a "\xXX" string
  *
- * Modifies the string passed in which must be '\0'-terminated.
+ * Puts an escaped copy into the dst buffer, which must be at least as big as
+ * the return value of pg_clean_ascii(src, NULL). The input string must be
+ * '\0'-terminated.
  *
  * This function exists specifically to deal with filtering out
  * non-ASCII characters in a few places where the client can provide an almost
@@ -73,22 +76,39 @@ strtoint(const char *pg_restrict str, char **pg_restrict endptr, int base)
  * In general, this function should NOT be used- instead, consider how to handle
  * the string without needing to filter out the non-ASCII characters.
  *
- * Ultimately, we'd like to improve the situation to not require stripping out
- * all non-ASCII but perform more intelligent filtering which would allow UTF or
+ * Ultimately, we'd like to improve the situation to not require replacing all
+ * non-ASCII but perform more intelligent filtering which would allow UTF or
  * similar, but it's unclear exactly what we should allow, so stick to ASCII only
  * for now.
  */
-void
-pg_clean_ascii(char *str)
+size_t
+pg_clean_ascii(const char *str, char *dst)
 {
-	/* Only allow clean ASCII chars in the string */
-	char	   *p;
+	const char *p;
+	size_t		i = 0;
 
 	for (p = str; *p != '\0'; p++)
 	{
+		/* Only allow clean ASCII chars in the string */
 		if (*p < 32 || *p > 126)
-			*p = '?';
+		{
+			if (dst)
+snprintf([i], 5, "\\x%02x", (unsigned char) *p);
+			i += 4;
+		}
+		else
+		{
+			if (dst)
+dst[i] 

Re: [PATCH] Log details for client certificate failures

[Andres Freund]

Hi,

On 2022-07-19 12:39:43 -0400, Tom Lane wrote:
> Having said that, I struggle to see why we are panicking about badly
> encoded log data from this source while blithely ignoring the problems
> posed by non-ASCII role names, database names, and tablespace names.

I think we should fix these as well. I'm not as concerned about post-auth
encoding issues (i.e. tablespace name) as about pre-auth data (role name,
database name) - obviously being allowed to log in already is a pretty good
filter...

Greetings,

Andres Freund

Re: [PATCH] Log details for client certificate failures

[Tom Lane]

Jacob Champion  writes:
> On 7/19/22 09:14, Andres Freund wrote:
>> IMO this should replace the existing ascii escape function instead.

> That will affect the existing behavior of application_name and
> cluster_name; is that acceptable?

I think Andres' point is exactly that these should all act alike.

Having said that, I struggle to see why we are panicking about badly
encoded log data from this source while blithely ignoring the problems
posed by non-ASCII role names, database names, and tablespace names.

regards, tom lane

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

[resending to list]

On 7/19/22 09:14, Andres Freund wrote:
> IMO this should replace the existing ascii escape function instead.
That will affect the existing behavior of application_name and
cluster_name; is that acceptable?

--Jacob

Re: [PATCH] Log details for client certificate failures

[Andres Freund]

Hi,

On 2022-07-19 09:07:31 -0700, Jacob Champion wrote:
> On Fri, Jul 15, 2022 at 4:45 PM Andres Freund  wrote:
> > On 2022-07-15 14:51:38 -0700, Jacob Champion wrote:
> > > That seems much worse than escaping for this particular patch; if your
> > > cert's Common Name is in (non-ASCII) UTF-8 then all you'll see is
> > > "CN=?" in the log lines that were supposed to be helping you
> > > root-cause. Escaping would be much more helpful in this case.
> >
> > I'm doubtful that's all that common.
> 
> Probably not, but the more systems that support it without weird
> usability bugs, the more common it will hopefully become.
> 
> > But either way, I suggest a separate patch to deal with that...
> 
> Proposed fix attached, which uses \x-escaping for bytes outside of
> printable ASCII.

I don't think this should be open coded in the ssl part of the code. IMO this
should replace the existing ascii escape function instead. I strongly oppose
open coding this functionality in prepare_cert_name().

Greetings,

Andres Freund

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Fri, Jul 15, 2022 at 4:45 PM Andres Freund  wrote:
> On 2022-07-15 14:51:38 -0700, Jacob Champion wrote:
> > That seems much worse than escaping for this particular patch; if your
> > cert's Common Name is in (non-ASCII) UTF-8 then all you'll see is
> > "CN=?" in the log lines that were supposed to be helping you
> > root-cause. Escaping would be much more helpful in this case.
>
> I'm doubtful that's all that common.

Probably not, but the more systems that support it without weird
usability bugs, the more common it will hopefully become.

> But either way, I suggest a separate patch to deal with that...

Proposed fix attached, which uses \x-escaping for bytes outside of
printable ASCII.

Thanks,
--Jacob
From 3c8e910a75c74f85b640f7d728205c276b1d1c51 Mon Sep 17 00:00:00 2001
From: Jacob Champion 
Date: Mon, 18 Jul 2022 15:01:19 -0700
Subject: [PATCH] Don't reflect unescaped cert data to the logs

Commit 3a0e385048 introduced a new path for unauthenticated bytes from
the client certificate to be printed unescaped to the logs. There are a
handful of these already, but it doesn't make sense to keep making the
problem worse. \x-escape any unprintable bytes.

The test case introduces a revoked UTF-8 certificate. This requires the
addition of the `-utf8` flag to `openssl req`. Since the existing
certificates all use an ASCII subset, this won't modify the existing
certificates' subjects if/when they get regenerated; this was verified
experimentally with

$ make sslfiles-clean
$ make sslfiles

Unfortunately the test can't be run as-is yet due to a test timing
issue; see 55828a6b60.
---
 src/backend/libpq/be-secure-openssl.c | 74 ---
 src/test/ssl/conf/client-revoked-utf8.config  | 13 
 src/test/ssl/ssl/client-crldir/9bb9e3c3.r0| 19 ++---
 src/test/ssl/ssl/client-revoked-utf8.crt  | 18 +
 src/test/ssl/ssl/client-revoked-utf8.key  | 27 +++
 src/test/ssl/ssl/client.crl   | 19 ++---
 .../ssl/ssl/root+client-crldir/9bb9e3c3.r0| 19 ++---
 src/test/ssl/ssl/root+client.crl  | 19 ++---
 src/test/ssl/sslfiles.mk  | 10 ++-
 src/test/ssl/t/001_ssltests.pl| 13 
 src/test/ssl/t/SSL/Backend/OpenSSL.pm |  3 +-
 11 files changed, 167 insertions(+), 67 deletions(-)
 create mode 100644 src/test/ssl/conf/client-revoked-utf8.config
 create mode 100644 src/test/ssl/ssl/client-revoked-utf8.crt
 create mode 100644 src/test/ssl/ssl/client-revoked-utf8.key

diff --git a/src/backend/libpq/be-secure-openssl.c b/src/backend/libpq/be-secure-openssl.c
index 9cec6866a3..ad0d79a511 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -35,6 +35,7 @@
 #include "storage/fd.h"
 #include "storage/latch.h"
 #include "tcop/tcopprot.h"
+#include "utils/builtins.h"
 #include "utils/memutils.h"
 
 /*
@@ -1082,16 +1083,17 @@ dummy_ssl_passwd_cb(char *buf, int size, int rwflag, void *userdata)
 }
 
 /*
- * Examines the provided certificate name, and if it's too long to log, modifies
- * and truncates it. The return value is NULL if no truncation was needed; it
- * otherwise points into the middle of the input string, and should not be
- * freed.
+ * Examines the provided certificate name, and if it's too long to log or
+ * contains unprintable ASCII, escapes and truncates it. The return value is
+ * always a new palloc'd string.
  */
 static char *
-truncate_cert_name(char *name)
+prepare_cert_name(char *name)
 {
 	size_t		namelen = strlen(name);
-	char	   *truncated;
+	char	   *truncated = name;
+	char	   *escaped;
+	int			i;
 
 	/*
 	 * Common Names are 64 chars max, so for a common case where the CN is the
@@ -1101,19 +1103,37 @@ truncate_cert_name(char *name)
 	 */
 #define MAXLEN 71
 
-	if (namelen <= MAXLEN)
-		return NULL;
-
-	/*
-	 * Keep the end of the name, not the beginning, since the most specific
-	 * field is likely to give users the most information.
-	 */
-	truncated = name + namelen - MAXLEN;
-	truncated[0] = truncated[1] = truncated[2] = '.';
+	if (namelen > MAXLEN)
+	{
+		/*
+		 * Keep the end of the name, not the beginning, since the most specific
+		 * field is likely to give users the most information.
+		 */
+		truncated = name + namelen - MAXLEN;
+		truncated[0] = truncated[1] = truncated[2] = '.';
+		namelen = MAXLEN;
+	}
 
 #undef MAXLEN
 
-	return truncated;
+	escaped = palloc(namelen * 4 + 1); /* one byte becomes four: "\xCC" */
+	i = 0;
+
+	for (char *c = truncated; *c; c++)
+	{
+		/* Keep printable characters including space. Escape everything else. */
+		if (*c >= 0x20 && *c <= 0x7E)
+			escaped[i++] = *c;
+		else
+		{
+			escaped[i++] = '\\';
+			escaped[i++] = 'x';
+			i += hex_encode(c, 1, [i]);
+		}
+	}
+
+	escaped[i] = '\0';
+	return escaped;
 }
 
 /*
@@ -1156,21 +1176,24 @@ verify_cb(int ok, X509_STORE_CTX *ctx)
 	{
 		char	   *subject,
    *issuer;
-		char	   *sub_truncated,
-   *iss_truncated;
+		char	   *sub_prepared,
+			

Re: [PATCH] Log details for client certificate failures

[Andres Freund]

Hi,

On 2022-07-15 14:51:38 -0700, Jacob Champion wrote:
> > We already have pg_clean_ascii() and use it for application_name, fwiw.
> 
> That seems much worse than escaping for this particular patch; if your
> cert's Common Name is in (non-ASCII) UTF-8 then all you'll see is
> "CN=?" in the log lines that were supposed to be helping you
> root-cause. Escaping would be much more helpful in this case.

I'm doubtful that's all that common. But either way, I suggest a separate
patch to deal with that...

Greetings,

Andres Freund

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On 7/15/22 14:19, Andres Freund wrote:
> On 2022-07-15 14:01:53 -0700, Jacob Champion wrote:
>> On 7/15/22 13:35, Andres Freund wrote:
>>> I don't know, but I don't think not caring at all is a good
>>> option. Particularly for unauthenticated data I'd say that escaping 
>>> everything
>>> but printable ascii chars is a sensible approach.
>>
>> It'll also be painful for anyone whose infrastructure isn't in a Latin
>> character set... Maybe that's worth the tradeoff for a v1.
> 
> I don't think it's a huge issue, or really avoidable, pre-authentication.
> Don't we require all server-side encodings to be supersets of ascii?

Well, I was going to say that for this feature, where the goal is to
debug a failed certificate chain, having to manually unescape the logged
certificate names if your infrastructure already handled UTF-8 natively
would be a real pain.

But your later point about truncation makes that moot; I forgot that my
patch can truncate in the middle of a UTF-8 sequence, so you're probably
dealing with replacement glyphs anyway. I don't really have a leg to
stand on there.

> We already have pg_clean_ascii() and use it for application_name, fwiw.

That seems much worse than escaping for this particular patch; if your
cert's Common Name is in (non-ASCII) UTF-8 then all you'll see is
"CN=?" in the log lines that were supposed to be helping you
root-cause. Escaping would be much more helpful in this case.

>> Is there an acceptable approach that could centralize it, so we fix it
>> once and are done? E.g. a log_encoding GUC and either conversion or
>> escaping in send_message_to_server_log()?
> 
> Introducing escaping to ascii for all log messages seems like it'd be
> incredibly invasive, and would remove a lot of worthwhile information. Nor
> does it really address the whole scope - consider e.g. the truncation in this
> patch, that can't be done correctly by the time send_message_to_server_log()
> is reached - just chopping in the middle of a multi-byte string would have
> made the string invalidly encoded. And we can't perform encoding conversion
> from client data until we've gone further into the authentication process, I
> think.
> 
> Always escaping ANSI escape codes (or rather the non-printable ascii range) is
> more convincing. Then we'd just need to make sure that client controlled data
> is properly encoded before handing it over to other parts of the system.
> 
> I can see a point in a log_encoding GUC at some point, but it seems a bit
> separate from the discussion here.

Fair enough.

--Jacob

Re: [PATCH] Log details for client certificate failures

[Tom Lane]

Andres Freund  writes:
> We already have pg_clean_ascii() and use it for application_name, fwiw.

Yeah, we should just use that.  If anyone wants to upgrade the situation
for non-ASCII data later, fixing it for all of these cases at once would
be appropriate.

regards, tom lane

Re: [PATCH] Log details for client certificate failures

[Andres Freund]

Hi,

On 2022-07-15 14:01:53 -0700, Jacob Champion wrote:
> On 7/15/22 13:35, Andres Freund wrote:
> >> (And do we want to fix it now, regardless?)
> > 
> > Yes.
> 
> Cool. I can get on board with that.
> 
> >> What guarantees are we supposed to be making for log encoding?
> > 
> > I don't know, but I don't think not caring at all is a good
> > option. Particularly for unauthenticated data I'd say that escaping 
> > everything
> > but printable ascii chars is a sensible approach.
> 
> It'll also be painful for anyone whose infrastructure isn't in a Latin
> character set... Maybe that's worth the tradeoff for a v1.

I don't think it's a huge issue, or really avoidable, pre-authentication.
Don't we require all server-side encodings to be supersets of ascii?

We already have pg_clean_ascii() and use it for application_name, fwiw.


> Is there an acceptable approach that could centralize it, so we fix it
> once and are done? E.g. a log_encoding GUC and either conversion or
> escaping in send_message_to_server_log()?

Introducing escaping to ascii for all log messages seems like it'd be
incredibly invasive, and would remove a lot of worthwhile information. Nor
does it really address the whole scope - consider e.g. the truncation in this
patch, that can't be done correctly by the time send_message_to_server_log()
is reached - just chopping in the middle of a multi-byte string would have
made the string invalidly encoded. And we can't perform encoding conversion
from client data until we've gone further into the authentication process, I
think.

Always escaping ANSI escape codes (or rather the non-printable ascii range) is
more convincing. Then we'd just need to make sure that client controlled data
is properly encoded before handing it over to other parts of the system.

I can see a point in a log_encoding GUC at some point, but it seems a bit
separate from the discussion here.

Greetings,

Andres Freund

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On 7/15/22 13:35, Andres Freund wrote:
>> (And do we want to fix it now, regardless?)
> 
> Yes.

Cool. I can get on board with that.

>> What guarantees are we supposed to be making for log encoding?
> 
> I don't know, but I don't think not caring at all is a good
> option. Particularly for unauthenticated data I'd say that escaping everything
> but printable ascii chars is a sensible approach.

It'll also be painful for anyone whose infrastructure isn't in a Latin
character set... Maybe that's worth the tradeoff for a v1.

Is there an acceptable approach that could centralize it, so we fix it
once and are done? E.g. a log_encoding GUC and either conversion or
escaping in send_message_to_server_log()?

--Jacob

Re: [PATCH] Log details for client certificate failures

[Andres Freund]

Hi,

On 2022-07-15 13:20:59 -0700, Jacob Champion wrote:
> On 7/15/22 12:11, Andres Freund wrote:
> > This might have been discussed somewhere, but I'm worried about emitting
> > unescaped data from pre-auth clients. What guarantees that subject / issuer
> > name only contain printable ascii-chars? Printing terminal control chars or
> > such would not be great, nor would splitting a string at a multi-boundary.
> 
> Hm. The last time I asked about that, Magnus pointed out that we reflect
> port->user_name as-is [1], so I kind of stopped worrying about it.

I think we need to fix a number of these. But no, I don't think we should just
add more because we've not been careful in a bunch of other places.


> Is this more dangerous than that?

Hard to say.


> (And do we want to fix it now, regardless?)

Yes.


> What guarantees are we supposed to be making for log encoding?

I don't know, but I don't think not caring at all is a good
option. Particularly for unauthenticated data I'd say that escaping everything
but printable ascii chars is a sensible approach.

Greetings,

Andres Freund

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On 7/15/22 12:11, Andres Freund wrote:
> This might have been discussed somewhere, but I'm worried about emitting
> unescaped data from pre-auth clients. What guarantees that subject / issuer
> name only contain printable ascii-chars? Printing terminal control chars or
> such would not be great, nor would splitting a string at a multi-boundary.

Hm. The last time I asked about that, Magnus pointed out that we reflect
port->user_name as-is [1], so I kind of stopped worrying about it. Is
this more dangerous than that? (And do we want to fix it now,
regardless?) What guarantees are we supposed to be making for log encoding?

Thanks,
--Jacob

[1]
https://www.postgresql.org/message-id/CABUevExVHryTasKmtJW5RtU-dBesYj4bV7ggpeVMfiPCHCvLNA%40mail.gmail.com

Re: [PATCH] Log details for client certificate failures

[Andres Freund]

Hi,

On 2022-07-15 09:46:40 -0700, Jacob Champion wrote:
> On 7/15/22 09:34, Peter Eisentraut wrote:
> > Committed like that.
> 
> Thanks for all the reviews!

This might have been discussed somewhere, but I'm worried about emitting
unescaped data from pre-auth clients. What guarantees that subject / issuer
name only contain printable ascii-chars? Printing terminal control chars or
such would not be great, nor would splitting a string at a multi-boundary.

Greetings,

Andres Freund

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On 7/15/22 09:34, Peter Eisentraut wrote:
> Committed like that.

Thanks for all the reviews!

--Jacob

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 14.07.22 23:09, Jacob Champion wrote:

On Thu, Jul 14, 2022 at 1:12 PM Peter Eisentraut
 wrote:

Concretely, I was thinking like the attached top-up patch.

The other way can surely be made to work somehow, but this seems much
simpler and with fewer questions about the details.


Ah, seeing it side-by-side helps. That's much easier, I agree.


Committed like that.

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Thu, Jul 14, 2022 at 1:12 PM Peter Eisentraut
 wrote:
> Concretely, I was thinking like the attached top-up patch.
>
> The other way can surely be made to work somehow, but this seems much
> simpler and with fewer questions about the details.

Ah, seeing it side-by-side helps. That's much easier, I agree.

Thanks,
--Jacob

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 13.07.22 01:06, Jacob Champion wrote:

I had to read up on this "ex_data" API.  Interesting.  But I'm wondering
a bit about how the life cycle of these objects is managed.  What
happens if the allocated error string is deallocated before its
containing object?  Or vice versa?


Yeah, I'm currently leaning heavily on the lack of any memory context
switches here. And I end up leaking out a pointer to the stale stack
of be_tls_open_server(), which is gross -- it works since there are no
other clients, but that could probably come back to bite us.

The ex_data API exposes optional callbacks for new/dup/free (I'm
currently setting those to NULL), so we can run custom code whenever
the SSL* is destroyed. If you'd rather the data have the same lifetime
of the SSL* object, we can switch to malloc/strdup/free (or even
OPENSSL_strdup() in later versions). But since we don't have any use
for the ex_data outside of this function, maybe we should just clear
it before we return, rather than carrying it around.


Concretely, I was thinking like the attached top-up patch.

The other way can surely be made to work somehow, but this seems much 
simpler and with fewer questions about the details.From 662bc1d19101865f91c6ed4a98c0f13f3757e1c7 Mon Sep 17 00:00:00 2001
From: Peter Eisentraut 
Date: Thu, 14 Jul 2022 22:08:53 +0200
Subject: [PATCH v5 2/2] squash! Log details for client certificate failures

---
 src/backend/libpq/be-secure-openssl.c | 29 +--
 1 file changed, 5 insertions(+), 24 deletions(-)

diff --git a/src/backend/libpq/be-secure-openssl.c 
b/src/backend/libpq/be-secure-openssl.c
index 8d5eee0d16..2147524ffc 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -81,13 +81,7 @@ static bool ssl_is_server_start;
 static int ssl_protocol_version_to_openssl(int v);
 static const char *ssl_protocol_version_to_string(int v);
 
-/* Helpers for storing application data in the SSL handle */
-struct pg_ex_data
-{
-   /* to bubble errors out of callbacks */
-   char   *errdetail;
-};
-static int ssl_ex_index;
+static const char *cert_errdetail;
 
 /*  */
 /*  Public interface   
*/
@@ -110,7 +104,6 @@ be_tls_init(bool isServerStart)
SSL_library_init();
SSL_load_error_strings();
 #endif
-   ssl_ex_index = SSL_get_ex_new_index(0, NULL, NULL, NULL, NULL);
SSL_initialized = true;
}
 
@@ -422,7 +415,6 @@ be_tls_open_server(Port *port)
int err;
int waitfor;
unsigned long ecode;
-   struct pg_ex_data exdata = {0};
boolgive_proto_hint;
 
Assert(!port->ssl);
@@ -455,14 +447,6 @@ be_tls_open_server(Port *port)

SSLerrmessage(ERR_get_error();
return -1;
}
-   if (!SSL_set_ex_data(port->ssl, ssl_ex_index, ))
-   {
-   ereport(COMMERROR,
-   (errcode(ERRCODE_PROTOCOL_VIOLATION),
-errmsg("could not attach application data to 
SSL handle: %s",
-   
SSLerrmessage(ERR_get_error();
-   return -1;
-   }
 
port->ssl_in_use = true;
 
@@ -561,7 +545,7 @@ be_tls_open_server(Port *port)

(errcode(ERRCODE_PROTOCOL_VIOLATION),
 errmsg("could not accept SSL 
connection: %s",

SSLerrmessage(ecode)),
-exdata.errdetail ? 
errdetail_internal("%s", exdata.errdetail) : 0,
+cert_errdetail ? 
errdetail_internal("%s", cert_errdetail) : 0,
 give_proto_hint ?
 errhint("This may indicate 
that the client does not support any SSL protocol version between %s and %s.",
 
ssl_min_protocol_version ?
@@ -570,6 +554,7 @@ be_tls_open_server(Port *port)
 
ssl_max_protocol_version ?
 
ssl_protocol_version_to_string(ssl_max_protocol_version) :
 
MAX_OPENSSL_TLS_VERSION) : 0));
+   cert_errdetail = NULL;
break;
case SSL_ERROR_ZERO_RETURN:
ereport(COMMERROR,
@@ -1145,12 +1130,10 @@ truncate_cert_name(char *name)
 static int
 verify_cb(int ok, 

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Mon, Jul 11, 2022 at 6:09 AM Peter Eisentraut
 wrote:
> I squashed those two together.  I also adjusted the error message a bit
> more for project style.  (We can put both lines into detail.)

Oh, okay. Log parsers don't have any issues with that?

> I had to read up on this "ex_data" API.  Interesting.  But I'm wondering
> a bit about how the life cycle of these objects is managed.  What
> happens if the allocated error string is deallocated before its
> containing object?  Or vice versa?

Yeah, I'm currently leaning heavily on the lack of any memory context
switches here. And I end up leaking out a pointer to the stale stack
of be_tls_open_server(), which is gross -- it works since there are no
other clients, but that could probably come back to bite us.

The ex_data API exposes optional callbacks for new/dup/free (I'm
currently setting those to NULL), so we can run custom code whenever
the SSL* is destroyed. If you'd rather the data have the same lifetime
of the SSL* object, we can switch to malloc/strdup/free (or even
OPENSSL_strdup() in later versions). But since we don't have any use
for the ex_data outside of this function, maybe we should just clear
it before we return, rather than carrying it around.

> How do we ensure we don't
> accidentally reuse the error string when the code runs again?  (I guess
> currently it can't?)

The ex_data is associated with the SSL*, not the global SSL_CTX*, so
that shouldn't be an issue. A new SSL* gets created at the start of
be_tls_open_server().

>  Maybe we should avoid this and just put the
> errdetail itself into a static variable that we unset once the message
> is printed?

If you're worried about the lifetime of the palloc'd data being too
short, does switching to a static variable help in that case?

--Jacob

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Sat, Jul 9, 2022 at 6:49 AM Graham Leggett  wrote:
> Please don’t invent another format, or try and truncate the data. This is a 
> huge headache when troubleshooting.

I hear you, and I agree that correlating these things across machines
is something we should be making easier. I'm just not convinced that
the particular format you've proposed, with a new set of rules for
quoting and escaping, needs to be part of this patch. (And I think
there are good reasons to truncate unverified cert data, so there'd
have to be clear benefits to offset the risk of opening it up.)

Searching Google for "issuer rdnSequence" comes up with mostly false
positives related to LDAP filtering and certificate dumps, and the
true positives seem to be mail threads that you've participated in. Do
many LDAP servers log certificate failures in this format by default?
(For that matter, does httpd?) The discussion at the time you added
this to httpd [1] seemed to be making the point that this was a niche
format, suited mostly for interaction with LDAP filters -- and Kaspar
additionally pointed out that it's not a canonical format, so all of
our implementations would have to have an ad hoc agreement to choose
exactly one encoding.

If you're using randomized serial numbers, you should be able to grep
for those by themselves and successfully match many different formats,
no? To me, that seems good enough for a first patch, considering we
don't currently log any of this information.

--Jacobfi

[1] https://lists.apache.org/thread/1665qc4mod7ppp58qk3bqc2l3wtl3lkn

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 08.07.22 20:39, Jacob Champion wrote:

I also added an optional 0002 that bubbles the error info up to the
final ereport(ERROR), using errdetail() and errhint(). I can squash it
into 0001 if you like it, or drop it if you don't. (This approach
could be adapted to the client, too.)


I squashed those two together.  I also adjusted the error message a bit 
more for project style.  (We can put both lines into detail.)


I had to read up on this "ex_data" API.  Interesting.  But I'm wondering 
a bit about how the life cycle of these objects is managed.  What 
happens if the allocated error string is deallocated before its 
containing object?  Or vice versa?  How do we ensure we don't 
accidentally reuse the error string when the code runs again?  (I guess 
currently it can't?)  Maybe we should avoid this and just put the 
errdetail itself into a static variable that we unset once the message 
is printed?From e9bbf69618bfea433a6916af9cdcc59f04b96eda Mon Sep 17 00:00:00 2001
From: Peter Eisentraut 
Date: Mon, 11 Jul 2022 14:28:43 +0200
Subject: [PATCH v5] Log details for client certificate failures

Currently, debugging client cert verification failures is mostly
limited to looking at the TLS alert code on the client side.  For
simple deployments, sometimes it's enough to see "sslv3 alert
certificate revoked" and know exactly what needs to be fixed, but if
you add any more complexity (multiple CA layers, misconfigured CA
certificates, etc.), trying to debug what happened based on the TLS
alert alone can be an exercise in frustration.

Luckily, the server has more information about exactly what failed in
the chain, and we already have the requisite callback implemented as a
stub.  Add an ex_data pointer to the SSL handle, so that we can store
error information from the verification callback.  This lets us add
our error details directly to the final "could not accept SSL
connection" log message, as opposed to issuing intermediate LOGs.

It ends up looking like

LOG:  connection received: host=localhost port=43112
LOG:  could not accept SSL connection: certificate verify failed
DETAIL:  Client certificate verification failed at depth 1: unable to get 
local issuer certificate.
Failed certificate data (unverified): subject "/CN=Test CA for 
PostgreSQL SSL regression test client certs", serial number 
2315134995201656577, issuer "/CN=Test root CA for PostgreSQL SSL regression 
test suite".

The length of the Subject and Issuer strings is limited to prevent
malicious client certs from spamming the logs.  In case the truncation
makes things ambiguous, the certificate's serial number is also
logged.

Author: Jacob Champion 
Discussion: 
https://www.postgresql.org/message-id/flat/d13c4a5787c2a3f83705124f0391e0738c796751.ca...@vmware.com
---
 src/backend/libpq/be-secure-openssl.c | 132 +-
 src/test/ssl/conf/client-long.config  |  14 +++
 src/test/ssl/ssl/client-long.crt  |  20 
 src/test/ssl/ssl/client-long.key  |  27 ++
 src/test/ssl/sslfiles.mk  |   2 +-
 src/test/ssl/t/001_ssltests.pl|  40 +++-
 src/test/ssl/t/SSL/Backend/OpenSSL.pm |   2 +-
 7 files changed, 230 insertions(+), 7 deletions(-)
 create mode 100644 src/test/ssl/conf/client-long.config
 create mode 100644 src/test/ssl/ssl/client-long.crt
 create mode 100644 src/test/ssl/ssl/client-long.key

diff --git a/src/backend/libpq/be-secure-openssl.c 
b/src/backend/libpq/be-secure-openssl.c
index 3d0168a369..8d5eee0d16 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -81,6 +81,14 @@ static bool ssl_is_server_start;
 static int ssl_protocol_version_to_openssl(int v);
 static const char *ssl_protocol_version_to_string(int v);
 
+/* Helpers for storing application data in the SSL handle */
+struct pg_ex_data
+{
+   /* to bubble errors out of callbacks */
+   char   *errdetail;
+};
+static int ssl_ex_index;
+
 /*  */
 /*  Public interface   
*/
 /*  */
@@ -102,6 +110,7 @@ be_tls_init(bool isServerStart)
SSL_library_init();
SSL_load_error_strings();
 #endif
+   ssl_ex_index = SSL_get_ex_new_index(0, NULL, NULL, NULL, NULL);
SSL_initialized = true;
}
 
@@ -413,6 +422,7 @@ be_tls_open_server(Port *port)
int err;
int waitfor;
unsigned long ecode;
+   struct pg_ex_data exdata = {0};
boolgive_proto_hint;
 
Assert(!port->ssl);
@@ -445,6 +455,15 @@ be_tls_open_server(Port *port)

SSLerrmessage(ERR_get_error();
return -1;
}
+   if (!SSL_set_ex_data(port->ssl, ssl_ex_index, ))

Re: [PATCH] Log details for client certificate failures

[Graham Leggett]

On 01 Jul 2022, at 22:59, Jacob Champion  wrote:

>> I added this to httpd a while back:
>> 
>> SSL_CLIENT_CERT_RFC4523_CEA
>> 
>> It would be good to interoperate.
> 
> What kind of interoperation did you have in mind? Are there existing
> tools that want to scrape this information for observability?

This is for human troubleshooting.

> I think the CEA syntax might not be a good fit for this particular
> patch: first, we haven't actually verified the certificate, so no one
> should be using it to assert certificate equality (and I'm truncating
> the Issuer anyway, to avoid letting someone flood the logs). Second,
> this is designed to be human-readable rather than machine-readable.

This is what a CEA looks like:

{ serialNumber 400410167207191393705333222102472642510002355884, issuer 
rdnSequence:”CN=Foo UK G1,O=Foo,C=UK" }

Whitespace and escaping is important above.

When troubleshooting, you want a string like the above that you can cut and 
paste and search for in other systems and log files. The verification status of 
the cert isn’t an issue at this point, you have a system in front of you where 
it doesn’t work when it should, and you need to know exactly what’s connecting, 
not what you think you’re connecting to, and you need precise data.

Please don’t invent another format, or try and truncate the data. This is a 
huge headache when troubleshooting.

Regards,
Graham
—

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Thu, Jul 7, 2022 at 2:50 AM Peter Eisentraut
 wrote:
> I looked into how you decode the serial number.  I have found some code
> elsewhere that passed the result of X509_get_serialNumber() directly to
> ASN1_INTEGER_set().  But I guess a serial number of maximum length 20
> octets wouldn't fit into a 32-bit long.  (There is
> ASN1_INTEGER_set_int64(), but that requires OpenSSL 1.1.0.)  Does that
> match your understanding?

Yep. And the bit lengths of the serial numbers used in the test suite
are in the low 60s already. Many people will just randomize their
serial numbers, so I think BN_bn2dec() is the way to go.

> For the detail string, I think we could do something like:
>
> DETAIL:  Failed certificate data (unverified): subject '%s', serial
> number %s, issuer '%s'

Done that way in v4.

I also added an optional 0002 that bubbles the error info up to the
final ereport(ERROR), using errdetail() and errhint(). I can squash it
into 0001 if you like it, or drop it if you don't. (This approach
could be adapted to the client, too.)

Thanks!
--Jacob
commit 7489e52168b76df3a84c68d79fb22651a05a0c05
Author: Jacob Champion 
Date:   Fri Jul 8 09:19:32 2022 -0700

squash! Log details for client certificate failures

Change detail message, per review.

diff --git a/src/backend/libpq/be-secure-openssl.c 
b/src/backend/libpq/be-secure-openssl.c
index 80b361b105..a2cbcdad5f 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -1173,9 +1173,10 @@ verify_cb(int ok, X509_STORE_CTX *ctx)
(errmsg("client certificate verification failed at 
depth %d: %s",
depth, errstring),
 /* only print detail if we have a certificate to print 
*/
-subject && errdetail("failed certificate had subject 
'%s', "
+subject && errdetail("Failed certificate data 
(unverified): "
+   
"subject '%s', "
"serial 
number %s, "
-   
"purported issuer '%s'",
+   "issuer 
'%s'",
  sub_truncated 
? sub_truncated : subject,
  serialno ? 
serialno : _("unknown"),
  iss_truncated 
? iss_truncated : issuer)));
diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl
index a9b737ed09..0f837e1b9f 100644
--- a/src/test/ssl/t/001_ssltests.pl
+++ b/src/test/ssl/t/001_ssltests.pl
@@ -685,7 +685,7 @@ $node->connect_fails(
expected_stderr => qr/SSL error: sslv3 alert certificate revoked/,
log_like => [
qr/client certificate verification failed at depth 0: 
certificate revoked/,
-   qr/failed certificate had subject '\/CN=ssltestuser', serial 
number 2315134995201656577, purported issuer '\/CN=Test CA for PostgreSQL SSL 
regression test client certs'/,
+   qr/Failed certificate data \(unverified\): subject 
'\/CN=ssltestuser', serial number 2315134995201656577, issuer '\/CN=Test CA for 
PostgreSQL SSL regression test client certs'/,
],
# revoked certificates should not authenticate the user
log_unlike => [qr/connection authenticated:/],);
@@ -737,7 +737,7 @@ $node->connect_fails(
expected_stderr => qr/SSL error: tlsv1 alert unknown ca/,
log_like => [
qr/client certificate verification failed at depth 0: unable to 
get local issuer certificate/,
-   qr/failed certificate had subject '\/CN=ssltestuser', serial 
number 2315134995201656576, purported issuer '\/CN=Test CA for PostgreSQL SSL 
regression test client certs'/,
+   qr/Failed certificate data \(unverified\): subject 
'\/CN=ssltestuser', serial number 2315134995201656576, issuer '\/CN=Test CA for 
PostgreSQL SSL regression test client certs'/,
]);
 
 $node->connect_fails(
@@ -746,7 +746,7 @@ $node->connect_fails(
expected_stderr => qr/SSL error: tlsv1 alert unknown ca/,
log_like => [
qr/client certificate verification failed at depth 0: unable to 
get local issuer certificate/,
-   qr/failed certificate had subject 
'\.\.\.\/CN=ssl-123456789012345678901234567890123456789012345678901234567890', 
serial number 2315418733629425152, purported issuer '\/CN=Test CA for 
PostgreSQL SSL regression test client certs'/,
+   qr/Failed certificate data \(unverified\): subject 
'\.\.\.\/CN=ssl-123456789012345678901234567890123456789012345678901234567890', 
serial number 2315418733629425152, issuer '\/CN=Test CA for PostgreSQL SSL 
regression test client 

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 05.07.22 18:34, Jacob Champion wrote:

On Fri, Jul 1, 2022 at 1:51 PM Jacob Champion  wrote:

Sorry for the misunderstanding! v3 adds the Issuer to the logs as well.


Resending v3; I messed up the certificate diff with my gitconfig.


This patch looks pretty good to me.  Some minor details:

I looked into how you decode the serial number.  I have found some code 
elsewhere that passed the result of X509_get_serialNumber() directly to 
ASN1_INTEGER_set().  But I guess a serial number of maximum length 20 
octets wouldn't fit into a 32-bit long.  (There is 
ASN1_INTEGER_set_int64(), but that requires OpenSSL 1.1.0.)  Does that 
match your understanding?


For the detail string, I think we could do something like:

DETAIL:  Failed certificate data (unverified): subject '%s', serial 
number %s, issuer '%s'

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Fri, Jul 1, 2022 at 1:51 PM Jacob Champion  wrote:
> Sorry for the misunderstanding! v3 adds the Issuer to the logs as well.

Resending v3; I messed up the certificate diff with my gitconfig.

--Jacob
From 8d03e043cd86ec81dfb49a138e871c5ac110dc06 Mon Sep 17 00:00:00 2001
From: Jacob Champion 
Date: Mon, 29 Mar 2021 10:07:31 -0700
Subject: [PATCH v3] Log details for client certificate failures

Currently, debugging client cert verification failures is mostly limited
to looking at the TLS alert code on the client side. For simple
deployments, sometimes it's enough to see "sslv3 alert certificate
revoked" and know exactly what needs to be fixed, but if you add any
more complexity (multiple CA layers, misconfigured CA certificates,
etc.), trying to debug what happened based on the TLS alert alone can be
an exercise in frustration.

Luckily, the server has more information about exactly what failed in
the chain, and we already have the requisite callback implemented as a
stub. Fill it out with error handling and add a COMMERROR log so that a
DBA can debug client failures more easily. It ends up looking like

LOG:  connection received: host=localhost port=44120
LOG:  client certificate verification failed at depth 1: unable to get local issuer certificate
DETAIL:  failed certificate had subject '/CN=Test CA for PostgreSQL SSL regression test client certs', serial number 2315134995201656577, purported issuer '/CN=Root CA'
LOG:  could not accept SSL connection: certificate verify failed

The length of the Subject and Issuer strings is limited to prevent
malicious client certs from spamming the logs. In case the truncation
makes things ambiguous, the certificate's serial number is also logged.
---
 src/backend/libpq/be-secure-openssl.c | 101 +-
 src/test/ssl/conf/client-long.config  |  14 
 src/test/ssl/ssl/client-long.crt  |  20 +
 src/test/ssl/ssl/client-long.key  |  27 +++
 src/test/ssl/sslfiles.mk  |   2 +-
 src/test/ssl/t/001_ssltests.pl|  40 +-
 src/test/ssl/t/SSL/Backend/OpenSSL.pm |   2 +-
 7 files changed, 200 insertions(+), 6 deletions(-)
 create mode 100644 src/test/ssl/conf/client-long.config
 create mode 100644 src/test/ssl/ssl/client-long.crt
 create mode 100644 src/test/ssl/ssl/client-long.key

diff --git a/src/backend/libpq/be-secure-openssl.c b/src/backend/libpq/be-secure-openssl.c
index 3d0168a369..80b361b105 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -1076,12 +1076,45 @@ dummy_ssl_passwd_cb(char *buf, int size, int rwflag, void *userdata)
 	return 0;
 }
 
+/*
+ * Examines the provided certificate name, and if it's too long to log, modifies
+ * and truncates it. The return value is NULL if no truncation was needed; it
+ * otherwise points into the middle of the input string, and should not be
+ * freed.
+ */
+static char *
+truncate_cert_name(char *name)
+{
+	size_t		namelen = strlen(name);
+	char	   *truncated;
+
+	/*
+	 * Common Names are 64 chars max, so for a common case where the CN is the
+	 * last field, we can still print the longest possible CN with a 7-character
+	 * prefix (".../CN=[64 chars]"), for a reasonable limit of 71 characters.
+	 */
+#define MAXLEN 71
+
+	if (namelen <= MAXLEN)
+		return NULL;
+
+	/*
+	 * Keep the end of the name, not the beginning, since the most specific
+	 * field is likely to give users the most information.
+	 */
+	truncated = name + namelen - MAXLEN;
+	truncated[0] = truncated[1] = truncated[2] = '.';
+
+#undef MAXLEN
+
+	return truncated;
+}
+
 /*
  *	Certificate verification callback
  *
  *	This callback allows us to log intermediate problems during
- *	verification, but for now we'll see if the final error message
- *	contains enough information.
+ *	verification.
  *
  *	This callback also allows us to override the default acceptance
  *	criteria (e.g., accepting self-signed or expired certs), but
@@ -1090,6 +1123,70 @@ dummy_ssl_passwd_cb(char *buf, int size, int rwflag, void *userdata)
 static int
 verify_cb(int ok, X509_STORE_CTX *ctx)
 {
+	int			depth;
+	int			errcode;
+	const char *errstring;
+	X509	   *cert;
+	char	   *subject = NULL, *issuer = NULL;
+	char	   *sub_truncated = NULL, *iss_truncated = NULL;
+	char	   *serialno = NULL;
+
+	if (ok)
+	{
+		/* Nothing to do for the successful case. */
+		return ok;
+	}
+
+	/* Pull all the information we have on the verification failure. */
+	depth = X509_STORE_CTX_get_error_depth(ctx);
+	errcode = X509_STORE_CTX_get_error(ctx);
+	errstring = X509_verify_cert_error_string(errcode);
+
+	cert = X509_STORE_CTX_get_current_cert(ctx);
+	if (cert)
+	{
+		ASN1_INTEGER *sn;
+		BIGNUM	   *b;
+
+		/*
+		 * Get the Subject and Issuer for logging, but don't let maliciously
+		 * huge certs flood the logs.
+		 */
+		subject = X509_NAME_to_cstring(X509_get_subject_name(cert));
+		sub_truncated = truncate_cert_name(subject);
+
+		issuer = 

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Thu, Jun 30, 2022 at 2:54 AM Graham Leggett  wrote:
>
> I added this to httpd a while back:
>
> SSL_CLIENT_CERT_RFC4523_CEA
>
> It would be good to interoperate.

What kind of interoperation did you have in mind? Are there existing
tools that want to scrape this information for observability?

I think the CEA syntax might not be a good fit for this particular
patch: first, we haven't actually verified the certificate, so no one
should be using it to assert certificate equality (and I'm truncating
the Issuer anyway, to avoid letting someone flood the logs). Second,
this is designed to be human-readable rather than machine-readable.

Thanks,
--Jacob

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Thu, Jun 30, 2022 at 2:43 AM Peter Eisentraut
 wrote:
>
> On 13.05.22 00:36, Jacob Champion wrote:
> > v2 limits the maximum subject length and adds the serial number to the
> > logs.
>
> I wrote that pg_stat_ssl uses the *issuer* plus serial number to
> identify a certificate.  What your patch shows is the subject and the
> serial number, which isn't the same thing.  Let's get that sorted out
> one way or the other.

Sorry for the misunderstanding! v3 adds the Issuer to the logs as well.

I wanted to clarify that this "issuer" has not actually been verified,
but all I could come up with was "purported issuer" which doesn't read
well to me. "Claimed issuer"? "Alleged issuer"? Thoughts?

> Another point, your patch produces
>
>  LOG:  connection received: host=localhost port=44120
>  LOG:  client certificate verification failed at depth 1: ...
>  DETAIL:  failed certificate had subject ...
>  LOG:  could not accept SSL connection: certificate verify failed
>
> I guess what we really would like is
>
>  LOG:  connection received: host=localhost port=44120
>  LOG:  could not accept SSL connection: certificate verify failed
>  DETAIL:  client certificate verification failed at depth 1: ...
>  failed certificate had subject ...
>
> But I suppose that would be very cumbersome to produce with the callback
> structure provided by OpenSSL?

I was about to say "yes, very cumbersome", but I actually think we
might be able to do that without bubbling the error up through
multiple callback layers, using SSL_set_ex_data() and friends. I'll
take a closer look.

Thanks!
--Jacob
commit dfe12fa0c3b93cf98169da2095e53edd79c936e6
Author: Jacob Champion 
Date:   Fri Jul 1 13:39:34 2022 -0700

squash! Log details for client certificate failures

Add the Issuer to the log.

diff --git a/src/backend/libpq/be-secure-openssl.c 
b/src/backend/libpq/be-secure-openssl.c
index 3ccc23ba62..80b361b105 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -1076,6 +1076,40 @@ dummy_ssl_passwd_cb(char *buf, int size, int rwflag, 
void *userdata)
return 0;
 }
 
+/*
+ * Examines the provided certificate name, and if it's too long to log, 
modifies
+ * and truncates it. The return value is NULL if no truncation was needed; it
+ * otherwise points into the middle of the input string, and should not be
+ * freed.
+ */
+static char *
+truncate_cert_name(char *name)
+{
+   size_t  namelen = strlen(name);
+   char   *truncated;
+
+   /*
+* Common Names are 64 chars max, so for a common case where the CN is 
the
+* last field, we can still print the longest possible CN with a 
7-character
+* prefix (".../CN=[64 chars]"), for a reasonable limit of 71 
characters.
+*/
+#define MAXLEN 71
+
+   if (namelen <= MAXLEN)
+   return NULL;
+
+   /*
+* Keep the end of the name, not the beginning, since the most specific
+* field is likely to give users the most information.
+*/
+   truncated = name + namelen - MAXLEN;
+   truncated[0] = truncated[1] = truncated[2] = '.';
+
+#undef MAXLEN
+
+   return truncated;
+}
+
 /*
  * Certificate verification callback
  *
@@ -1093,8 +1127,8 @@ verify_cb(int ok, X509_STORE_CTX *ctx)
int errcode;
const char *errstring;
X509   *cert;
-   char   *certname = NULL;
-   char   *truncated = NULL;
+   char   *subject = NULL, *issuer = NULL;
+   char   *sub_truncated = NULL, *iss_truncated = NULL;
char   *serialno = NULL;
 
if (ok)
@@ -,33 +1145,18 @@ verify_cb(int ok, X509_STORE_CTX *ctx)
cert = X509_STORE_CTX_get_current_cert(ctx);
if (cert)
{
-   size_t  namelen;
ASN1_INTEGER *sn;
BIGNUM *b;
 
/*
-* Get the Subject for logging, but don't let maliciously huge 
certs
-* flood the logs.
-*
-* Common Names are 64 chars max, so for a common case where 
the CN is
-* the last field, we can still print the longest possible CN 
with a
-* 7-character prefix (".../CN=[64 chars]"), for a reasonable 
limit of
-* 71 characters.
+* Get the Subject and Issuer for logging, but don't let 
maliciously
+* huge certs flood the logs.
 */
-#define MAXLEN 71
-   certname = X509_NAME_to_cstring(X509_get_subject_name(cert));
-   namelen = strlen(certname);
+   subject = X509_NAME_to_cstring(X509_get_subject_name(cert));
+   sub_truncated = truncate_cert_name(subject);
 
-   if (namelen > MAXLEN)
-   {
-   /*
-* Keep the end of the Subject, not the beginning, 
since the most
-  

Re: [PATCH] Log details for client certificate failures

[Graham Leggett]

On 30 Jun 2022, at 10:43, Peter Eisentraut  
wrote:

> I wrote that pg_stat_ssl uses the *issuer* plus serial number to identify a 
> certificate.  What your patch shows is the subject and the serial number, 
> which isn't the same thing.  Let's get that sorted out one way or the other.

Quick observation on this one, the string format of an issuer and serial number 
is defined as a “Certificate Exact Assertion” in RFC 4523.

I added this to httpd a while back:

SSL_CLIENT_CERT_RFC4523_CEA

It would be good to interoperate.

Regards,
Graham
—

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 13.05.22 00:36, Jacob Champion wrote:

On Thu, 2022-05-05 at 15:12 +, Jacob Champion wrote:

On Wed, 2022-05-04 at 15:53 +0200, Peter Eisentraut wrote:

In terms of aligning what is printed, I meant that pg_stat_ssl uses the
issuer plus serial number to identify the certificate unambiguously.


Oh, that's a great idea. I'll do that too.


v2 limits the maximum subject length and adds the serial number to the
logs.


I wrote that pg_stat_ssl uses the *issuer* plus serial number to 
identify a certificate.  What your patch shows is the subject and the 
serial number, which isn't the same thing.  Let's get that sorted out 
one way or the other.


Another point, your patch produces

LOG:  connection received: host=localhost port=44120
LOG:  client certificate verification failed at depth 1: ...
DETAIL:  failed certificate had subject ...
LOG:  could not accept SSL connection: certificate verify failed

I guess what we really would like is

LOG:  connection received: host=localhost port=44120
LOG:  could not accept SSL connection: certificate verify failed
DETAIL:  client certificate verification failed at depth 1: ...
failed certificate had subject ...

But I suppose that would be very cumbersome to produce with the callback 
structure provided by OpenSSL?


I'm not saying the proposed way is unacceptable, but maybe it's worth 
being explicit about this tradeoff.

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Thu, 2022-05-05 at 15:12 +, Jacob Champion wrote:
> On Wed, 2022-05-04 at 15:53 +0200, Peter Eisentraut wrote:
> > In terms of aligning what is printed, I meant that pg_stat_ssl uses the
> > issuer plus serial number to identify the certificate unambiguously.
> 
> Oh, that's a great idea. I'll do that too.

v2 limits the maximum subject length and adds the serial number to the
logs.

Thanks!
--Jacob
commit eb5ddc1d8909fe322ddeb1ec4bf9118bb9544667
Author: Jacob Champion 
Date:   Wed May 11 10:33:33 2022 -0700

squash! Log details for client certificate failures

- Add a maximum Subject length to prevent malicious client certs from
  spamming the logs.

- Add the certificate serial number to the output, for disambiguation if
  the Subject gets truncated unhelpfully.

diff --git a/src/backend/libpq/be-secure-openssl.c 
b/src/backend/libpq/be-secure-openssl.c
index 1683f9cc9e..3ccc23ba62 100644
--- a/src/backend/libpq/be-secure-openssl.c
+++ b/src/backend/libpq/be-secure-openssl.c
@@ -1094,6 +1094,8 @@ verify_cb(int ok, X509_STORE_CTX *ctx)
const char *errstring;
X509   *cert;
char   *certname = NULL;
+   char   *truncated = NULL;
+   char   *serialno = NULL;
 
if (ok)
{
@@ -1108,14 +1110,56 @@ verify_cb(int ok, X509_STORE_CTX *ctx)
 
cert = X509_STORE_CTX_get_current_cert(ctx);
if (cert)
+   {
+   size_t  namelen;
+   ASN1_INTEGER *sn;
+   BIGNUM *b;
+
+   /*
+* Get the Subject for logging, but don't let maliciously huge 
certs
+* flood the logs.
+*
+* Common Names are 64 chars max, so for a common case where 
the CN is
+* the last field, we can still print the longest possible CN 
with a
+* 7-character prefix (".../CN=[64 chars]"), for a reasonable 
limit of
+* 71 characters.
+*/
+#define MAXLEN 71
certname = X509_NAME_to_cstring(X509_get_subject_name(cert));
+   namelen = strlen(certname);
+
+   if (namelen > MAXLEN)
+   {
+   /*
+* Keep the end of the Subject, not the beginning, 
since the most
+* specific field is likely to give users the most 
information.
+*/
+   truncated = certname + namelen - MAXLEN;
+   truncated[0] = truncated[1] = truncated[2] = '.';
+   }
+#undef MAXLEN
+
+   /*
+* Pull the serial number, too, in case a Subject is still 
ambiguous.
+* This mirrors be_tls_get_peer_serial().
+*/
+   sn = X509_get_serialNumber(cert);
+   b = ASN1_INTEGER_to_BN(sn, NULL);
+   serialno = BN_bn2dec(b);
+
+   BN_free(b);
+   }
 
ereport(COMMERROR,
(errmsg("client certificate verification failed at 
depth %d: %s",
depth, errstring),
 /* only print detail if we have a certificate to print 
*/
-certname && errdetail("failed certificate's subject: 
%s", certname)));
+certname && errdetail("failed certificate had subject 
'%s', serial number %s",
+  truncated ? 
truncated : certname,
+  serialno ? 
serialno : _("unknown";
 
+   if (serialno)
+   OPENSSL_free(serialno);
if (certname)
pfree(certname);
 
diff --git a/src/test/ssl/conf/client-long.config 
b/src/test/ssl/conf/client-long.config
new file mode 100644
index 00..0e92a8fbfe
--- /dev/null
+++ b/src/test/ssl/conf/client-long.config
@@ -0,0 +1,14 @@
+# An OpenSSL format CSR config file for creating a client certificate with a
+# long Subject.
+
+[ req ]
+distinguished_name = req_distinguished_name
+prompt = no
+
+[ req_distinguished_name ]
+# Common Names are 64 characters max
+CN = 
ssl-123456789012345678901234567890123456789012345678901234567890
+OU = Some Organizational Unit
+O  = PostgreSQL Global Development Group
+
+# no extensions in client certs
diff --git a/src/test/ssl/ssl/client-long.crt b/src/test/ssl/ssl/client-long.crt
new file mode 100644
index 00..a1db55b5c3
--- /dev/null
+++ b/src/test/ssl/ssl/client-long.crt
@@ -0,0 +1,69 @@
+Certificate:
+Data:
+Version: 1 (0x0)
+Serial Number: 2315418733629425152 (0x202205121600)
+Signature Algorithm: sha256WithRSAEncryption
+Issuer: CN = Test CA for PostgreSQL SSL regression test client certs
+Validity
+Not Before: May 12 21:44:47 

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Wed, 2022-05-04 at 15:53 +0200, Peter Eisentraut wrote:
> Just saying that cutting it off appears to be acceptable.  A bit more
> than 63 bytes should be okay for the log.

Gotcha.

> In terms of aligning what is printed, I meant that pg_stat_ssl uses the
> issuer plus serial number to identify the certificate unambiguously.

Oh, that's a great idea. I'll do that too.

Thanks!
--Jacob

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 04.05.22 01:05, Jacob Champion wrote:

On Tue, 2022-05-03 at 21:06 +0200, Peter Eisentraut wrote:

The information in pg_stat_ssl is limited to NAMEDATALEN (see struct
PgBackendSSLStatus).

It might make sense to align what your patch prints to identify
certificates with what is shown in that view.


Sure, a max length should be easy enough to do. Is there a reason to
limit to NAMEDATALEN specifically? I was under the impression that we
would rather not have had that limitation in the stats framework, if we
could have avoided it. (In particular I think NAMEDATALEN will cut off
the longest possible Common Name by just five bytes.)


Just saying that cutting it off appears to be acceptable.  A bit more 
than 63 bytes should be okay for the log.


In terms of aligning what is printed, I meant that pg_stat_ssl uses the 
issuer plus serial number to identify the certificate unambiguously.

Re: [PATCH] Log details for client certificate failures

[Jacob Champion]

On Tue, 2022-05-03 at 21:06 +0200, Peter Eisentraut wrote:
> The information in pg_stat_ssl is limited to NAMEDATALEN (see struct
> PgBackendSSLStatus).
> 
> It might make sense to align what your patch prints to identify
> certificates with what is shown in that view.

Sure, a max length should be easy enough to do. Is there a reason to
limit to NAMEDATALEN specifically? I was under the impression that we
would rather not have had that limitation in the stats framework, if we
could have avoided it. (In particular I think NAMEDATALEN will cut off
the longest possible Common Name by just five bytes.)

Thanks,
--Jacob

Re: [PATCH] Log details for client certificate failures

[Peter Eisentraut]

On 03.05.22 19:04, Jacob Champion wrote:

One question/concern -- the Subject that's printed to the logs could be
pretty big (OpenSSL limits the incoming certificate chain to 100K, by
default), which introduces an avenue for intentional log spamming. Is
there an existing convention for limiting the length of log output used
for debugging? Maybe I should just hardcode a smaller limit and
truncate anything past that? Or we could just log the Common Name,
which should be limited to 64 bytes...


The information in pg_stat_ssl is limited to NAMEDATALEN (see struct 
PgBackendSSLStatus).


It might make sense to align what your patch prints to identify 
certificates with what is shown in that view.