STARTTLS fails with custom certificate (mTLS)

[4e4c52]

Hello 👋

I am running into a strange issue with Net::IMAP. I post here after trying to find a solution on the Ruby Discord server.

I'm trying to connect to an IMAP server using STARTTLS with a custom certificate.
When I call the starttls method, I get the following:

S: * OK [CAPABILITY IMAP4rev1 SASL-IR ID ENABLE IDLE LITERAL+ AUTH=EXTERNAL AUTH=PLAIN STARTTLS LOGINDISABLED] MSSPRO LPS-AUTH_CLI IMAP server ready.
C: RUBY0001 STARTTLS
S: RUBY0001 OK Begin TLS negotiation now
SSL_connect returned=1 errno=0 peeraddr=195.35.24.212:143 state=error: ssl/tls alert unexpected message (SSL alert number 10)
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-protocol-0.2.2/lib/net/protocol.rb:46:in 'OpenSSL::SSL::SSLSocket#connect_nonblock'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-protocol-0.2.2/lib/net/protocol.rb:46:in 'Net::Protocol#ssl_socket_connect'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:3789:in 'Net::IMAP#start_tls_session'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:1402:in 'block in Net::IMAP#starttls'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:3427:in 'block (2 levels) in Net::IMAP#receive_responses'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:3426:in 'Array#each'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:3426:in 'block in Net::IMAP#receive_responses'

I wrote a script that uses TCPSocket and OpenSSL::SSL::SSLSocket to connect to the server manually and it works fine.
I've also tried in Python with the imaplib and it works fine as well.

The three scripts are available in this gist: https://gist.github.com/4e4c52/543ea036030acc6b3d9e876a44777234

As I am trying to connect to a development server, I can provide the PKCS12 file and its password if it helps reproducing.

[nevans]

I haven't seen that before, and I don't know enough about the details of OpenSSL to understand that specific error code. But my instinct is that the OpenSSL::SSL::SSLContext needs a subtly different configuration in order to connect to that host.

Here's how I would debug this:

Your script builds SSL::Context here:
https://gist.github.com/4e4c52/543ea036030acc6b3d9e876a44777234#file-socket-rb-L83-L97

    ssl_context = OpenSSL::SSL::SSLContext.new
    ssl_context.cert = @cert
    ssl_context.key = @key

    # Add CA certificates to store if present
    if @ca_certs && !@ca_certs.empty?
      ssl_context.cert_store = OpenSSL::X509::Store.new
      @ca_certs.each { |ca| ssl_context.cert_store.add_cert(ca) }
    end

    ssl_context.verify_mode = OpenSSL::SSL::VERIFY_PEER

But Net::IMAP#starttls builds its SSL::Context by calling OpenSSL::SSL::SSLContext#set_params:

net-imap/lib/net/imap.rb

Lines 3783 to 3789 in 286905e

	params = (Hash.try_convert(ssl) || {}).freeze
	context = SSLContext.new
	context.set_params(params)
	if defined?(VerifyCallbackProc)
	context.verify_callback = VerifyCallbackProc
	end
	context.freeze

#set_params applies the following defaults:
https://github.com/ruby/openssl/blob/5403c0c314449785f0e312cdb58d87471a2b7303/lib/openssl/ssl.rb#L24-L33

      DEFAULT_PARAMS = { # :nodoc:
        :verify_mode => OpenSSL::SSL::VERIFY_PEER,
        :verify_hostname => true,
        :options => -> {
          opts = OpenSSL::SSL::OP_ALL
          opts &= ~OpenSSL::SSL::OP_DONT_INSERT_EMPTY_FRAGMENTS
          opts |= OpenSSL::SSL::OP_NO_COMPRESSION
          opts
        }.call
      }

With a little more for the default cert_store.
https://github.com/ruby/openssl/blob/5403c0c314449785f0e312cdb58d87471a2b7303/lib/openssl/ssl.rb#L144-L154

      def set_params(params={})
        params = DEFAULT_PARAMS.merge(params)
        self.options |= params.delete(:options) # set before min_version/max_version
        params.each{|name, value| self.__send__("#{name}=", value) }
        if self.verify_mode != OpenSSL::SSL::VERIFY_NONE
          unless self.ca_file or self.ca_path or self.cert_store
            self.cert_store = DEFAULT_CERT_STORE
          end
        end
        return params
      end

I was going to recommend you prints out an inspection of Net::IMAP#ssl_ctx and compare it to your script's... but it looks like you've already done that. I'm guessing we could see something relevant by comparing those.

If you change your socket script to use SSLContext#set_params with the exact same params as you give Net::IMAP, does it also fail? If you can call Net::IMAP#starttls with parameters so it creates the exact same SSLContext, I expect that will allow it to connect. Maybe you need to different options for that server? Maybe some default callback behaves differently when verify_mode is SSL_VERIFY_NONE? Your TCP socket (and sockopts) are set differently too, so maybe it's something to do with that (I'm really grasping at straws here)?

[nevans]

And, separately from that line of inquiry, I just had the idea that maybe recent changes to how we read responses (to limit max read buffer and eventually add timeouts) could have affected #starttls in a way that isn't captured by the tests. Or, if it's related to the changes in v0.5.7, it may also be related to the (seemingly platform-specific) flaky tests in #287.

Can you also test this with net-imap v0.5.6? If this is caused by the changes in v0.5.7, your script should work with v0.5.6.

[nevans]

