Resolved: warning: request to update table btree:/var/run/smtp_tls_session_cache in non-postfix directory /var/run

There were a few warning popping up in my /var/log/mail.warn log for Postfix, like this:

Feb  4 09:16:15 sixsigma postfix/tlsmgr[3394]: warning: request to update table
btree:/var/run/smtpd_tls_session_cache in non-postfix directory /var/run
Feb  4 09:16:15 sixsigma postfix/tlsmgr[3394]: warning: redirecting the request
to postfix-owned data_directory /var/lib/postfix
Feb  4 09:16:15 sixsigma postfix/tlsmgr[3394]: warning: request to update table
btree:/var/run/smtp_tls_session_cache in non-postfix directory /var/run
Feb  4 09:16:15 sixsigma postfix/tlsmgr[3394]: warning: redirecting the request
to postfix-owned data_directory /var/lib/postfix

I fixed the problem by reconfiguring /etc/postfix/main.cf and changing this:

smtpd_tls_session_cache_database = btree:/var/run/smtpd_tls_session_cache
smtp_tls_session_cache_database = btree:/var/run/smtp_tls_session_cache

To this:

smtpd_tls_session_cache_database = btree:/var/lib/postfix/smtpd_tls_session_cache
smtp_tls_session_cache_database = btree:/var/lib/postfix/smtp_tls_session_cache

Postfix header checks

I wanted to do something about the fact that I get a lot of spam where the date is substantially in the past, that is, months or years ago.

I figure I’ll never get any mail that I care about where the date is set that far back so what I wanted was a way to filter out such email.

There didn’t seem to be any suitable option in Thunderbird, and I’d rather have this done on the server than the client anyway, so I started fishing around for options in Postfix.

I found out about header checks.

To enable I had to add a file to the header_checks configuration option in /etc/postfix/main.cf:

header_checks =
  regexp:/etc/postfix/header_filter_map
  regexp:/etc/postfix/spamheadercheck

Then I created a header_filter_map file with some regexes for the date:

/^Date: .* [JFMASOND][aepuco][nbrynlgptvc] 1\d\d\d/ DISCARD Date 1
/^Date: .* [JFMASOND][aepuco][nbrynlgptvc] 200\d/ DISCARD Date 2
/^Date: .* [JFMASOND][aepuco][nbrynlgptvc] 201[0-1]/ DISCARD Date 3
/^Date: .* Jan 2012/ DISCARD Date Jan
/^Date: .* Feb 2011/ DISCARD Date Feb
/^Date: .* Mar 2011/ DISCARD Date Mar
/^Date: .* Apr 2011/ DISCARD Date Apr
/^Date: .* May 2011/ DISCARD Date May
/^Date: .* Jun 2011/ DISCARD Date Jun
/^Date: .* Jul 2011/ DISCARD Date Jul
/^Date: .* Aug 2011/ DISCARD Date Aug
/^Date: .* Sep 2011/ DISCARD Date Sep
/^Date: .* Oct 2011/ DISCARD Date Oct
/^Date: .* Nov 2011/ DISCARD Date Nov
/^Date: .* Dec 2011/ DISCARD Date Dec

I also found this file so I added some rules for the X-Mailer header, like this:

/^X-Mailer: 0001/                               DISCARD Mailer 1
/^X-Mailer: Avalanche/                          DISCARD Mailer 2
/^X-Mailer: Crescent Internet Tool/             DISCARD Mailer 3
/^X-Mailer: DiffondiCool/                       DISCARD Mailer 4
/^X-Mailer: E-Mail Delivery Agent/              DISCARD Mailer 5
/^X-Mailer: Emailer Platinum/                   DISCARD Mailer 6
/^X-Mailer: Entity/                             DISCARD Mailer 7
/^X-Mailer: Extractor/                          DISCARD Mailer 8
/^X-Mailer: Floodgate/                          DISCARD Mailer 9
/^X-Mailer: GOTO Software Sarbacane/            DISCARD Mailer 10
/^X-Mailer: MailWorkz/                          DISCARD Mailer 11
/^X-Mailer: MassE-Mail/                         DISCARD Mailer 12
/^X-Mailer: MaxBulk.Mailer/                     DISCARD Mailer 13
/^X-Mailer: News Breaker Pro/                   DISCARD Mailer 14
/^X-Mailer: SmartMailer/                        DISCARD Mailer 15
/^X-Mailer: StormPort/                          DISCARD Mailer 16
/^X-Mailer: SuperMail-2/                        DISCARD Mailer 17

Now that I know how to do this I’ll start adding rules for particular spam that I seem to get a lot of.

I’m not sure if I made the best decision, but I decided to silently discard email rather than reject it.

Problem with STARTTLS in local spampd filter

As part of my anti-spam solution I have Postfix send mail to another Postfix instance running on another port, and I’m still a little confused about how it all works, but basically I had a problem in my mail logs that looked like this:

