TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
14 messages Options
Reply | Threaded
Open this post in threaded view
|

TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

PGNet Dev-6
i've got two servers communicating over ssl.

comms between them work if

        /etc/pki/tls/openssl.cnf

includes

        Options = PrioritizeChaCha

but fail if 'ServerPreference'

        (cref:

                Undocumented openssl.cnf options and PrioritizeChaCha
                https://blog.germancoding.com/2020/05/30/undocumented-openssl-cnf-options-and-prioritizechacha/

                man SSL_CONF_cmd
                        ServerPreference: use server and not client preference order when determining which cipher suite, signature algorithm or elliptic curve to use for an incoming connection.  Equivalent to SSL_OP_CIPHER_SERVER_PREFERENCE. Only used by servers.
        )

is added,

        Options = ServerPreference,PrioritizeChaCha

i'm trying to understand expected behavior, and troubleshoot

the 2 servers are

        postconf mail_version
                mail_version = 3.5.7
        dovecot --version
                2.3.10.1 (a3d0e1171)

they're on the same machine, which runs

       
        grep PRETTY /etc/os-release
                PRETTY_NAME="Fedora 32 (Server Edition)"
        openssl version
                OpenSSL 1.1.1g FIPS  21 Apr 2020

dovecot's configured to listen for SMTP submissions on its own submission proxy port 60465

dovecot then re-submits the message to postfix, on submission port 465.

the openssl cnf containts

        /etc/pki/tls/openssl.cnf
                openssl_conf = default_conf

                [default_conf]
                ssl_conf = ssl_sect

                [ssl_sect]
                system_default = system_default_sect

                [system_default_sect]
                MinProtocol = TLSv1.2
                CipherString = ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256
                Ciphersuites = TLS_CHACHA20_POLY1305_SHA256:TLS_AES_256_GCM_SHA384:TLS_AES_128_GCM_SHA256

                Options = PrioritizeChaCha

with that^^ config, message submit

        cat ~/test.eml | msmtp -a internal [hidden email]

to dovecot:60465 succeeds.  postfix logs report no probs,

        Sep 23 13:43:36 mx postfix/submit-from-dovecot-proxy/smtpd[27325]: connect from internal.mx.example.com[10.0.1.50]
        Sep 23 13:43:36 mx postfix/submit-from-dovecot-proxy/smtpd[27325]: Trusted TLS connection established from internal.mx.example.com[10.0.1.50]: TLSv1.3 with cipher TLS_CHACHA20_POLY1305_SHA256 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-384) server-digest SHA384 client-signature ECDSA (P-384) client-digest SHA384
        Sep 23 13:43:36 mx postfix/submit-from-dovecot-proxy/smtpd[27325]: 4BxVWX41svzWf7g: client=internal.mx.example.com[10.0.1.50]
        Sep 23 13:43:36 mx postfix/qmgr[27295]: 4BxVWX41svzWf7g: from=<[hidden email]>, size=583, nrcpt=1 (queue active)
        Sep 23 13:43:36 mx postfix/submit-from-dovecot-proxy/smtpd[27325]: disconnect from internal.mx.example.com[10.0.1.50] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
        Sep 23 13:43:36 mx postfix/lmtp[27329]: 4BxVWX41svzWf7g: to=<[hidden email]>, relay=mx.example.com[private/dovecot-lmtp], delay=0.03, delays=0.01/0.01/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> kPB/Iniza1/YaQAA+IOfAw Saved)
        Sep 23 13:43:36 mx postfix/qmgr[27295]: 4BxVWX41svzWf7g: removed

and the message _is_ delivered to final destination without error. mail flows -- in- & out-bound -- without interruption.


OTOH, if, as mentioned above, I simply change

- Options = PrioritizeChaCha
+ Options = ServerPreference,PrioritizeChaCha

, then otherwise-identical submission to dovecot:60465 fails,

        cat ~/test.eml | msmtp -a internal [hidden email]
                msmtp: envelope from address [hidden email] not accepted by the server
                msmtp: server message: 421 4.4.0 internal.mx.example.com Failed to establish relay connection
                msmtp: could not send mail (account internal from /etc/msmtprc)

