Hi, On 2023-12-08 11:33:16 -0800, Andres Freund wrote: > On 2023-12-08 10:51:01 -0800, Andres Freund wrote: > > On 2023-12-08 13:46:07 -0500, Tom Lane wrote: > > > Andres Freund <and...@anarazel.de> writes: > > > > On 2023-12-08 13:23:50 -0500, Tom Lane wrote: > > > >> Hmm, don't suppose you have a way to reproduce that? > > > > > > > After a bit of trying, yes. I put an abort() into pgtls_open_client(), > > > > after > > > > initialize_SSL(). Connecting does result in: > > > > LOG: could not accept SSL connection: Success > > > > > > OK. I can dig into that, unless you're already on it? > > [...] > > Seems like we should just treat errno == 0 as a reason to emit the "EOF > detected" message?
I thought it'd be nice to have a test for this, particularly because it's not clear that the behaviour is consistent across openssl versions. I couldn't think of a way to do that with psql. But it's just a few lines of perl to gin up an "SSL" startup packet and then close the socket. I couldn't quite figure out when IO::Socket::INET was added, but I think it's likely been long enough, I see references from 1999. This worked easily on linux and freebsd, but not on windows and macos, where it seems to cause ECONNRESET. I thought that explicitly shutting down the socket might help, but that just additionally caused freebsd to fail. Windows uses an older openssl, so it could also be caused by the behaviour differing back then. To deal with that, I changed the test to instead check if "not accept SSL connection: Success" is not logged. I'm not sure that actually would be logged on windows, it does seem to have different strings for errors than other platforms. Greetings, Andres Freund
>From d5133a5783b743c0235e016dcb438d2dda82a07b Mon Sep 17 00:00:00 2001 From: Andres Freund <and...@anarazel.de> Date: Fri, 8 Dec 2023 13:09:38 -0800 Subject: [PATCH v1] WIP: Fix error message for client disconnects during SSL startup Author: Reviewed-by: Discussion: https://postgr.es/m/20231208193316.5ylgs4zb6zngw...@awork3.anarazel.de Backpatch: --- src/backend/libpq/be-secure-openssl.c | 7 ++++- src/test/ssl/t/001_ssltests.pl | 42 +++++++++++++++++++++++++++ 2 files changed, 48 insertions(+), 1 deletion(-) diff --git a/src/backend/libpq/be-secure-openssl.c b/src/backend/libpq/be-secure-openssl.c index 6b8125695a3..3c182c2d3a4 100644 --- a/src/backend/libpq/be-secure-openssl.c +++ b/src/backend/libpq/be-secure-openssl.c @@ -496,7 +496,12 @@ aloop: WAIT_EVENT_SSL_OPEN_SERVER); goto aloop; case SSL_ERROR_SYSCALL: - if (r < 0) + /* + * If errno is 0, the client closed the socket without + * shutting down the SSL connection, e.g. because the client + * terminated. + */ + if (r < 0 && errno != 0) ereport(COMMERROR, (errcode_for_socket_access(), errmsg("could not accept SSL connection: %m"))); diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl index d921f1dde9f..e23300b318e 100644 --- a/src/test/ssl/t/001_ssltests.pl +++ b/src/test/ssl/t/001_ssltests.pl @@ -213,6 +213,48 @@ $node->connect_fails( ? qr/server accepted connection without a valid SSL certificate/ : qr/sslcertmode value "require" is not supported/); + +# Check log message makes sense when initiating SSL connection establishment +# but then closing the socket immediately. In the past that sometimes was +# logged as "could not accept SSL connection: Success", which is misleading. +# Such disconnects happens regularly in real workloads, but can't easily be +# tested with psql. Therefore just establish the connection the hard way - +# it's easy enough here, because we just need to send a startup packet asking +# for SSL to be initiated. +{ + use IO::Socket::INET; + + my $sock = IO::Socket::INET->new( + PeerAddr => $SERVERHOSTADDR, + PeerPort => $node->port, + Proto => 'tcp'); + + my $log_location = -s $node->logfile; + + # ssl request is message length as 32 bit big endian, 4 byte magic "ssl" + # protocol version, terminated by a 0 byte. + my $message = pack "NNx", 4 + 4 + 1, (1234 << 16) | 5679; + + $sock->send($message); + $sock->close(); + + # On at least macos and windows closing the socket leads to a ECONNRESET + # on the server side. Therefore we don't check if the right message is + # logged, but that the "Success" message isn't. + # + # First wait for the connection attempt to be logged, so we can test for + # the absence of the "Success" message without a race. + ok( $node->wait_for_log( + qr/could not accept SSL connection:/, + $log_location), + 'aborted connection attempt is logged'); + + $node->log_check("aborted connection attempt is logged as failure", + $log_location, + (log_unlike => [qr/could not accept SSL connection: Success/])); +} + + # CRL tests # Invalid CRL filename is the same as no CRL, succeeds -- 2.38.0
