Re: What is happening here? (TLS Library Problem)

2022-06-10 Thread Viktor Dukhovni 
On Fri, Jun 10, 2022 at 02:55:24PM +0200, Gerben Wierda wrote:

> > which links to https://github.com/openssl/openssl/issues/11378 
> > . The
> > latter had a breaking fix, backed it out for OpenSSL 1.1.1, but
> > kept it in the branch that become OpenSSL 3.
> 
> So basically, the sender doesn’t properly close the SSL protocol,
> their MTA is using an SSL which isn’t properly implemented.

No, the sending application tears down the TLS connections abruptly,
without calling SSL_shutdown(), it is free to do so, and also the TCP
connection can terminate before the "close_notify" alert is received.

This is expected to happen some of the time, not an SSL library bug.
Many application protocols (e.g. SMTP) have some sort of explicit
message framing, and are resilient against message truncation at
connection close.

-- 
Viktor.

Re: What is happening here? (TLS Library Problem)

2022-06-10 Thread Viktor Dukhovni 
On Fri, Jun 10, 2022 at 07:17:45AM -0400, Wietse Venema wrote:

> Specifically, google 0A000126, the first result is PHP issue 8369a
> which links to https://github.com/openssl/openssl/issues/11378. The
> latter had a breaking fix, backed it out for OpenSSL 1.1.1, but
> kept it in the branch that become OpenSSL 3.

I guess that makes for a bit of bitrot to handle in the Postfix TLS
layer.  We need to add "SSL_OP_IGNORE_UNEXPECTED_EOF" to the SSL options
when defined (OpenSSL 3.0 and later).

-- 
Viktor.

--- src/tls/tls.h
+++ src/tls/tls.h
@@ -387,6 +387,13 @@ extern void tls_param_init(void);
 #define SSL_OP_NO_TLSv1_3  0L  /* Noop */
 #endif
 
+/*
+ * Always used when defined, SMTP has no trucation attacks.
+ */
+#ifndef SSL_OP_IGNORE_UNEXPECTED_EOF
+#define SSL_OP_IGNORE_UNEXPECTED_EOF0L
+#endif
+
 #define TLS_KNOWN_PROTOCOLS \
( TLS_PROTOCOL_SSLv2 | TLS_PROTOCOL_SSLv3 | TLS_PROTOCOL_TLSv1 \
   | TLS_PROTOCOL_TLSv1_1 | TLS_PROTOCOL_TLSv1_2 | TLS_PROTOCOL_TLSv1_3 
)
@@ -403,7 +410,8 @@ extern void tls_param_init(void);
  * just exposed via hex codes or named elements of tls_ssl_options.
  */
 #define TLS_SSL_OP_MANAGED_BITS \
-   (SSL_OP_CIPHER_SERVER_PREFERENCE | TLS_SSL_OP_PROTOMASK(~0))
+   (SSL_OP_CIPHER_SERVER_PREFERENCE | SSL_OP_IGNORE_UNEXPECTED_EOF | \
+TLS_SSL_OP_PROTOMASK(~0))
 
 extern int tls_proto_mask_lims(const char *, int *, int *);
 
--- src/tls/tls_client.c
+++ src/tls/tls_client.c
@@ -713,6 +713,16 @@ TLS_APPL_STATE *tls_client_init(const 
TLS_CLIENT_INIT_PROPS *props)
 }
 tls_dane_digest_init(client_ctx, fpt_alg);
 
+/*
+ * Presently we use TLS only with SMTP where truncation attacks are not
+ * possible as a result of application framing.  If we ever use TLS in
+ * some other application protocol where truncation could be relevant,
+ * we'd need to disable truncation detection conditionally, or expcitly
+ * clear the option in that code path.
+ *
+ */
+off |= SSL_OP_IGNORE_UNEXPECTED_EOF;
+
 /*
  * Protocol selection is destination dependent, so we delay the protocol
  * selection options to the per-session SSL object.
--- src/tls/tls_server.c
+++ src/tls/tls_server.c
@@ -512,6 +512,16 @@ TLS_APPL_STATE *tls_server_init(const 
TLS_SERVER_INIT_PROPS *props)
 if (scache_timeout <= 0)
cachable = 0;
 
+/*
+ * Presently we use TLS only with SMTP where truncation attacks are not
+ * possible as a result of application framing.  If we ever use TLS in
+ * some other application protocol where truncation could be relevant,
+ * we'd need to disable truncation detection conditionally, or expcitly
+ * clear the option in that code path.
+ *
+ */
+off |= SSL_OP_IGNORE_UNEXPECTED_EOF;
+
 /*
  * Protocol work-arounds, OpenSSL version dependent.
  */