root@sixsigma:/var/log# tail -f mail.log | grep "\(SSL\)\|\(TLS\)"
Feb  1 03:51:16 sixsigma postfix/smtpd[8636]: setting up TLS connection from localhost[127.0.0.1]
Feb  1 03:51:16 sixsigma postfix/smtpd[8636]: localhost[127.0.0.1]: TLS cipher list "ALL:+RC4:@STRENGTH"
Feb  1 03:51:16 sixsigma postfix/smtpd[8636]: SSL_accept:before/accept initialization
Feb  1 03:52:19 sixsigma postfix/smtpd[8556]: SSL_accept error from localhost[127.0.0.1]: -1
Feb  1 03:52:19 sixsigma postfix/smtpd[8556]: lost connection after STARTTLS from localhost[127.0.0.1]
Feb  1 03:52:19 sixsigma postfix/smtp[8555]: SSL_connect error to 127.0.0.1[127.0.0.1]:10025: -1
Feb  1 03:52:19 sixsigma postfix/smtp[8555]: B97C42542CE: Cannot start TLS: handshake failure
Feb  1 03:52:19 sixsigma postfix/smtpd[8651]: initializing the server-side TLS engine
Feb  1 03:52:19 sixsigma postfix/smtp[8555]: Host offered STARTTLS: [127.0.0.1]
Feb  1 03:55:06 sixsigma postfix/smtpd[8660]: initializing the server-side TLS engine
Feb  1 03:55:06 sixsigma postfix/smtpd[8660]: setting up TLS connection from localhost[127.0.0.1]
Feb  1 03:55:06 sixsigma postfix/smtpd[8660]: localhost[127.0.0.1]: TLS cipher list "ALL:+RC4:@STRENGTH"
Feb  1 03:55:06 sixsigma postfix/smtpd[8660]: SSL_accept:before/accept initialization
Feb  1 03:56:09 sixsigma postfix/smtpd[8664]: initializing the server-side TLS engine
Feb  1 03:56:09 sixsigma postfix/smtpd[8664]: setting up TLS connection from localhost[127.0.0.1]
Feb  1 03:56:09 sixsigma postfix/smtpd[8664]: localhost[127.0.0.1]: TLS cipher list "ALL:+RC4:@STRENGTH"
Feb  1 03:56:09 sixsigma postfix/smtpd[8664]: SSL_accept:before/accept initialization
Feb  1 03:56:16 sixsigma postfix/smtp[8649]: SSL_connect error to 127.0.0.1[127.0.0.1]:10025: -1
Feb  1 03:56:16 sixsigma postfix/smtpd[8636]: SSL_accept error from localhost[127.0.0.1]: -1
Feb  1 03:56:16 sixsigma postfix/smtp[8649]: 5E6172542D0: Cannot start TLS: handshake failure
Feb  1 03:56:16 sixsigma postfix/smtpd[8636]: lost connection after STARTTLS from localhost[127.0.0.1]
Feb  1 03:56:16 sixsigma postfix/smtp[8649]: Host offered STARTTLS: [127.0.0.1]
Feb  1 03:56:54 sixsigma postfix/smtpd[8636]: setting up TLS connection from localhost[127.0.0.1]
Feb  1 03:56:54 sixsigma postfix/smtpd[8636]: localhost[127.0.0.1]: TLS cipher list "ALL:+RC4:@STRENGTH"
Feb  1 03:56:54 sixsigma postfix/smtpd[8636]: SSL_accept:before/accept initialization

You can see an error “SSL_connect error to 127.0.0.1[127.0.0.1]:10025” which means, as far as I can tell, that when the primary Postfix instance uses SMTP to connect to the SMTPD at 127.0.0.1:10025 there is a problem with TLS support. It seems that the software listening on 127.0.0.1:10025 thinks it can support TLS but then can’t.

I did some research and learned about Per-site TLS policies. So I created a policy file that looks like this:

root@sixsigma:/etc# cat postfix/tls_per_site
# JE 2012-02-01: http://www.postfix.org/TLS_LEGACY_README.html#client_tls_per_site
localhost:10025 NONE

Basically it says not to use TLS when connecting to localhost on port 10025. The spampd software is listening on port 100025 and Postfix is using spampd as a content filter:

root@sixsigma:/etc# grep -R 10025 *
default/spampd:LISTENPORT=10025
postfix/main.cf:content_filter = scan:[127.0.0.1]:10025

I think when spampd is done it connects back to Postfix listening on port 10026:

root@sixsigma:/etc# grep -R 10026 *
default/spampd:DESTPORT=10026
postfix/master.cf:localhost:10026 inet    n       -       n       -       10      smtpd

So I configured the Postfix instance on 10026 not to use TLS:

root@sixsigma:/etc# cat postfix/master.cf
...
localhost:10026 inet    n       -       n       -       10      smtpd
        -o content_filter=
        -o local_recipient_maps=
        -o relay_recipient_maps=
        -o myhostname=filter.mynetwork.local
        -o smtpd_helo_restrictions=
        -o smtpd_client_restrictions=
        -o smtpd_sender_restrictions=
        -o smtpd_recipient_restrictions=permit_mynetworks,reject
        -o mynetworks=127.0.0.0/8
        -o smtpd_use_tls=no
        -o smtp_use_tls=no
