Re: DELIVERY issue with postfix 3.4.0-RC2

2019-02-17 Thread A. Schulze
Am 17.02.19 um 14:41 schrieb A. Schulze:
> I updated to postfix 3.4.0-RC2 and enabled "smtp_tls_connection_reuse"

corrected the subject, as DANE is not necessary related here.


Re: DELIVERY issue with postfix 3.4.0-RC2

2019-02-17 Thread 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'

Andreas


Re: DELIVERY issue with postfix 3.4.0-RC2

2019-02-17 Thread Wietse Venema
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


Re: DELIVERY issue with postfix 3.4.0-RC2

2019-02-17 Thread A. Schulze



Am 17.02.19 um 16:10 schrieb Wietse Venema:

> How do those 'other' connections differ from what is shown above?
I don't see differences. This tlsproxy process handled a connection to gmail, 
outlook.com and some other destinations. All unverified because I did not 
configure the matching root certificates.
Interesting: it also handled later an other connection to an other destination 
that *could* be verified using DANE (verified connection established to ...)
 
> 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?
cannot check that without bothering the receiver with annoying test messages.
Will ask for permission...

> The error message suggests a problem in the certificate trust chain,
> like an unknown root certificate.

that's the point I started with subject "DANE issue..."
The destination don't need any certificate chains. The destination can be 
validated using DANE.

> What is the output from:
> 
> postconf -F smtp/unix/chroot tlsproxy/unix/chroot
smtp/unix/chroot = y
tlsproxy/unix/chroot = y

Andreas


Re: DELIVERY issue with postfix 3.4.0-RC2

2019-02-17 Thread Wietse Venema
Wietse Venema:
> How do those 'other' connections differ from what is shown above?

A. Schulze:
> I don't see differences. This tlsproxy process handled a connection
> to gmail, outlook.com and some other destinations. All unverified
> because I did not configure the matching root certificates.

Conclusion: Postfix works as expected? I see no unexplained failures.

> Interesting: it also handled later an other connection to an other
> destination that *could* be verified using DANE (verified connection
> established to ...)

That is expected. DANE aims to lessen the dependency on PKI.

Wietse


Re: DELIVERY issue with postfix 3.4.0-RC2

2019-02-17 Thread A. Schulze



Am 17.02.19 um 18:23 schrieb Wietse Venema:
> Conclusion: Postfix works as expected?

hard to say...

delivery deferred if smtp_tls_connection_reuse = yes
delivery works if smtp_tls_connection_reuse = no

http://www.postfix.org/TLS_README.html#client_tls_reuse say "As of Postfix 3.4, 
TLS connection reuse is disabled by default."
As usual, you select good defaults :-)

I'll make some further test next week and report my findings...

Andreas



Re: DELIVERY issue with postfix 3.4.0-RC2

2019-02-17 Thread Wietse Venema
A. Schulze:
> 
> 
> Am 17.02.19 um 18:23 schrieb Wietse Venema:
> > Conclusion: Postfix works as expected?
> 
> hard to say...
> 
> delivery deferred if smtp_tls_connection_reuse = yes
> delivery works if smtp_tls_connection_reuse = no

Is the problem that certificate verification failure handling is
different depending on the smtp_tls_connection_reuse setting?

Are there other problems?

With smtp_tls_connection_reuse=yes, does certificate verification
failure handling differ for connection that is logged as "new" or
as "reused"?

Wietse