Re: What is happening here? (TLS Library Problem)

2022-06-10 Thread Gerben Wierda 

> On 10 Jun 2022, at 13:17, Wietse Venema  wrote:
> 
> Wietse Venema:
>> Gerben Wierda:
>>> 
 On 10 Jun 2022, at 02:30, Wietse Venema  wrote:
 
 Gerben Wierda:
> What is happening here? (mail is delivered, I?m just curious)
> 
> Jun 09 23:37:39 mail postfix/postscreen[4294]: CONNECT from 
> [146.185.52.133]:10400 to [192.168.2.66]:25
> Jun 09 23:37:45 mail postfix/postscreen[4294]: PASS NEW 
> [146.185.52.133]:10400
> Jun 09 23:37:45 mail smtp/smtpd[4296]: connect from 
> ims-smtp133.persgroep-ops.net[146.185.52.133]
> Jun 09 23:37:46 mail smtp/smtpd[4296]: CC868E75AA1E: 
> client=ims-smtp133.persgroep-ops.net[146.185.52.133]
> Jun 09 23:37:47 mail postfix/cleanup[4300]: CC868E75AA1E: 
> message-id=<220609233739.sim_40lt1wa1poje3tjw6hnmtvk29xxj_ghn7vvejgut3cs3hljfekzafd9hipabzz8ro0vetlr2qj0j2ddp9oie2u%2bfuro...@ims-smtp133.persgroep-ops.net>
> Jun 09 23:37:48 mail postfix/qmgr[8801]: CC868E75AA1E: 
> from=, size=34628, nrcpt=1 (queue active)
> Jun 09 23:37:48 mail smtp/smtpd[4296]: warning: TLS library problem: 
> error:0A000126:SSL routines::unexpected eof while 
> reading:ssl/record/rec_layer_s3.c:309:
> Jun 09 23:37:48 mail smtp/smtpd[4296]: disconnect from 
> ims-smtp133.persgroep-ops.net[146.185.52.133] ehlo=2 starttls=1 mail=1 
> rcpt=1 data=1 commands=6
> 
 
 Did you look for 0A000126 with a web search engine?
>>> 
>>> Yes. Searched on the entire error string as well.
>>> 
>>> But that did not give me a clue.
>> 
>> I got: OpenSSL 3 is more strict about clients that disconnect without
>> fully following the protocol.
> 
> Specifically, google 0A000126, the first result is PHP issue 8369a

Indeed. Interesting. I use duckduckgo (which relies on Bing afaik) and it 
doesn’t find that.

> which links to https://github.com/openssl/openssl/issues/11378 
> . The
> latter had a breaking fix, backed it out for OpenSSL 1.1.1, but
> kept it in the branch that become OpenSSL 3.

So basically, the sender doesn’t properly close the SSL protocol, their MTA is 
using an SSL which isn’t properly implemented.

G

Re: What is happening here? (TLS Library Problem)

