Thank you, Peter.
It makes more sense now, and I'm so glad someone else is able to reproduce this.
To clarify on why I consider this a problem - It is not just the alerts on monitoring system. The alerts themselves can be tuned / thresholds increased etc. The real issue (could argue this is non-issue), is the noise..
If something start to not work as expected besides this "inconvenience" and start to produce TCP resets as well, this could potentially diminish the troubleshooting tool visibility.
That said. Now that someone else is able to reproduce this and I more clarity as to what may be going on (can explain to team), I can consider this as "known behaviour".
Hopefully this will be addressed someday, but until then, we'll just have to live with it. :)
Med vennlig hilsen.
Best regards, Janis Puris.
On 27 Apr 2019, 12:55 +0200, Peter J. Holzer <hjp-pgsql@xxxxxx>, wrote:
On 2019-04-26 18:36:12 +0200, Jānis Pūris wrote:
Thanks for the insight, Tom.
It's fairly obvious from the postmaster log that the client side
is not bothering to close the transaction it started
Thats what I was also thinking, but I've managed to reproduce it with
autocommit or commit before closing connection as well.
This is only reproducible with SSL connection.
I've reproduced it with ubuntu package bundles certs, my own created, generated
with CA etc hence I do not think it is a problem with certificates themselves.
This happens with various clients, php driver, java driver and also libpq used
by psycopg2. We are running a lot of different kind of microservices and thus
far I can tell, almost (if not all) of them have this problem manifest.
I can not however reproduce this when doing something like
$ psql "user=postgres sslmode=require host=localhost dbname=postgres"
postgres=# \q
I can reproduce it in this case also (kernel 4.9, openssl 1.1.0j,
posgres 9.5.16).
stracing psql shows this:
send(3, "\27\3\3\0\35fV\354\31v\332\10\22\202-#8\5\267\5\202\346\3748\353\326&\374\rf\2776"..., 34, MSG_NOSIGNAL) = 34
send(3, "\25\3\3\0\32fV\354\31v\332\10\23\307\207\335V\355Lhh\"\214\331\25l\352\27\32\332\357", 31, MSG_NOSIGNAL) = 31
close(3) = 0
I.e., psql sends some data (presumably a TLS close_notify alert) and
then closes the file descriptor.
tcpdump shows this:
12:30:02.276188 IP6 localhost.47712 > localhost.postgresql: Flags [P.], seq 414:445, ack 1239, win 360, options [nop,nop,TS val 337416186 ecr 337416186], length 31
12:30:02.276243 IP6 localhost.47712 > localhost.postgresql: Flags [F.], seq 445, ack 1239, win 360, options [nop,nop,TS val 337416186 ecr 337416186], length 0
12:30:02.276306 IP6 localhost.postgresql > localhost.47712: Flags [P.], seq 1239:1270, ack 446, win 350, options [nop,nop,TS val 337416186 ecr 337416186], length 31
12:30:02.276315 IP6 localhost.47712 > localhost.postgresql: Flags [R], seq 2477517213, win 0, length 0
The first packet shown are the 31 bytes of the second send, then the
cliens sends a FIN packet. Then the server replies with a packet of the
same length (so presumably also a close_notify alert). Since the client
has already closed the connection, it replies with a RST.
One might argue that openssl should wait for the other side to reply
before closing the connection. But waiting doesn't really accomplish
anything from the application's point of view and introduces and
unnecessary delay.
This is an issue because we have a lot of connections being initiated and
closed. And this creates a lot of TCP resets.
Why are those resets a problem? (If the answer is "our monitoring
software complains about them" then the question becomes "why does your
monitoring software think they are a problem?")
hp
--
_ | Peter J. Holzer | we build much bigger, better disasters now
|_|_) | | because we have much more sophisticated
| | | hjp@xxxxxx | management tools.
__/ | http://www.hjp.at/ | -- Ross Anderson <https://www.edge.org/>