and in postfix logs,

        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: connect from internal.mx.example.com[10.0.1.50]
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: setting up TLS connection from internal.mx.example.com[10.0.1.50]
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: internal.mx.example.com[10.0.1.50]: TLS cipher list "TTLS13-CHACHA20-POLY1305-SHA256:ECDHE-ECDSA-CHACHA20-POLY1305:!aNULL"
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: SSL_accept:before SSL initialization
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: SSL_accept:error in error
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: SSL_accept error from internal.mx.example.com[10.0.1.50]: -1
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: warning: TLS library problem: error:1408F10B:SSL routines:ssl3_get_record:wrong version number:ssl/record/ssl3_record.c:331:
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: lost connection after CONNECT from internal.mx.example.com[10.0.1.50]
        Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: disconnect from internal.mx.example.com[10.0.1.50] commands=0/0


iiuc (?) that^^ _is_ an ssl error, reported by postfix, and preventing the send 'tween dovecot & postfix.

1st, is there any reason to expect that use of "Options = ServerPreference" should _not_ work here?

If not, then what's a likely cause of the problem?  At this point, I'm not clear if this is postfix, dovecot, openssl, or some combo.

&/or, what additional info's required to determine further?

Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Viktor Dukhovni
On Wed, Sep 23, 2020 at 02:11:50PM -0700, PGNet Dev wrote:

> /etc/pki/tls/openssl.cnf
> openssl_conf = default_conf
>
> [default_conf]
> ssl_conf = ssl_sect
>
> [ssl_sect]
> system_default = system_default_sect
>
> [system_default_sect]
> MinProtocol = TLSv1.2
> CipherString = ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256
> Ciphersuites = TLS_CHACHA20_POLY1305_SHA256:TLS_AES_256_GCM_SHA384:TLS_AES_128_GCM_SHA256
>
> Options = PrioritizeChaCha