2022-06-10 Thread Wietse Venema 
Wietse Venema:
> Gerben Wierda:
> > 
> > > On 10 Jun 2022, at 02:30, Wietse Venema  wrote:
> > > 
> > > Gerben Wierda:
> > >> What is happening here? (mail is delivered, I?m just curious)
> > >> 
> > >> Jun 09 23:37:39 mail postfix/postscreen[4294]: CONNECT from 
> > >> [146.185.52.133]:10400 to [192.168.2.66]:25
> > >> Jun 09 23:37:45 mail postfix/postscreen[4294]: PASS NEW 
> > >> [146.185.52.133]:10400
> > >> Jun 09 23:37:45 mail smtp/smtpd[4296]: connect from 
> > >> ims-smtp133.persgroep-ops.net[146.185.52.133]
> > >> Jun 09 23:37:46 mail smtp/smtpd[4296]: CC868E75AA1E: 
> > >> client=ims-smtp133.persgroep-ops.net[146.185.52.133]
> > >> Jun 09 23:37:47 mail postfix/cleanup[4300]: CC868E75AA1E: 
> > >> message-id=<220609233739.sim_40lt1wa1poje3tjw6hnmtvk29xxj_ghn7vvejgut3cs3hljfekzafd9hipabzz8ro0vetlr2qj0j2ddp9oie2u%2bfuro...@ims-smtp133.persgroep-ops.net>
> > >> Jun 09 23:37:48 mail postfix/qmgr[8801]: CC868E75AA1E: 
> > >> from=, size=34628, nrcpt=1 (queue active)
> > >> Jun 09 23:37:48 mail smtp/smtpd[4296]: warning: TLS library problem: 
> > >> error:0A000126:SSL routines::unexpected eof while 
> > >> reading:ssl/record/rec_layer_s3.c:309:
> > >> Jun 09 23:37:48 mail smtp/smtpd[4296]: disconnect from 
> > >> ims-smtp133.persgroep-ops.net[146.185.52.133] ehlo=2 starttls=1 mail=1 
> > >> rcpt=1 data=1 commands=6
> > >> 
> > > 
> > > Did you look for 0A000126 with a web search engine?
> > 
> > Yes. Searched on the entire error string as well.
> > 
> > But that did not give me a clue.
> 
> I got: OpenSSL 3 is more strict about clients that disconnect without
> fully following the protocol.

Specifically, google 0A000126, the first result is PHP issue 8369a
which links to https://github.com/openssl/openssl/issues/11378. The
latter had a breaking fix, backed it out for OpenSSL 1.1.1, but
kept it in the branch that become OpenSSL 3.

Wietse

Re: What is happening here? (TLS Library Problem)

2022-06-10 Thread Wietse Venema 
Gerben Wierda:
> 
> > On 10 Jun 2022, at 02:30, Wietse Venema  wrote:
> > 
> > Gerben Wierda:
> >> What is happening here? (mail is delivered, I?m just curious)
> >> 
> >> Jun 09 23:37:39 mail postfix/postscreen[4294]: CONNECT from 
> >> [146.185.52.133]:10400 to [192.168.2.66]:25
> >> Jun 09 23:37:45 mail postfix/postscreen[4294]: PASS NEW 
> >> [146.185.52.133]:10400
> >> Jun 09 23:37:45 mail smtp/smtpd[4296]: connect from 
> >> ims-smtp133.persgroep-ops.net[146.185.52.133]
> >> Jun 09 23:37:46 mail smtp/smtpd[4296]: CC868E75AA1E: 
> >> client=ims-smtp133.persgroep-ops.net[146.185.52.133]
> >> Jun 09 23:37:47 mail postfix/cleanup[4300]: CC868E75AA1E: 
> >> message-id=<220609233739.sim_40lt1wa1poje3tjw6hnmtvk29xxj_ghn7vvejgut3cs3hljfekzafd9hipabzz8ro0vetlr2qj0j2ddp9oie2u%2bfuro...@ims-smtp133.persgroep-ops.net>
> >> Jun 09 23:37:48 mail postfix/qmgr[8801]: CC868E75AA1E: 
> >> from=, size=34628, nrcpt=1 (queue active)
> >> Jun 09 23:37:48 mail smtp/smtpd[4296]: warning: TLS library problem: 
> >> error:0A000126:SSL routines::unexpected eof while 
> >> reading:ssl/record/rec_layer_s3.c:309:
> >> Jun 09 23:37:48 mail smtp/smtpd[4296]: disconnect from 
> >> ims-smtp133.persgroep-ops.net[146.185.52.133] ehlo=2 starttls=1 mail=1 
> >> rcpt=1 data=1 commands=6
> >> 
> > 
> > Did you look for 0A000126 with a web search engine?
> 
> Yes. Searched on the entire error string as well.
> 
> But that did not give me a clue.

I got: OpenSSL 3 is more strict about clients that disconnect without
fully following the protocol.

Wietse

Re: Local relay delivery delays on particular mails

2022-06-10 Thread Nikolaos Milas 