Looking at the code again, I don't see how it could be related to v0.5.7. But at least it's an easily testable hypothesis. I think it's more likely due to SSL_CTX options.

[4e4c52]

I tried building the SSLContext with set_params in the socket version, it works as well, even with verify_mode set to OpenSSL::SSL::VERIFY_NONE.

Also tried with the gem pinned to 0.5.7, same issue. When discussing the issue on Discord, I even tried with Ruby 2.7 and the bug was still occurring.

[rhenium]

SSL_connect returned=1 errno=0 peeraddr=195.35.24.212:143 state=error: ssl/tls alert unexpected message (SSL alert number 10)

This error message says that the client received the "unexpected_message" alert from the server, which is unusual.

The three scripts are available in this gist: https://gist.github.com/4e4c52/543ea036030acc6b3d9e876a44777234

I reproduced the same error without a client certificate. It seems this server (or possibly a middlebox in front of the server, such as a firewall) may have a bug with handling a STARTTLS command when it is split into two TCP segments.

Applying this diff changes the error to "ssl/tls alert bad certificate", which makes more sense because I don't send a client certificate.

diff --git a/lib/net/imap.rb b/lib/net/imap.rb
index 41524d7b1196..bb44de55428b 100644
--- a/lib/net/imap.rb
+++ b/lib/net/imap.rb
@@ -3534,6 +3534,8 @@ module Net
 
     def send_command(cmd, *args, &block)
       synchronize do
+        require "stringio"
+        s, @sock = @sock, StringIO.new
         args.each do |i|
           validate_data(i)
         end
@@ -3544,6 +3546,8 @@ module Net
           send_data(i, tag)
         end
         put_string(CRLF)
+        s.write(@sock.string)
+        @sock = s
         if cmd == "LOGOUT"
           @logout_command_tag = tag
         end

[4e4c52]

@rhenium I confirm it's working with your changes. I get a new error just after the handshake with the advertised capabilities.
I think it's because of the double space before the ID ATOM.

S: * OK [CAPABILITY IMAP4rev1 SASL-IR ID ENABLE IDLE LITERAL+ AUTH=EXTERNAL AUTH=PLAIN STARTTLS LOGINDISABLED] MSSPRO LPS-AUTH_CLI IMAP server ready.
C: RUBY0001 STARTTLS
S: RUBY0001 OK Begin TLS negotiation now
TLS OK
C: RUBY0002 CAPABILITY
S: * CAPABILITY IMAP4rev1 SASL-IR  ID ENABLE IDLE LITERAL+ AUTH=EXTERNAL AUTH=PLAIN
Net::IMAP::ResponseParser parse_error: unexpected ATOM (expected CRLF)
  tokenized : "* CAPABILITY IMAP4rev1 SASL-IR  ID"
  remaining : " ENABLE IDLE LITERAL+ AUTH=EXTERNAL AUTH=PLAIN\r\n"
  @lex_state: EXPR_BEG
  @pos      : 34
  @token    : ATOM: "ID"
  caller[ 0]: CRLF!                          (parser_utils:110)
  caller[ 1]: response                       (response_parser:686)
  caller[ 2]: parse                          (response_parser:40)
  caller[ 3]: get_response                   (imap:3482)
  caller[ 4]: receive_responses              (imap:3384)
  caller[ 5]: start_receiver_thread          (imap:3361)
unexpected ATOM (expected CRLF)
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap/response_parser/parser_utils.rb:239:in 'Net::IMAP::ResponseParser::ParserUtils#parse_error'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap/response_parser/parser_utils.rb:110:in 'Net::IMAP::ResponseParser#CRLF!'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap/response_parser.rb:686:in 'Net::IMAP::ResponseParser#response'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap/response_parser.rb:40:in 'Net::IMAP::ResponseParser#parse'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:3482:in 'Net::IMAP#get_response'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:3384:in 'Net::IMAP#receive_responses'
/Users/nathan/.local/share/mise/installs/ruby/3.4.6/lib/ruby/gems/3.4.0/gems/net-imap-0.5.10/lib/net/imap.rb:3361:in 'block in Net::IMAP#start_receiver_thread'
C: RUBY0003 LOGOUT

[nevans]

@rhenium Thanks for debugging that! It would've been a very long time before I got around to debugging commands split across multiple packets!

@4e4c52 Please note that, while @rhenium's patch is a good workaround for moving you forward with this server right now, it will break sending of "literals" (e.g: strings with non-ASCII chars). I'm guessing that bug will manifest as a command simply hanging (waiting on a condition variable that won't be triggered until the connection is dropped).

I've wanted to refactor the #send_command (and related) code for a while, for other reasons.

I think it's because of the double space before the ID ATOM.

That's correct. You can patch the parser to workaround that:

diff --git a/lib/net/imap/response_parser.rb b/lib/net/imap/response_parser.rb
index 03e54b202..836aae294 100644
--- a/lib/net/imap/response_parser.rb
+++ b/lib/net/imap/response_parser.rb
@@ -1761,10 +1761,10 @@ module Net
         UntaggedResponse.new label("ENABLED"), capability__list, @str
       end
 
-      # As a workaround for buggy servers, allow a trailing SP:
-      #     *(SP capability) [SP]
+      # As a workaround for buggy servers, allow extra spaces:
+      #     *(SP *SP capability) *SP
       def capability__list
-        list = []; while SP? && (capa = capability?) do list << capa end; list
+        list = []; while accept_spaces && (capa = capability?) do list << capa end; list
       end
 
       alias resp_code__capability capability__list