SSL: fatal access denied with opensmtp AND dovecot

Mon Feb 16 01:41:27 UTC 2015

Hi,

I've been tasked with setting up a FreeBSD-based email server, with opensmtpd
and dovecot.

I've come across an issue with both, giving an error stating "fatal access
denied" when attempting to initiate TLS connectiong.

The certificates work fine on a test OpenBSD host, so they're not the issue.
I'm amused that both dovecot *and* opensmtpd show almost identical issue, and
suspect that something openssl related might be broken.

Dovecot
-------

==> /var/log/debug.log <==
Feb 16 01:33:55 hydrogen dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Feb 16 01:33:55 hydrogen dovecot: imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Feb 16 01:33:55 hydrogen dovecot: auth: Debug: Loading modules from directory: /usr/local/lib/dovecot/auth
Feb 16 01:33:55 hydrogen dovecot: auth: Debug: Wrote new auth token secret to /var/run/dovecot/auth-token-secret.dat
Feb 16 01:33:55 hydrogen dovecot: auth: Debug: passwd-file /usr/local/etc/dovecot/users: Read 5 users in 0 secs
Feb 16 01:33:55 hydrogen dovecot: auth: Debug: auth client connected (pid=94662)
Feb 16 01:33:55 hydrogen dovecot: imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [190.210.108.249]
Feb 16 01:33:55 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [190.210.108.249]
Feb 16 01:33:55 hydrogen dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv2/v3 read client hello A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Debug: SSL alert: close notify [190.210.108.249]

==> /var/log/maillog <==
Feb 16 01:33:56 hydrogen dovecot: imap-login: Warning: SSL alert: where=0x4004, ret=561: fatal access denied [190.210.108.249]
Feb 16 01:33:56 hydrogen dovecot: imap-login: Disconnected (no auth attempts in 1 secs): user=<>, rip=190.210.108.249, lip=104.236.123.233, TLS, session=<C19llCoPSQC+0mz5>

Opensmtpd
---------

debug: smtp: new client on listener: 0x8024eb000
smtp-in: New session 6f9022aa19efcad6 from host athena.barrera.io [190.210.108.249]
debug: lka: looking up pki "mail.asteq.com.ar"
debug: session_start_ssl: switching to SSL
debug: pony: rsae_priv_enc
debug: SSL library error: io_dispatch_accept_ssl:SSL_accept: error:14094419:SSL routines:SSL3_READ_BYTES:tlsv1 alert access denied
smtp-in: Disconnecting session 6f9022aa19efcad6: IO error: error:14094419:SSL routines:SSL3_READ_BYTES:tlsv1 alert access denied
debug: smtp: 0x802501000: deleting session: IO error

Some details:

* Certificate file modes can't be an issue because both services start as root.
  smtpd actually demands that the files are at most mode 700 and owned by 0:0.
* I've checked the certificates and keys and they look fine. I tried another
  self-generated pair too.
* FreeBSD 10.1-RELEASE-p5.
* dovecot2-2.2.15_3 from packages
* Tried both opensmtpd-5.4.4,1 and opensmtpd-devel-201502012312.
* Certificates were generated with "openssl genrsa -out ssl.key 4096".
* The original certificates (I later tried self-signed) were signed by
  StartSSL.
* Debugging is set to the maximum on both daemons. Dovecot only actually spat
  the error after I increased logging verbosity quite a bit.

Any hints? Has anyone come across similar issues? Searching online for this
issue got me now-where.

-- 
Hugo Osvaldo Barrera
A: Because we read from top to bottom, left to right.
Q: Why should I start my reply below the quoted text?
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: not available
URL: <http://lists.freebsd.org/pipermail/freebsd-questions/attachments/20150215/cef29e95/attachment.sig>