...

Then I revised my primary Postfix TLS configuration so that it looked like this:

root@sixsigma:/etc# cat postfix/main.cf
...
# JE 2012-01-20: http://www.howtoforge.com/centos-5.1-server-lamp-email-dns-ftp-ispconfig-p5
# JE 2012-02-01: http://www.postfix.org/TLS_LEGACY_README.html#client_tls_per_site

smtpd_use_tls = yes
smtpd_tls_auth_only = no
smtpd_tls_cert_file = /root/cert/blackbrick.com.crt
smtpd_tls_key_file = /root/cert/blackbrick.key
smtpd_tls_CAfile = /root/cert/gd_bundle.crt
smtpd_tls_loglevel = 1
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
smtpd_tls_session_cache_database = btree:/var/run/smtpd_tls_session_cache

smtp_use_tls = yes
smtp_tls_note_starttls_offer = yes
smtp_tls_per_site = hash:/etc/postfix/tls_per_site
smtp_tls_cert_file = /root/cert/blackbrick.com.crt
smtp_tls_key_file = /root/cert/blackbrick.key
smtp_tls_CAfile = /root/cert/gd_bundle.crt
smtp_tls_session_cache_database = btree:/var/run/smtp_tls_session_cache

tls_random_source = dev:/dev/urandom

So I have a smtp_tls_per_site parameter referencing my policy file, and the policy file says not to use TLS when connecting to localhost:10025.

Now when I watch the logs I’m not seeing any errors:

root@sixsigma:/var/log# tail -f mail.log | grep "\(SSL\)\|\(TLS\)"
Feb  1 04:33:58 sixsigma postfix/smtpd[8989]: setting up TLS connection from 60-240-67-126.tpgi.com.au[60.240.67.126]
Feb  1 04:33:59 sixsigma postfix/smtpd[8989]: Anonymous TLS connection established from 60-240-67-126.tpgi.com.au[60.240.67.126]: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)

So it all seems to be working. I guess the only thing that I’m worried about is that I’ve somehow disabled TLS in situations where I want it (which is all of the time except for local traffic). But… it seems like I got it right.

As mentioned over on Re: Postfix Cannot start TLS:

If using Postfix 2.2 or earlier, disable opportunistic TLS for this destination.

  http://www.postfix.org/TLS_LEGACY_README.html#client_tls_per_site

With Postfix 2.3 and later, opportunistic TLS handshake failures trigger a plain-text retry, so no policy table entries are required to send email to sites with broken TLS (provided you are not trying to enforce TLS).

So that explains why I was seeing the errors in the logs but that mail was still being delivered. Postfix was trying again after TLS failed. Anyway, it should be a little faster now, at least. And I won’t have useless errors clogging up my logs anymore.

Postfix smtps configuration

I found some information on configuring Postfix to provide SMTPS (SSL/TLS) services on CentOS 5.1 Server Setup: LAMP, Email, DNS, FTP, ISPConfig (a.k.a. The Perfect Server) – Page 5 and Getting Postfix to run SMTPS on port 465.

The first article suggests main.cf configuration settings such as:

postconf -e 'smtpd_sasl_local_domain ='
postconf -e 'smtpd_sasl_auth_enable = yes'
postconf -e 'smtpd_sasl_security_options = noanonymous'
postconf -e 'broken_sasl_auth_clients = yes'
postconf -e 'smtpd_recipient_restrictions = permit_sasl_authenticated,permit_mynetworks,reject_unauth_destination'
postconf -e 'inet_interfaces = all'
postconf -e 'mynetworks = 127.0.0.0/8'

postconf -e 'smtpd_tls_auth_only = no'
postconf -e 'smtp_use_tls = yes'
postconf -e 'smtpd_use_tls = yes'
postconf -e 'smtp_tls_note_starttls_offer = yes'
postconf -e 'smtpd_tls_key_file = /etc/postfix/ssl/smtpd.key'
postconf -e 'smtpd_tls_cert_file = /etc/postfix/ssl/smtpd.crt'
postconf -e 'smtpd_tls_CAfile = /etc/postfix/ssl/cacert.pem'
postconf -e 'smtpd_tls_loglevel = 1'
postconf -e 'smtpd_tls_received_header = yes'
postconf -e 'smtpd_tls_session_cache_timeout = 3600s'
postconf -e 'tls_random_source = dev:/dev/urandom'

postconf -e 'myhostname = server1.example.com'

And the second article tells how to modify master.cf to enable SMTPS:

smtps     inet  n       -       n       -       -       smtpd
  -o smtpd_tls_wrappermode=yes
  -o smtpd_sasl_auth_enable=yes
  -o smtpd_client_restrictions=permit_sasl_authenticated,reject