Postfix has been trying to tell me something: your configuration is wrong.
Most cleverly, Postfix has been emailing me about this.
The first email came on 22 Oct 2014.
Date: Wed, 22 Oct 2014 08:18:07 +0000 (UTC) From: MAILER-DAEMON@supernews.example.org (Mail Delivery System) To: postmaster@supernews.example.org (Postmaster) Subject: Postfix SMTP server: errors from researchscan245.eecs.umich.edu[141.212.121.245] Message-Id: <20141022081807.0FE0917042@supernews.example.org> Transcript of session follows. Out: 220 supernews.example.org ESMTP Postfix In: EHLO umich.edu Out: 250-supernews.example.org Out: 250-PIPELINING Out: 250-SIZE 32768000 Out: 250-ETRN Out: 250-STARTTLS Out: 250-ENHANCEDSTATUSCODES Out: 250-8BITMIME Out: 250 DSN In: STARTTLS Out: 454 4.7.0 TLS not available due to local problem In: ??? Out: 502 5.5.2 Error: command not recognized In: Out: 500 5.5.2 Error: bad syntax In: ? Out: 502 5.5.2 Error: command not recognized In: Out: 500 5.5.2 Error: bad syntax In: Out: 500 5.5.2 Error: bad syntax Session aborted, reason: lost connection For other details, see the local mail logfile
I ignored it.
The second email arrived five days later on 27 October 2014:
Date: Mon, 27 Oct 2014 21:51:44 +0000 (UTC) From: MAILER-DAEMON@supernews.example.org (Mail Delivery System) To: postmaster@supernews.example.org (Postmaster) Subject: Postfix SMTP server: errors from unknown[107.150.52.82] Message-Id: <20141027215144.E48851703A@supernews.example.org> Transcript of session follows. Out: 220 supernews.example.org ESMTP Postfix In: STARTTLS Out: 454 4.7.0 TLS not available due to local problem Session aborted, reason: lost connection For other details, see the local mail logfile
I recall looking around, but I didn’t do anything. I think I found an error in the logs but didn’t have time to fix it.
A few days ago, another email arrived:
Date: Sat, 15 Nov 2014 03:41:21 +0000 (UTC) From: MAILER-DAEMON@supernews.example.org (Mail Delivery System) To: postmaster@supernews.example.org (Postmaster) Subject: Postfix SMTP server: errors from unknown[107.150.52.84] Message-Id: <20141115034121.CF22A1708C@supernews.example.org> Transcript of session follows. Out: 220 supernews.example.org ESMTP Postfix In: STARTTLS Out: 454 4.7.0 TLS not available due to local problem Session aborted, reason: lost connection For other details, see the local mail logfile
Yesterday, I had time to look at the log files. I found this:
Nov 15 03:41:21 supernews postfix/smtpd[70475]: cannot load Certificate Authority data: disabling TLS support
Nov 15 03:41:21 supernews postfix/smtpd[70475]: warning: TLS library problem: error:02001002:system library:fopen:No such file or directory:/usr/src/secure/lib/libcrypto/../../../crypto/openssl/crypto/bio/bss_file.c:126:fopen('/usr/local/etc/ssl/ca-bundle.crt','r'):
Nov 15 03:41:21 supernews postfix/smtpd[70475]: warning: TLS library problem: error:2006D080:BIO routines:BIO_new_file:no such file:/usr/src/secure/lib/libcrypto/../../../crypto/openssl/crypto/bio/bss_file.c:129:
Nov 15 03:41:21 supernews postfix/smtpd[70475]: warning: TLS library problem: error:0B084002:x509 certificate routines:X509_load_cert_crl_file:system lib:/usr/src/secure/lib/libcrypto/../../../crypto/openssl/crypto/x509/by_file.c:274:
Nov 15 03:41:21 supernews postfix/smtpd[70475]: connect from unknown[107.150.52.84]
Nov 15 03:41:21 supernews postfix/smtpd[70475]: lost connection after STARTTLS from unknown[107.150.52.84]
Nov 15 03:41:21 supernews postfix/cleanup[69879]: CF22A1708C: message-id=<20141115034121.CF22A1708C@supernews.example.org>
Nov 15 03:41:21 supernews postfix/smtpd[70475]: disconnect from unknown[107.150.52.84]
Nov 15 03:41:21 supernews postfix/qmgr[1286]: CF22A1708C: from=<double-bounce@supernews.example.org>, size=655, nrcpt=1 (queue active)
Nov 15 03:41:21 supernews postfix/local[69886]: CF22A1708C: to=<dan@supernews.example.org>, orig_to=<postmaster>, relay=local, delay=0.01, delays=0/0/0/0.01, dsn=2.0.0, status=sent (delivered to command: exec /usr/local/bin/procmail -t -a ${EXTENSION})
Nov 15 03:41:21 supernews postfix/qmgr[1286]: CF22A1708C: removed
Nov 15 03:41:21 supernews postfix/pickup[69183]: D5D2F17091: uid=1001 from=<dan>
Nov 15 03:41:21 supernews postfix/cleanup[69879]: D5D2F17091: message-id=<20141115034121.CF22A1708C@supernews.example.org>
Nov 15 03:41:21 supernews postfix/qmgr[1286]: D5D2F17091: from=<dan@supernews.example.org>, size=857, nrcpt=1 (queue active)
What? Where’s the file?
I searched and failed to find it.
Let’s look at the Postfix configuration:
[dan@supernews:/usr/local/etc/postfix] $ grep ca-bundle.crt * master.cf: -o smtpd_tls_CAfile=/usr/local/etc/ssl/ca-bundle.crt [dan@supernews:/usr/local/etc/postfix] $
I googled for smtpd_tls_CAfile to find out more and wound up reading the Postfix docs on this subject.
I looked up my own documentation on this where I found it did indeed refer to a .pem file. The Postfix docs referred to a .pem. Wait, do I have that file?
$ ls -l /usr/local/etc/ssl/ca-bundle.pem -rw------- 1 root wheel 133499 Oct 6 2013 /usr/local/etc/ssl/ca-bundle.pem
Oh, damn. Is it that easy? Yes. I updated the configuration file to refer to the correct file name, restarted Postfix, and all was well.
Next time, I won’t ignore those emails for so long.