On 8/6/2022 11:55 p.m., Viktor Dukhovni wrote:

The milter may be performing DKIM signature checks on inbound mail,
signing would be only for outbound.  DKIM signature checks may involve
DNS lookups, which could introduce some latency if the remote zone is
uncooperative.

On 9/6/2022 2:41 a.m., Wietse Venema wrote:

I agree that DKIM is unlikely to use upo 255 seconds even if
you had turned on signature checks by mistake.


Based on your comments (and based on our current postfix config, which 
is simple) I focused on checking the OpenDKIM config, as a serious 
candidate of being responsible for the delays.


I noticed that our incoming mails had DKIM verification signatures from 
both servers (mailgw1 AND vmail2) which was not right. There is no point 
in verifying DKIM signature twice.


So, yes, I had mistakenly turned on signature checking on vmail2.

Additionally, the usual delay was around 4 minutes, which is consistent 
with the 255 seconds timeout you mentioned.


I turned off signature checking on vmail2 and *delays stopped occurring*!

It seems that something in DKIM signature verification process was 
causing OpenDKIM to stall when analyzing particular domains.


(Note that DKIM signature checking on mailgw1 through amavis does not 
cause any issues whatsoever.)


OpenDKIM logs did not reveal any details regarding the messages with 
earlier delays; only the final successful signing event was logged.


I did not try to re-enable (unneeded) signature verification and 
increasing OpenDKIM log level in an effort to discover more details on 
the issue; therefore I can't tell what exactly may have been the cause 
of failures on particular domains. Since it is a production server, it 
is not easy to make a decision to re-introduce mail delivery delays to 
end-users in order to do further experiments.


Yet, it is clear that the delay was induced by OpenDKIM sig verification 
process.


I do appreciate and thank you both Wietse and Victor for the precious 
insight you have provided on postfix message processing at various 
stages and your commendable kindness in devoting your effort to help me, 
even though I am not a mail expert! I would have surely needed your 
further guidance to configure postfix in a way that would allow me to 
carry out the step-by-step analysis you advised if it had proved necessary.


All the best,
Nick

Re: What is happening here? (TLS Library Problem)

2022-06-10 Thread Gerben Wierda 


> On 10 Jun 2022, at 02:30, Wietse Venema  wrote:
> 
> Gerben Wierda:
>> What is happening here? (mail is delivered, I?m just curious)
>> 
>> Jun 09 23:37:39 mail postfix/postscreen[4294]: CONNECT from 
>> [146.185.52.133]:10400 to [192.168.2.66]:25
>> Jun 09 23:37:45 mail postfix/postscreen[4294]: PASS NEW 
>> [146.185.52.133]:10400
>> Jun 09 23:37:45 mail smtp/smtpd[4296]: connect from 
>> ims-smtp133.persgroep-ops.net[146.185.52.133]
>> Jun 09 23:37:46 mail smtp/smtpd[4296]: CC868E75AA1E: 
>> client=ims-smtp133.persgroep-ops.net[146.185.52.133]
>> Jun 09 23:37:47 mail postfix/cleanup[4300]: CC868E75AA1E: 
>> message-id=<220609233739.sim_40lt1wa1poje3tjw6hnmtvk29xxj_ghn7vvejgut3cs3hljfekzafd9hipabzz8ro0vetlr2qj0j2ddp9oie2u%2bfuro...@ims-smtp133.persgroep-ops.net>
>> Jun 09 23:37:48 mail postfix/qmgr[8801]: CC868E75AA1E: 
>> from=, size=34628, nrcpt=1 (queue active)
>> Jun 09 23:37:48 mail smtp/smtpd[4296]: warning: TLS library problem: 
>> error:0A000126:SSL routines::unexpected eof while 
>> reading:ssl/record/rec_layer_s3.c:309:
>> Jun 09 23:37:48 mail smtp/smtpd[4296]: disconnect from 
>> ims-smtp133.persgroep-ops.net[146.185.52.133] ehlo=2 starttls=1 mail=1 
>> rcpt=1 data=1 commands=6
>> 
> 
> Did you look for 0A000126 with a web search engine?

Yes. Searched on the entire error string as well.

But that did not give me a clue.

G