From: | Daniel Gustafsson <daniel(at)yesql(dot)se> |
---|---|
To: | Postgres hackers <pgsql-hackers(at)lists(dot)postgresql(dot)org> |
Subject: | OpenSSL connection setup debug callback issue |
Date: | 2020-12-10 13:43:33 |
Message-ID: | 232CF476-94E1-42F1-9408-719E2AEC5491@yesql.se |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-hackers |
I went looking at the SSL connection state change information callback we
install when setting up connections with OpenSSL, and I wasn't getting the
state changes I expected. Turns out we install it at the tail end of setting
up the connection so we miss most of the calls. Moving it to the beginning of
be_tls_open_server allows us to catch the handshake etc. I also extended it by
printing the human readable state change message available from OpenSSL to make
the logs more detailed (SSL_state_string_long has existed since 0.9.8).
A randomly selected sequence from a src/test/ssl testrun with the callback
moved but not extended with state information:
LOG: connection received: host=localhost port=51177
DEBUG: SSL: handshake start
DEBUG: SSL: accept loop
DEBUG: SSL: accept exit (-1)
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept exit (-1)
DEBUG: SSL: accept exit (-1)
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: accept loop
DEBUG: SSL: handshake done
DEBUG: SSL: accept exit (1)
DEBUG: SSL connection from "(anonymous)"
The same sequence with the patch applied:
LOG: connection received: host=localhost port=51177
DEBUG: SSL: handshake start: "before/accept initialization"
DEBUG: SSL: accept loop: "before/accept initialization"
DEBUG: SSL: accept exit (-1): "SSLv2/v3 read client hello A"
DEBUG: SSL: accept loop: "SSLv3 read client hello A"
DEBUG: SSL: accept loop: "SSLv3 write server hello A"
DEBUG: SSL: accept loop: "SSLv3 write certificate A"
DEBUG: SSL: accept loop: "SSLv3 write key exchange A"
DEBUG: SSL: accept loop: "SSLv3 write certificate request A"
DEBUG: SSL: accept loop: "SSLv3 flush data"
DEBUG: SSL: accept exit (-1): "SSLv3 read client certificate A"
DEBUG: SSL: accept exit (-1): "SSLv3 read client certificate A"
DEBUG: SSL: accept loop: "SSLv3 read client certificate A"
DEBUG: SSL: accept loop: "SSLv3 read client key exchange A"
DEBUG: SSL: accept loop: "SSLv3 read certificate verify A"
DEBUG: SSL: accept loop: "SSLv3 read finished A"
DEBUG: SSL: accept loop: "SSLv3 write change cipher spec A"
DEBUG: SSL: accept loop: "SSLv3 write finished A"
DEBUG: SSL: accept loop: "SSLv3 flush data"
DEBUG: SSL: handshake done: "SSL negotiation finished successfully"
DEBUG: SSL: accept exit (1): "SSL negotiation finished successfully"
DEBUG: SSL connection from "(anonymous)"
The attached contains these two changes as well as comment fixups which Heikki
noticed.
cheers ./daniel
Attachment | Content-Type | Size |
---|---|---|
0001-Move-information-callback-earlier-to-capture-connect.patch | application/octet-stream | 4.2 KB |
From | Date | Subject | |
---|---|---|---|
Next Message | Bharath Rupireddy | 2020-12-10 13:50:29 | Re: Parallel Inserts in CREATE TABLE AS |
Previous Message | Ashutosh Bapat | 2020-12-10 13:31:28 | Re: Insert Documentation - Returning Clause and Order |