A. Schulze:
>
>
> Am 17.02.19 um 15:24 schrieb Wietse Venema:
> > A. Schulze:
> >> Hello,
> >>
> >> I updated to postfix 3.4.0-RC2 and enabled "smtp_tls_connection_reuse"
> >> Now I notice delivery problems to "gervers.com". DANE setup looks OK.
> >> https://dane.sys4.de/smtp/gervers.com
> >>
> >> "posttls-finger gervers.com" also show
> >> posttls-finger: 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)
> >>
> >> But a message to the domain is not delivered. Instead I found this logged
> >> by tlsproxy:
> >>
> >> Feb 17 14:18:28 mail postfix/tlsproxy[14593]:
> >> sys1.mmini.de[5.9.100.168]:25: re-using session with untrusted
> >> certificate, look for details earlier in the log
> >> Feb 17 14:18:28 mail postfix/tlsproxy[14593]: 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)
> >>
> >> But I did not found anything special "earlier in the log" ...
> >
> > Surely the SMTP client logged SOMETHING?
> >
> > Surely the tlsproxy daemon logged SOMETHING when it created the TLS
> > connection?
>
> Hello Wietse,
>
> thanks for asking :-) Yes, of corse, there are other loglines...
> Here are the all message and connection related entries (I found):
>
> Feb 17 10:27:54 mail postfix/smtpd[9445]: 442M9Q3L8Kzkn:
> client=localhost[127.0.0.1]
> Feb 17 10:27:54 mail postfix/cleanup[9442]: 442M9Q3L8Kzkn: message-id=<....>
> Feb 17 10:27:54 mail opendkim[19651]: 442M9Q3L8Kzkn: DKIM-Signature field
> added
> Feb 17 10:27:54 mail postfix/qmgr[29788]: 442M9Q3L8Kzkn: from=<...>,
> size=1802, nrcpt=1 (queue active)
> Feb 17 10:27:55 mail postfix/tlsproxy[9450]: CONNECT to [5.9.100.168]:25
> Feb 17 10:27:55 mail postfix/tlsproxy[9450]: CA certificate verification
> failed for sys1.mmini.de[5.9.100.168]:25: num=28:certificate rejected
> Feb 17 10:27:55 mail postfix/tlsproxy[9450]: 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 10:27:55 mail postfix/smtp[9452]: 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 10:27:55 mail postfix/smtp[9452]: 442M9Q3L8Kzkn: Server certificate
> not trusted
> Feb 17 10:27:55 mail postfix/tlsproxy[9450]: DISCONNECT [5.9.100.168]:25
> Feb 17 10:27:56 mail postfix/tlsproxy[9450]: CONNECT to
> [2a01:4f8:162:32ac::2]:25
> Feb 17 10:27:56 mail postfix/tlsproxy[9450]: CA certificate verification
> failed for sys1.mmini.de[2a01:4f8:162:32ac::2]:25: num=28:certificate rejected
> Feb 17 10:27:56 mail postfix/tlsproxy[9450]: 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 10:27:56 mail postfix/smtp[9452]: 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 10:27:56 mail postfix/smtp[9452]: 442M9Q3L8Kzkn: to=<***@gervers.com>,
> relay=sys1.mmini.de[2a01:4f8:162:32ac::2]:25, delay=1.6,
> delays=0.11/0.02/1.5/0, dsn=4.7.5, status=deferred (Server certificate not
> trusted)
> Feb 17 10:27:56 mail postfix/tlsproxy[9450]: DISCONNECT
> [2a01:4f8:162:32ac::2]:25
>
> the same tlsproxy process handled 5 other connections before this one. All
> logged as 'Untrusted TLS connection established to'
How do those 'other' connections differ from what is shown above?
What I see is an SMTP client deferring delivery with a NEW TLS
connection. That is different from your earlier report about a
REUSED connection.
Can you confirm that the SMTP client will not deliver to this
destination with NEW and REUSED tlsproxy connections?
The error message suggests a problem in the certificate trust chain,
like an unknown root certificate. What is the output from:
postconf -F smtp/unix/chroot tlsproxy/unix/chroot
Wietse
