I think I have opportunistic TLS configured correctly in postfix but it seemingly never chooses to actually use TLS. It always falls back to an unencrypted connection and gives me no indication as to why.
Here is the relevant configuration for postfix:
smtp_tls_CAfile=/etc/pki/tls/certs/ca-bundle.crt
smtp_tls_security_level = may
smtp_tls_loglevel = 4
smtp_tls_session_cache_database = btree:/var/lib/postfix/smtp_scache
I'm not sure if it matters but this postfix instance is not the origin email server, the emails are relayed to this instance, and the relay is intentionally not encrypted (i.e. I have not set smtpd_tls_security_level on this instance).
Here is the log output after sending an email to a gmail account (I've redacted some info). I'm expecting to see more information about the TLS connection. It's a little confusing because there are two instances of postfix running on this one machine, one that is bound to 127.0.0.1 and relays to the other which is bound on a virtual IP 10.0.1.13; they both log to the same file so you have to do a bit of deciphering:
Jul 30 15:26:10 mail01-prd postfix/smtpd[3479]: connect from localhost[127.0.0.1]
Jul 30 15:26:10 mail01-prd postfix/smtpd[3479]: 2220221EB6B8: client=localhost[127.0.0.1]
Jul 30 15:26:10 mail01-prd postfix/cleanup[3482]: 2220221EB6B8: message-id=<800049941.22.1532985970098@mail01-prd.mydomain.local>
Jul 30 15:26:10 mail01-prd postfix/qmgr[10017]: 2220221EB6B8: from=<lands@mydomain.com>, size=492, nrcpt=1 (queue active)
Jul 30 15:26:10 mail01-prd postfix/smtpd[3479]: disconnect from localhost[127.0.0.1]
Jul 30 15:26:10 mail01-prd postfix/smtpd[3256]: connect from mail01-prd.mydomain.local[10.0.2.45]
Jul 30 15:26:10 mail01-prd postfix/smtpd[3256]: 2865A40C505D: client=mail01-prd.mydomain.local[10.0.2.45]
Jul 30 15:26:10 mail01-prd postfix/cleanup[3484]: 2865A40C505D: message-id=<800049941.22.1532985970098@mail01-prd.mydomain.local>
Jul 30 15:26:10 mail01-prd postfix/smtpd[3256]: disconnect from mail01-prd.mydomain.local[10.0.2.45]
Jul 30 15:26:10 mail01-prd postfix/smtp[3483]: 2220221EB6B8: to=<redacted.recipient@gmail.com>, relay=mail.mydomain.local[10.0.1.13]:25, delay=0.05, delays=0.01/0.01/0/0.03, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 2865A40C505D)
Jul 30 15:26:10 mail01-prd postfix/qmgr[3131]: 2865A40C505D: from=<lands@mydomain.com>, size=704, nrcpt=1 (queue active)
Jul 30 15:26:10 mail01-prd postfix/qmgr[10017]: 2220221EB6B8: removed
Jul 30 15:26:10 mail01-prd postfix/smtp[3486]: initializing the client-side TLS engine
Jul 30 15:26:10 mail01-prd postfix/smtp[3486]: 2865A40C505D: to=<redacted.recipient@gmail.com>, relay=gmail-smtp-in.l.google.com[74.125.195.26]:25, delay=0.36, delays=0.03/0.02/0.08/0.23, dsn=2.0.0, status=sent (250 2.0.0 OK 1532985970 e9-v6si12074342pgg.330 - gsmtp)
Jul 30 15:26:10 mail01-prd postfix/qmgr[3131]: 2865A40C505D: removed
Here is the email with headers that is received by gmail (host/ip/recipient names redacted):
Delivered-To: redacted.recipient@gmail.com
Received: by 2002:a4a:cb81:0:0:0:0:0 with SMTP id y1-v6csp4285688ooq;
Mon, 30 Jul 2018 14:26:10 -0700 (PDT)
X-Google-Smtp-Source: AAOMgpciN/INPuQuWD82OjqCJbrXEYhn9T0oHqorMQRg7EiQ0FqrPrW4jb/Stjic14k9+BnU1kQ1
X-Received: by 2002:a63:bf08:: with SMTP id v8-v6mr17488862pgf.3.1532985970510;
Mon, 30 Jul 2018 14:26:10 -0700 (PDT)
ARC-Seal: i=1; a=rsa-sha256; t=1532985970; cv=none;
d=google.com; s=arc-20160816;
b=Sl6ChvN8Nm3nhPipdoM5ODedUNXx4la4LKx31fCB8RDoC7PW5sREdnQIV4trnoZ6rW
1yBSwiqjxGJ00yzQolcCtKrlv2YEnVaXW06fFpHdCWr3LMRDQSDIsWzfX76iejvy2JOD
Y7lYwtQ3TYMGZhd97WvCABK1WrMONPIOeqYvwvfKr87znBkuPYQ/N+pntAcqzFJlLueG
sgXr+TpJVHd82f72NbdGh1mv8wsEE4IXLlGjnujtNurnXEc93kBf7eQuQTnkV41aElAT
drvXrtqSMhunbmODv7u2VexnluHnjlgOBwo96SrCboWr/sKoQU6P5uH3ZJqLVfNlIC8N
0D+A==
ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816;
h=from:content-transfer-encoding:mime-version:subject:message-id:to
:date:arc-authentication-results;
bh=g3zLYH4xKxcPrHOD18z9YfpQcnk/GaJedfustWU5uGs=;
b=Ovql6aUsRnD1conm5UblwcOCwt4AQ9uOdnSqX1HoqqwT34OO0GhJLTdh2B2oX799oU
GlrIaQaiDMGagHXxz8AYWv27G9gC0QR39pYXNAxERYLmTkpDDxkTmIPfDeRkoj2PBauh
zyzZGOsx7E+xI7MBohxetxiy0ymlXTBsE5Y4LpnL51Z31yPVtQw2fh/ATBqnlNYOKUGP
w1NvSgLpYQBJPz0nNlnYigFhwRhjTOS2YfZjWND4fyV3QTTDUpQS64Lu9uLjN/DLldFi
jIP0ONSPNv4NzQocPgyu4UaAVbU9h7W274F8F30vOWbL35qdP/LabrjQ3jus29kKsY8m
7IFw==
ARC-Authentication-Results: i=1; mx.google.com;
spf=pass (google.com: domain of lands@mydomain.com designates 1.2.3.4 as permitted sender) smtp.mailfrom=lands@mydomain.com
Return-Path: <lands@mydomain.com>
Received: from mail.mydomain.com (mail.mydomain.com. [1.2.3.4])
by mx.google.com with ESMTP id e9-v6si12074342pgg.330.2018.07.30.14.26.10
for <redacted.recipient@gmail.com>;
Mon, 30 Jul 2018 14:26:10 -0700 (PDT)
Received-SPF: pass (google.com: domain of lands@mydomain.com designates 1.2.3.4 as permitted sender) client-ip=1.2.3.4;
Authentication-Results: mx.google.com;
spf=pass (google.com: domain of lands@mydomain.com designates 1.2.3.4 as permitted sender) smtp.mailfrom=lands@mydomain.com
Received: from mail01-prd.mydomain.local (mail01-prd.mydomain.local [10.0.2.45]) by mail.mydomain.com (Postfix) with ESMTP id 2865A40C505D for <redacted.recipient@gmail.com>; Mon, 30 Jul 2018 15:26:10 -0600 (MDT)
Received: from mail01-prd.mydomain.local (localhost [127.0.0.1]) by mail01-prd.mydomain.local (Postfix) with ESMTP id 2220221EB6B8 for <redacted.recipient@gmail.com>; Mon, 30 Jul 2018 15:26:10 -0600 (MDT)
Date: Mon, 30 Jul 2018 15:26:10 -0600 (MDT)
To: redacted.recipient@gmail.com
Message-ID: <800049941.22.1532985970098@mail01-prd.mydomain.local>
Subject: ssl 4
MIME-Version: 1.0
Content-Type: text/html; charset=us-ascii
Content-Transfer-Encoding: 7bit
From: lands@mydomain.com
test
The postfix version is 2.10.1 running on CentOS 7.2.1511, selinux is disabled, and firewalld is not running. The network firewall is configured to allow outgoing connections on ports 25, 465, and 587.
Gmail displays the red icon indicating that it wasn't encrypted and the CheckTLS service also reports that it isn't encrypted using TLS.
Nothing significant showing up in /var/log/messages or /var/log/audit/audit.log.
Any ideas?
Update 2018-07-31:
I can successfully send a non-encrypted message using telnet/smtp:
[root@mail01-prd ~]# telnet -b 10.0.1.13 gmail-smtp-in.l.google.com 25
Trying 74.125.195.27...
Connected to gmail-smtp-in.l.google.com.
Escape character is '^]'.
220 mx.google.com ESMTP d38-v6si13528460pla.422 - gsmtp
EHLO mydomain.com
250-mx.google.com at your service, [204.191.254.74]
250 SIZE 157286400
MAIL FROM:redacted.sender@mydomain.com
250 2.1.0 OK d38-v6si13528460pla.422 - gsmtp
RCPT TO:redacted.recipient@gmail.com
250 2.1.5 OK d38-v6si13528460pla.422 - gsmtp
DATA
354 Start mail input; end with <CRLF>.<CRLF>
From: redacted.recipient@mydomain.com
Subject: Test
Test
.
250 2.0.0 OK 1533054157 d38-v6si13528460pla.422 - gsmtp
But I'm unable to establish a STARTTLS connection on this port:
[root@mail01-prd ~]# openssl s_client -debug -starttls smtp -crlf -connect gmail-smtp-in.l.google.com:25
CONNECTED(00000003)
read from 0xaaeb30 [0xaf4540] (4096 bytes => 55 (0x37))
0000 - 32 32 30 20 6d 78 2e 67-6f 6f 67 6c 65 2e 63 6f 220 mx.google.co
0010 - 6d 20 45 53 4d 54 50 20-6f 36 2d 76 36 73 69 38 m ESMTP o6-v6si8
0020 - 36 34 39 31 37 39 70 6c-68 2e 32 32 36 20 2d 20 649179plh.226 -
0030 - 67 73 6d 74 70 0d 0a gsmtp..
write to 0xaaeb30 [0xaf5550] (25 bytes => 25 (0x19))
0000 - 45 48 4c 4f 20 6f 70 65-6e 73 73 6c 2e 63 6c 69 EHLO openssl.cli
0010 - 65 6e 74 2e 6e 65 74 0d-0a ent.net..
read from 0xaaeb30 [0xaf4540] (4096 bytes => 73 (0x49))
0000 - 32 35 30 2d 6d 78 2e 67-6f 6f 67 6c 65 2e 63 6f 250-mx.google.co
0010 - 6d 20 61 74 20 79 6f 75-72 20 73 65 72 76 69 63 m at your servic
0020 - 65 2c 20 5b 32 30 34 2e-31 39 31 2e 32 35 34 2e e, [204.191.254.
0030 - 37 34 5d 0d 0a 32 35 30-20 53 49 5a 45 20 31 35 74]..250 SIZE 15
0040 - 37 32 38 36 34 30 30 0d-0a 7286400..
didn't found starttls in server response, try anyway...
write to 0xaaeb30 [0x7ffef414dfc0] (10 bytes => 10 (0xA))
0000 - 53 54 41 52 54 54 4c 53-0d 0a STARTTLS..
read from 0xaaeb30 [0x9e2e20] (8192 bytes => 40 (0x28))
0000 - 35 30 30 20 53 79 6e 74-61 78 20 65 72 72 6f 72 500 Syntax error
0010 - 2c 20 63 6f 6d 6d 61 6e-64 20 75 6e 72 65 63 6f , command unreco
0020 - 67 6e 69 7a 65 64 0d 0a- gnized..
write to 0xaaeb30 [0xaf44c0] (289 bytes => 289 (0x121))
0000 - 16 03 01 01 1c 01 00 01-18 03 03 31 d6 0a a9 f9 ...........1....
0010 - 56 55 0c cd 05 8e 02 16-a9 01 f0 78 a2 f9 4b c7 VU.........x..K.
0020 - f4 03 e3 49 1f f3 f1 1a-56 3a 1c 00 00 ac c0 30 ...I....V:.....0
0030 - c0 2c c0 28 c0 24 c0 14-c0 0a 00 a5 00 a3 00 a1 .,.(.$..........
0040 - 00 9f 00 6b 00 6a 00 69-00 68 00 39 00 38 00 37 ...k.j.i.h.9.8.7
0050 - 00 36 00 88 00 87 00 86-00 85 c0 32 c0 2e c0 2a .6.........2...*
0060 - c0 26 c0 0f c0 05 00 9d-00 3d 00 35 00 84 c0 2f .&.......=.5.../
0070 - c0 2b c0 27 c0 23 c0 13-c0 09 00 a4 00 a2 00 a0 .+.'.#..........
0080 - 00 9e 00 67 00 40 00 3f-00 3e 00 33 00 32 00 31 ...g.@.?.>.3.2.1
0090 - 00 30 00 9a 00 99 00 98-00 97 00 45 00 44 00 43 .0.........E.D.C
00a0 - 00 42 c0 31 c0 2d c0 29-c0 25 c0 0e c0 04 00 9c .B.1.-.).%......
00b0 - 00 3c 00 2f 00 96 00 41-c0 12 c0 08 00 16 00 13 .<./...A........
00c0 - 00 10 00 0d c0 0d c0 03-00 0a 00 07 c0 11 c0 07 ................
00d0 - c0 0c c0 02 00 05 00 04-00 ff 01 00 00 43 00 0b .............C..
00e0 - 00 04 03 00 01 02 00 0a-00 0a 00 08 00 17 00 19 ................
00f0 - 00 18 00 16 00 23 00 00-00 0d 00 20 00 1e 06 01 .....#..... ....
0100 - 06 02 06 03 05 01 05 02-05 03 04 01 04 02 04 03 ................
0110 - 03 01 03 02 03 03 02 01-02 02 02 03 00 0f 00 01 ................
0120 - 01
I'm assuming I've done something wrong there, I just haven't figured out what it is yet.
Best Answer
It turns out it was Untangle that was actively rewriting the SMTP commands to prevent a TLS connection from being established. This became clear after telneting directly to google's SMTP server and finding out that it wasn't responding to the EHLO command with an offer for STARTTLS (because Untangle stripped it away).
I followed the instructions here:
https://forums.untangle.com/spam-blocker-lite/34567-smtp-block-starttls.html
Essentially going to Config -> networking -> bypass rules and adding an extra rule to prevent it from inspecting SMTP data.