Distros have gotten rather enthusiastic of late to turn up the crypto to
11.  This does not always yield good results. :-(  I'd be tempted to
drop most if not all of those settings, they're not email-friendly.

> OTOH, if, as mentioned above, I simply change
>
> - Options = PrioritizeChaCha
> + Options = ServerPreference,PrioritizeChaCha
>
> , then otherwise-identical submission to dovecot:60465 fails,
>
> and in postfix logs,
>
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: connect from internal.mx.example.com[10.0.1.50]
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: setting up TLS connection from internal.mx.example.com[10.0.1.50]
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: internal.mx.example.com[10.0.1.50]: TLS cipher list "TTLS13-CHACHA20-POLY1305-SHA256:ECDHE-ECDSA-CHACHA20-POLY1305:!aNULL"
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: SSL_accept:before SSL initialization
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: SSL_accept:error in error
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: SSL_accept error from internal.mx.example.com[10.0.1.50]: -1
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: warning: TLS library problem: error:1408F10B:SSL routines:ssl3_get_record:wrong version number:ssl/record/ssl3_record.c:331:
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: lost connection after CONNECT from internal.mx.example.com[10.0.1.50]
> Sep 23 13:45:42 mx postfix/submit-from-dovecot-proxy/smtpd[27011]: disconnect from internal.mx.example.com[10.0.1.50] commands=0/0

That's rather more verbose than default Postfix TLS logging, I hope it
is temporary.  Are you sure the third line is copied correctly into
your post?

> Sep 23 13:45:42 mx
> postfix/submit-from-dovecot-proxy/smtpd[27011]:
> internal.mx.example.com[10.0.1.50]: TLS cipher list
> "TTLS13-CHACHA20-POLY1305-SHA256:ECDHE-ECDSA-CHACHA20-POLY1305:!aNULL"

That cipherlist, has an extra "T" in front of the TLS 1.3 ChaCha cipher,
that should not be there...  Also, Postfix has no knowledge of TLS 1.3
cipher suites, Postfix has only cipher configuration knobs only for the
TLS <= 1.2 ciphers, so I don't know how that particular string ended up
in your logs.

Is there something in your Postfix configuration that resembles that
particular blob?  If so, it should not be there...

--
    Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

PGNet Dev-6
> I'd be tempted to drop most if not all of those settings, they're not email-friendly.

PUBLIC email non-friendly, because of still-frequent old cipher/protocol implementations?

or,

inherently problematic with TLS in/onr SMTP?

in this case, there's nothing public ... both the dovecot and postfix instances are internal.  the internal postfix instance hands off to a public facing external postfix instance, which exposes/uses postfix-default cipherlists only.

the attempt is to clean- & tighten-up the comms internally; not that that's particularly relevant to the error(s) seen.

> That's rather more verbose than default Postfix TLS logging, I hope it is temporary.

yep. 'temporarily' monkeying with log levels all over the place, trying to find the cause of this^.
now dialed back.

> Are you sure the third line is copied correctly into your post?

not entirely; it's copied from my too-busy/very-messy 'WTF?' notes.

below, i've (re)included logs instead _directly_ copied from shell.

> That cipherlist, has an extra "T" in front of the TLS 1.3 ChaCha cipher, that should not be there...

fat thumbs in notes, I suspect.

> Also, Postfix has no knowledge of TLS 1.3 cipher suites, Postfix has only cipher configuration knobs only for the TLS <= 1.2 ciphers, so I don't know how that particular string ended up in your logs.

a bit too postfix-y for this list, but ...

I'm then perhaps misreading

        http://www.postfix.org/TLS_README.html
        http://www.postfix.org/FORWARD_SECRECY_README.html

                "If you want to take maximal advantage of ciphers that offer forward secrecy see the Getting started section of FORWARD_SECRECY_README. The full document conveniently presents all information about Postfix forward secrecy support in one place: what forward secrecy is, how to tweak settings, and what you can expect to see when Postfix uses ciphers with forward secrecy.

                Postfix 2.8 and later, in combination with OpenSSL 0.9.7 and later allows TLS servers to preempt the TLS client's cipher-suite preference list. This is possible only with SSLv3 and later, as in SSLv2 the client chooses the cipher-suite from a list supplied by the server.

                By default, the OpenSSL server selects the client's most preferred cipher-suite that the server supports. With SSLv3 and later, the server may choose its own most preferred cipher-suite that is supported (offered) by the client. Setting "tls_preempt_cipherlist = yes" enables server cipher-suite preferences. The default OpenSSL behavior applies with "tls_preempt_cipherlist = no". "

RE-(re-,re-,etc-)reading, I'm now scratching my head a bit as to which is the server defining the preferences ... my _goal_ was to ensure that the server receiving submission -- 1st @ the MUA -> dovecot listener, then @ dovecot -> postfix -- dictates the ciphers/suites in use. or at least declares preference.

In any case, the following should be with defaults.

> Is there something in your Postfix configuration that resembles that
particular blob?  If so, it should not be there...

yep. now removed ...


with postfix's tls log level dialed back down

        -o smtpd_tls_loglevel=1

and its

        tls_high_cipherlist

back to default

simplifying

        /etc/pki/tls/openssl.cnf
                openssl_conf = default_conf

                [default_conf]
                ssl_conf = ssl_sect

                [ssl_sect]
                system_default = system_default_sect

                [system_default_sect]
                Options = PrioritizeChaCha

@ test submit to dovecot

        cat ~/test.eml | msmtp -a internal [hidden email]

send/receive is successful.

        dovecot logs

                2020-09-24 04:59:01 submission-login: Info: Login: user=<[hidden email]>, method=PLAIN, rip=10.0.1.17, lip=10.0.1.17, mpid=11209, TLS
                2020-09-24 04:59:01 submission([hidden email])<q/Y1mg+wauOsHgsy>: Info: Successfully relayed message: from=<[hidden email]>, size=135, id=kROCNiWmbF/JKwAA+IOfAw, nrcpt=1, reply=`250 2.0.0 Ok: queued as 4BxxVF6VD2zWf49'
                2020-09-24 04:59:01 lmtp(11200): Info: Connect from local
                2020-09-24 04:59:01 submission([hidden email])<q/Y1mg+wauOsHgsy>: Info: Disconnect from 10.0.1.17: Client has quit the connection in=223 out=114 (state=READY)
                2020-09-24 04:59:02 lmtp([hidden email])<YCW8NiWmbF/AKwAA+IOfAw>: Info: sieve: msgid=<[hidden email]>: stored mail into mailbox 'INBOX'
                2020-09-24 04:59:02 lmtp(11200): Info: Disconnect from local: Client has quit the connection (state=READY)

        postfix logs

                Sep 24 04:59:01 mx postfix/submit-from-dovecot-proxy/smtpd[11186]: connect from internal.mx.example.com[10.0.1.17]
                Sep 24 04:59:01 mx postfix/submit-from-dovecot-proxy/smtpd[11186]: Trusted TLS connection established from internal.mx.example.com[10.0.1.17]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-384) server-digest SHA384 client-signature ECDSA (P-384) client-digest SHA384
                Sep 24 04:59:01 mx postfix/submit-from-dovecot-proxy/smtpd[11186]: 4BxxVF6VD2zWf49: client=internal.mx.example.com[10.0.1.17]
                Sep 24 04:59:01 mx postfix/qmgr[11139]: 4BxxVF6VD2zWf49: from=<[hidden email]>, size=577, nrcpt=1 (queue active)
                Sep 24 04:59:01 mx postfix/submit-from-dovecot-proxy/smtpd[11186]: disconnect from internal.mx.example.com[10.0.1.17] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
                Sep 24 04:59:02 mx postfix/lmtp[11190]: 4BxxVF6VD2zWf49: to=<[hidden email]>, relay=mx.example.com[private/dovecot-lmtp], delay=0.19, delays=0/0/0/0.19, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> YCW8NiWmbF/AKwAA+IOfAw Saved)
                Sep 24 04:59:02 mx postfix/qmgr[11139]: 4BxxVF6VD2zWf49: removed

changing only

        /etc/pki/tls/openssl.cnf
- Options = PrioritizeChaCha
+ Options = ServerPreference,PrioritizeChaCha

@ re-test submit to dovecot FAILs,

        cat ~/test.eml | msmtp -a internal [hidden email]
                msmtp: envelope from address [hidden email] not accepted by the server
                msmtp: server message: 421 4.4.0 internal.mx.example.com Failed to establish relay connection
                msmtp: could not send mail (account internal from /etc/msmtprc)

        dovecot log

                2020-09-24 05:01:44 submission-login: Info: Login: user=<[hidden email]>, method=PLAIN, rip=10.0.1.17, lip=10.0.1.17, mpid=11260, TLS

                ==> /var/log/dovecot/dovecot.log <==
                2020-09-24 05:01:44 submission([hidden email])<GCHoow+wbuOsHgsy>: Error: smtp-client: conn internal.mx.example.com:465 (10.0.1.17:465) [1]: connect(internal.mx.example.com:465) failed: Failed to initialize SSL: Couldn't initialize SSL context: Can't load SSL certificate: error:14187180:SSL routines:ssl_do_config:bad value: section=system_default, cmd=Options, arg=ServerPreference,PrioritizeChaCha
                2020-09-24 05:01:44 submission([hidden email])<GCHoow+wbuOsHgsy>: Error: Failed to establish relay connection: Failed to connect to remote server

                ==> /var/log/dovecot/dovecot-info.log <==
                2020-09-24 05:01:44 submission([hidden email])<GCHoow+wbuOsHgsy>: Info: Disconnect from 10.0.1.17: Failed to establish relay connection in=0 out=22 (state=GREETING)

        postfix log

                Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: connect from internal.mx.example.com[10.0.1.17]
                Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: SSL_accept error from internal.mx.example.com[10.0.1.17]: -1
                Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: warning: TLS library problem: error:1408F10B:SSL routines:ssl3_get_record:wrong version number:ssl/record/ssl3_record.c:331:
                Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: lost connection after CONNECT from internal.mx.example.com[10.0.1.17]
                Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: disconnect from internal.mx.example.com[10.0.1.17] commands=0/0


again, the _only_ change between the two submissions is the addition of the "ServerPreference" option to the openssl.cnf config.

still not clear to me which piece(s) of that^ are having an issue with it. or why.

for this list, my initial question is -- *IS* it openssl's "fault"?  or mine, or one of the other apps'?

Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Viktor Dukhovni
On Thu, Sep 24, 2020 at 07:43:04AM -0700, PGNet Dev wrote:

> > I'd be tempted to drop most if not all of those settings, they're not email-friendly.
>
> PUBLIC email non-friendly, because of still-frequent old cipher/protocol implementations?
>
> or,
>
> inherently problematic with TLS in/onr SMTP?

Mostly the former.

> > Also, Postfix has no knowledge of TLS 1.3 cipher suites, Postfix has
> > only cipher configuration knobs only for the TLS <= 1.2 ciphers, so
> > I don't know how that particular string ended up in your logs.
>
> a bit too postfix-y for this list, but ...
>
> I'm then perhaps misreading
>
> http://www.postfix.org/TLS_README.html
> http://www.postfix.org/FORWARD_SECRECY_README.html
>
> In any case, the following should be with defaults.
>
> > Is there something in your Postfix configuration that resembles that
> > particular blob?  If so, it should not be there...
>
> yep. now removed ...

That's very likely to have been the cause of the problem.  That setting
was not valid as a TLS <= 1.2 cipherlist.

> simplifying
>
> /etc/pki/tls/openssl.cnf
> openssl_conf = default_conf
> [default_conf]
> ssl_conf = ssl_sect
> [ssl_sect]
> system_default = system_default_sect
> [system_default_sect]
> Options = PrioritizeChaCha
>
> send/receive is successful.
>
> postfix logs
>
>               Trusted TLS connection established from
>               internal.mx.example.com[10.0.1.17]: TLSv1.3 with
>               cipher TLS_AES_256_GCM_SHA384 (256/256 bits)
>               key-exchange X25519 server-signature ECDSA (P-384)
>               server-digest SHA384 client-signature ECDSA (P-384)
>               client-digest SHA384

So client and server both support TLS 1.3, and use AES-256-GCM by
default.

> changing only
>
> /etc/pki/tls/openssl.cnf
> - Options = PrioritizeChaCha
> + Options = ServerPreference,PrioritizeChaCha
>
> @ re-test submit to dovecot FAILs,
>
> postfix log
>
> Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: connect from internal.mx.example.com[10.0.1.17]
> Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: SSL_accept error from internal.mx.example.com[10.0.1.17]: -1
> Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: warning: TLS library problem: error:1408F10B:SSL routines:ssl3_get_record:wrong version number:ssl/record/ssl3_record.c:331:
> Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: lost connection after CONNECT from internal.mx.example.com[10.0.1.17]
> Sep 24 05:01:44 mx postfix/submit-from-dovecot-proxy/smtpd[11261]: disconnect from internal.mx.example.com[10.0.1.17] commands=0/0
>
> again, the _only_ change between the two submissions is the addition of the "ServerPreference" option to the openssl.cnf config.

This looks like the protocol version is no longer TLS 1.3 as a result,
and one side or the other now expects or sent the wrong protocol
version.  For further progress a PCAP file is needed which contains a
full capture of exactly one TCP connection corresponding to this
failure.

You should check for any other non-default Postfix TLS settings that
may have been set to poorly chosen values.

> still not clear to me which piece(s) of that^ are having an issue with it. or why.

Ultimately, the TLS library (OpenSSL) is failing to interoperate between
client and server after this change.  But whether this is a bug in
OpenSSL, or a problem setting in the application is not yet clear.

> for this list, my initial question is -- *IS* it openssl's "fault"?
> or mine, or one of the other apps'?

You need to post A PCAP file that tshark can read with a single
TCP session containing the failed handshake.

What are the exact OpenSSL versons on the client and server?

Anything interesting in openssl.cnf on the client end?

--
    Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

PGNet Dev-6
On 9/24/20 5:51 PM, Viktor Dukhovni wrote:
>> again, the _only_ change between the two submissions is the addition of the "ServerPreference" option to the openssl.cnf config.
>
> This looks like the protocol version is no longer TLS 1.3 as a result,
> and one side or the other now expects or sent the wrong protocol
> version.  For further progress a PCAP file is needed which contains a
> full capture of exactly one TCP connection corresponding to this
> failure.
>
> You need to post A PCAP file that tshark can read with a single

> TCP session containing the failed handshake.



Been awhile since I 'de-noised' a comms dump; I'll dust off my notes, & work on getting a useful/relevant PCAP file ...

> You should check for any other non-default Postfix TLS settings that
> may have been set to poorly chosen values.

i need to re-read, again, to figure out what those might be, and what restrictions exist.

iiuc, i _should_ be able to lock this all down to specification and use of even a _single_ cipher.  it's all/only 'internal' (to my org) transport after all.

i can certainly live with a short list -- but with the goal to 'always' end up using TLS13 chacha20-poly1305 suite .

>> still not clear to me which piece(s) of that^ are having an issue with it. or why.
>
> Ultimately, the TLS library (OpenSSL) is failing to interoperate between
> client and server after this change.  But whether this is a bug in
> OpenSSL, or a problem setting in the application is not yet clear.
>
>> for this list, my initial question is -- *IS* it openssl's "fault"?
>> or mine, or one of the other apps'?
>
> What are the exact OpenSSL versons on the client and server?
> Anything interesting in openssl.cnf on the client end?


The client/server are the _same_ host.  Specifically, dovecot & postfix are submission listeners on the same box -- on different ports, of course.


So they both 'experience' the same openssl.cnf


Version is

 openssl version
  OpenSSL 1.1.1g FIPS  21 Apr 2020

provided by distro pacakges on Fedora 32,

 rpm -qa | grep ssl | sort
  openssl-1.1.1g-1.fc32.x86_64
  openssl-devel-1.1.1g-1.fc32.x86_64
  openssl-libs-1.1.1g-1.fc32.x86_64






Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Viktor Dukhovni
On Thu, Sep 24, 2020 at 06:43:05PM -0700, PGNet Dev wrote:

> Been awhile since I 'de-noised' a comms dump; I'll dust off my notes, & work on getting a useful/relevant PCAP file ...

    # tcpdump -s0 -w /some/file tcp port 12345
    <start delivery that will fail, hit ^C once that happens>
    ^C

    # tcpdump -r /some/file 'tcp[13] & 0x12 == 2'
    <prints all connection initiating SYN packets, note the client's source port>

    # tcpdump -r /some/file -s0 -w session.pcap tcp port <theport>

    # tcpdump -r session.pcap
    <should contain one short session from 3-way SYN to 3-way FIN and/or RST>

See also:

    https://www.spinics.net/lists/openssl-users/msg05623.html

for notes on using "tshark" to extract the detailed protocol
diagnostics.  These can be somewhat disappointing with TLS 1.3,
because privacy...(most of the handshake is encrypted).

> Version is
>
>  openssl version
>   OpenSSL 1.1.1g FIPS  21 Apr 2020

Looking at the upstream OpenSSL source, the first thing to note is that
the prefer chacha setting has no effect at all, unless you also have
server preference set (which you can do with Postfix settings, rather
than globally in the config file).

Secondly, the effect of "prefer chacha" is to just synthesize a
transient ordered list of server cipher preferences that moves any
cha-cha ciphers to the top, cipher selection then continues as usual.

So your reported symptoms re protocol version mismatch look rather
perplexing, don't know what the client is doing, and whether the client
is even linked with OpenSSL?  Is dovecot using OpenSSL or GnuTLS?

--
    Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

PGNet Dev-6
On 9/24/20 7:32 PM, Viktor Dukhovni wrote:
> On Thu, Sep 24, 2020 at 06:43:05PM -0700, PGNet Dev wrote:
>
>> Been awhile since I 'de-noised' a comms dump; I'll dust off my notes, & work on getting a useful/relevant PCAP file ...
>
>      # tcpdump -s0 -w /some/file tcp port 12345

thx, was already rattling around in the docs!

> for notes on using "tshark" to extract the detailed protocol
> diagnostics.  These can be somewhat disappointing with TLS 1.3,
> because privacy...(most of the handshake is encrypted).

useful read

> Looking at the upstream OpenSSL source, the first thing to note is that
> the prefer chacha setting has no effect at all, unless you also have
> server preference set (which you can do with Postfix settings, rather
> than globally in the config file).

i've tried with both

        tls_preempt_cipherlist = yes

enabling postfix's cipher-suite prefs

and with
 
        tls_preempt_cipherlist = no


which iiuc uses the openssl.cnf 'global' setting

> Secondly, the effect of "prefer chacha" is to just synthesize a
> transient ordered list of server cipher preferences that moves any
> cha-cha ciphers to the top, cipher selection then continues as usual.

yup, that's one goal  ... use chacha whenever available.

> So your reported symptoms re protocol version mismatch look rather
> perplexing, don't know what the client is doing, and whether the client
> is even linked with OpenSSL?  Is dovecot using OpenSSL or GnuTLS?

dovecot's using openssl.  it's used by default,

        https://wiki2.dovecot.org/CompilingSource#SSL.2FTLS_Support

unclear if gnutls is supported still. in any case, the pkgs are built with openssl,

        https://src.fedoraproject.org/rpms/dovecot/blob/master/f/dovecot.spec#_155


now to the tcpdump ...

for this instance with

        dovecot --version
                2.3.10.1 (a3d0e1171)
        postconf mail_version
                mail_version = 3.5.7
        openssl version
                OpenSSL 1.1.1g FIPS  21 Apr 2020

        dovecot submission port == 60465
        postfix submission port == 465
       
&

        cat /etc/pki/tls/openssl.cnf
                openssl_conf = default_conf

                [default_conf]
                ssl_conf = ssl_sect

                [ssl_sect]
                system_default = system_default_sect

                [system_default_sect]
!! Options = ServerPreference,PrioritizeChaCha


submitting the 'failed' (as above) message

        cat ~/test.eml | msmtp -a internal [hidden email]

with this tshark cmd,

        tshark -n -V -i lo -d tcp.port==465,tls or -d tcp.port==60465,tls

which i think does the trick?, the dump of dissected tls packets from both submission ports, is here: https://is.gd/d5R67s


Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Viktor Dukhovni
On Thu, Sep 24, 2020 at 08:30:35PM -0700, PGNet Dev wrote:

> for this instance with
>
> dovecot --version
> 2.3.10.1 (a3d0e1171)
> postconf mail_version
> mail_version = 3.5.7
> openssl version
> OpenSSL 1.1.1g FIPS  21 Apr 2020
>
> dovecot submission port == 60465
> postfix submission port == 465
>

Well, the connection to port 60465 begins with a client TLS HELLO, and
then a successful TLS 1.3 handshake takes place.

For the connection to 465, the client connects, and just sends
"QUIT<CRLF>", which isn't exactly a TLS HELLO.  Is that really the
session you intended to capture.  It is not surprising that the server
is "unimpressed" with the client's TLS protocol version.  It is
surprising that the client sent "QUIT<CRLF>" only .14 seconds after SYN,
since if it expected to do SMTP STARTLS, it would typically wait for the
server greeting for more than a fraction of a second.

--
    Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

PGNet Dev-6
On 9/24/20 9:13 PM, Viktor Dukhovni wrote:
> On Thu, Sep 24, 2020 at 08:30:35PM -0700, PGNet Dev wrote:
> Is that really the session you intended to capture.

Interestingly phrased!

The intention was to capture the tcp data 'thru' the failed event.


That^^ is the data streamed to console, with that^^ tshark command, from right before the moment I exec the msmtp send, until it fails ... and sits there.

Whether that tshark cmd correctly captures that 'intention', well that's a different issue.

> It is surprising that the client sent "QUIT<CRLF>" only .14 seconds after SYN,
> since if it expected to do SMTP STARTLS, it would typically wait for the
> server greeting for more than a fraction of a second.

So, iiuc, that's a dovecot faux pas?

I certainly don't supsect that it's the result of anything that postfix signals in the transaction.

If it's 'from' dovecot, how would I ferret out whether it's dovecot code "innards", or something in the (mis)function of linked openssl libs?
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Viktor Dukhovni
On Thu, Sep 24, 2020 at 09:26:26PM -0700, PGNet Dev wrote:

> > It is surprising that the client sent "QUIT<CRLF>" only .14 seconds after SYN,
> > since if it expected to do SMTP STARTLS, it would typically wait for the
> > server greeting for more than a fraction of a second.
>
> So, iiuc, that's a dovecot faux pas?

No, it is a misconfiguration on your part.  Dovecot, as configured, is
expecting to talk to a standard SUBMIT service (i.e. SMTP + STARTTLS),
but you've configured the server port for TLS wrapper-mode (port 465
SMTP inside implicit TLS).

You have to either configure Dovecot to submit to port 587 (or similar)
that does not do TLS wrapper-mode (implicit TLS).  Or configure it
to use implicit TLS.

I must lodge a complaint on wasting my time here, you intimated that
just changing openssl.cnf makes the difference.  But that is clearly not
the case, because you're testing different server endpoints, with port
60465 for the "working" case, and "465" for the non-working case.

It seems likely that you don't have TLS wrapper mode on port 60465.

--
    Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

PGNet Dev-6
On 9/25/20 12:18 AM, Viktor Dukhovni wrote:
> On Thu, Sep 24, 2020 at 09:26:26PM -0700, PGNet Dev wrote:
> I must lodge a complaint on wasting my time here

seems your're done, then.


thx anyway.

> you intimated that just changing openssl.cnf makes the difference.

i didn't 'intimate'.

i stated so. as that is exactly/only what's changed.
and the change it causes has been documented.

> But that is clearly not the case, because you're testing different server endpoints, with port
> 60465 for the "working" case, and "465" for the non-working case.

that's simply not the case

as stated

 60465 is the dovecot submission port
 465 it the postfix submission port

the mua submits to dovecot at port 60465
dovecot resubmits to postfix at port 465

that same configuration is used in each/every test.

again, the ONLY thing that changed between the 'working' and 'failed' cases is the setting in openssl.cnf

I never directly submit to 465

> It seems likely that you don't have TLS wrapper mode on port 60465.

port 60465 is, and always has been, configured for implicit SSL -- not starttls usage.

Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Viktor Dukhovni
On Fri, Sep 25, 2020 at 07:36:44AM -0700, PGNet Dev wrote:

> > But that is clearly not the case, because you're testing different server endpoints, with port
> > 60465 for the "working" case, and "465" for the non-working case.
>
> that's simply not the case
>
> as stated
>
>  60465 is the dovecot submission port
>  465 it the postfix submission port

Well, I expected you to post a working and non-workin trace for the
*same* server endpoint, with the good and bad configuration.

Secondly, if dovecot is in fact configured to use implicit TLS when
forwarding to port 465, then sending a cleartext "QUIT" to that port is
rather unexpected behaviour.  That would be a dovecot bug.  But if,
absent the setting in question it actually performs the implicit TLS
handshake, despite that setting having no effect on client TLS, then
that's rather a mystery.

> the mua submits to dovecot at port 60465 dovecot resubmits to postfix
> at port 465

Where's the recording of the successful transmission to port 465 (and
not say 587).

> that same configuration is used in each/every test.

The cleartext "QUIT" sent by the client strongly suggests that's not the
case.  Miracles may happen, but otherwise the only explanation is that
the working connections also differed in additional ways beyond the
ChaCha preference.

> again, the ONLY thing that changed between the 'working' and 'failed'
> cases is the setting in openssl.cnf

How does that cause Dovecot to use cleartext on port 465, and not
send a TLS client HELO?  Or was that recording from a connection
made by hand with telnet or the like?

> I never directly submit to 465
>
> > It seems likely that you don't have TLS wrapper mode on port 60465.
>
> port 60465 is, and always has been, configured for implicit SSL -- not starttls usage.

Well, who or what sent QUIT to 465?  This time this carefully enough to
not make any mistakes, making sure that the recording has the correct
data.

There should be two separate recordings, both to port 465, one working
and one not.  Both made by Dovecot, before and after the openssl.cnf
change.  Make sure to record the second of two failure cases, just
in case Dovecot is doing some sort of connection caching, and sends
QUIT in the clear by mistake when dropping a cached connection.

--
    Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

PGNet Dev-6
On 9/25/20 8:55 AM, Viktor Dukhovni wrote:
> Well, I expected you to post a working and non-workin trace for the
> *same* server endpoint, with the good and bad configuration.
>
> Secondly,
(snip)

> Where's the recording of the successful transmission to port 465 (and
> not say 587).

you asked for a capture of the _failed_ transaction.

> For further progress a PCAP file is needed which contains a
> full capture of exactly one TCP connection corresponding to this
> failure.

> You need to post A PCAP file that tshark can read with a single
> TCP session containing the failed handshake.

you did not ask for captures of BOTH failed & successful transactions.

i'll pass on the drama.

again, thx anyway.
Reply | Threaded
Open this post in threaded view
|

Re: TLS handshake fails ("SSL_accept:error in error") for server->server connection (smtp submit dovecot->postfix) if /etc/pki/tls/openssl.cnf "Options=" includes 'ServerPreference' ?

Viktor Dukhovni
On Fri, Sep 25, 2020 at 10:01:18AM -0700, PGNet Dev wrote:

> > Where's the recording of the successful transmission to port 465 (and
> > not say 587).
>
> you asked for a capture of the _failed_ transaction.

I had intended to ask for both, hard to compare otherwise.  Good luck.

--
    Viktor.