On Sun, Feb 17, 2019 at 10:31:05PM +0100, A. Schulze wrote:
> ok, so I start silent testing ...
>
> https://andreasschulze.de/tmp/reuse_on.txt
> https://andreasschulze.de/tmp/reuse_off.txt
Thanks, these get us much closer to the source of the problem.
Something about the way the way that chain verification is happening
in the proxy appears to cause the chain to be verified differently.
I'll try to investigate from here. There's nothing at first blush
with the "postconf -nf" or "postconf -Mf" that would suggest any
relevant issues.
No proxy:
DANE-use evidenced by use of normally disabled SNI, and
"trust-anchor signed" status, verification succeeds with a TA
public key match at depth 1:
Feb 17 22:11:53 mail postfix/smtp[23428]:
setting up TLS connection to sys1.mmini.de[2a01:4f8:162:32ac::2]:25
...
Feb 17 22:11:53 mail postfix/smtp[23428]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: SNI hostname: sys1.mmini.de
...
Feb 17 22:11:53 mail postfix/smtp[23428]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=1 matched trust anchor public-key
sha256
digest=60:B8:75:75:44:7D:CB:A2:A3:6B:7D:11:AC:09:FB:24:A9:DB:40:6F:EE:12:D2:CC:90:18:05:17:61:6E:8A:18
Feb 17 22:11:53 mail postfix/smtp[23428]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=0 chain is trust-anchor signed
Feb 17 22:11:53 mail postfix/smtp[23428]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=0 verify=1
subject=/CN=raketenstaffel.de
Feb 17 22:11:53 mail postfix/smtp[23428]: SSL_connect:SSLv3/TLS read server
certificate
...
Feb 17 22:11:53 mail postfix/tlsmgr[23429]: write smtp TLS cache entry
smtp&gervers.com&sys1.mmini.de&2a01:4f8:162:32ac::2&&636409472BD3C450C50707A4F46B749E669552335D3415B49FB59B1A82A2D7B1:
time=1550437913 [data 1774 bytes]
Feb 17 22:11:53 mail postfix/smtp[23428]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25:
subject_CN=sys1.mmini.de, issuer_CN=Let's Encrypt Authority X3,
fingerprint=20:F4:59:CA:8C:7C:D7:21:21:43:16:54:F0:F1:24:35:85:75:00:D7,
pkey_fingerprint=86:53:E8:0E:7A:48:A1:C6:DC:1C:F6:81:16:A9:04:4B:80:EE:F4:2C
Feb 17 22:11:53 mail postfix/smtp[23428]: Verified TLS connection
established to
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: TLSv1.2
with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
With proxy:
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: CONNECT to
[2a01:4f8:162:32ac::2]:25
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: setting up TLS connection to
sys1.mmini.de[2a01:4f8:162:32ac::2]:25
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: looking for session
smtp&gervers.com&sys1.mmini.de&2a01:4f8:162:32ac::2&&636409472BD3C450C50707A4F46B749E669552335D3415B49FB59B1A82A2D7B1
in smtp cache
Same session lookup key which hashes the TLS policy settings
evidences the same TLS settings in both cases.
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: SNI hostname: sys1.mmini.de
Same IPv6 address and SNI name as without the proxy.
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=1 matched trust anchor public-key
sha256
digest=60:B8:75:75:44:7D:CB:A2:A3:6B:7D:11:AC:09:FB:24:A9:DB:40:6F:EE:12:D2:CC:90:18:05:17:61:6E:8A:18
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=0 chain is trust-anchor signed
So far, so good, the chain should now be verified.
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=1 verify=0 subject=/C=US/O=Let's
Encrypt/CN=Let's Encrypt Authority X3
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=1 verify=0 subject=/C=US/O=Let's
Encrypt/CN=Let's Encrypt Authority X3
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=1 verify=0 subject=/C=US/O=Let's
Encrypt/CN=Let's Encrypt Authority X3
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[2a01:4f8:162:32ac::2]:25: depth=0 verify=1
subject=/CN=raketenstaffel.de
But suddenly, we're doing some sort of additional non-DANE
certificate checks at depth 1. Not yet clear why. These fail.
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: SSL_connect:SSLv3/TLS read
server certificate
...
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: save session
smtp&gervers.com&sys1.mmini.de&2a01:4f8:162:32ac::2&&636409472BD3C450C50707A4F46B749E669552335D3415B49FB59B1A82A2D7B1
to smtp cache
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: CA certificate verification
failed for sys1.mmini.de[2a01:4f8:162:32ac::2]:25: num=28:certificate rejected
...
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: Untrusted TLS connection
established to sys1.mmini.de[2a01:4f8:162:32ac::2]:25: TLSv1.2 with cipher
ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Peer verification failed in the proxy.
Feb 17 22:08:45 mail postfix/smtp[23259]: Untrusted TLS connection
established to sys1.mmini.de[2a01:4f8:162:32ac::2]:25: TLSv1.2 with cipher
ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Feb 17 22:08:45 mail postfix/smtp[23259]: 442fk50Pg3z1CY: Server
certificate not trusted
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: DISCONNECT
[2a01:4f8:162:32ac::2]:25
The smtp(8) client learns the bad news, and we try again, now with IPv4:
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: looking for session
smtp&gervers.com&sys1.mmini.de&5.9.100.168&&636409472BD3C450C50707A4F46B749E669552335D3415B49FB59B1A82A2D7B1
in smtp cache
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[5.9.100.168]:25: SNI hostname: sys1.mmini.de
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: sys1.mmini.de[5.9.100.168]:25:
depth=1 matched trust anchor public-key sha256
digest=60:B8:75:75:44:7D:CB:A2:A3:6B:7D:11:AC:09:FB:24:A9:DB:40:6F:EE:12:D2:CC:90:18:05:17:61:6E:8A:18
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[5.9.100.168]:25: depth=0 chain is trust-anchor signed
As expected with DANE.
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[5.9.100.168]:25: depth=1 verify=0
subject=/C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[5.9.100.168]:25: depth=1 verify=0
subject=/C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[5.9.100.168]:25: depth=1 verify=0
subject=/C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[5.9.100.168]:25:
depth=0 verify=1 subject=/CN=raketenstaffel.de
These callbacks are NOT expected.
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: SSL_connect:SSLv3/TLS read
server certificate
...
Feb 17 22:08:45 mail postfix/tlsproxy[23261]: CA certificate verification
failed for sys1.mmini.de[5.9.100.168]:25: num=28:certificate rejected
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
sys1.mmini.de[5.9.100.168]:25: subject_CN=raketenstaffel.de,
issuer_CN=Let's Encrypt Authority X3,
fingerprint=20:F4:59:CA:8C:7C:D7:21:21:43:16:54:F0:F1:24:35:85:75:00:D7,
pkey_fingerprint=86:53:E8:0E:7A:48:A1:C6:DC:1C:F6:81:16:A9:04:4B:80:EE:F4:2C
Same certificate fingerprint as without the proxy.
Feb 17 22:08:45 mail postfix/tlsproxy[23261]:
Untrusted TLS connection established to sys1.mmini.de[5.9.100.168]:25:
TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Feb 17 22:08:45 mail postfix/smtp[23259]: Untrusted TLS connection
established to
sys1.mmini.de[5.9.100.168]:25: TLSv1.2 with cipher
ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Feb 17 22:08:45 mail postfix/smtp[23259]: 442fk50Pg3z1CY:
to=<recipi...@gervers.com>,
relay=sys1.mmini.de[5.9.100.168]:25, delay=0.56,
delays=0.1/0.03/0.43/0, dsn=4.7.5,
status=undeliverable (Server certificate not trusted)
Bad news.
--
Viktor.
