Out of the blue it seems, I suddenly have multiple clients experiencing
issues sending mail. In all of the cases, the users with issues share
the common traits:
- When using an older device - Blackberry, older iPhone, older email
client (Eudora, etc) it is far more prevalent
- Sending larger emails, especially with attachments - although this is
not always the case. It sometimes happens almost immediately upon connection
- Utilizing SSL - a couple are still utilizing SSLV3, but most are at
least TLS1.0, some with older ciphers
I have experienced it myself, using a modern client (Thunderbird) and
TLS1.2 and a modern cipher, when attempting to send an email with an
attachment.
Whenever they experience the problem, I log:
ssl-read - renegotiation in progress - SSL_WANT_READ
ssl-read renegotiation finished - recovered from - SSL_WANT_READ
This will happen several times in a row within a second or two, after
which ASSP shuts them down and blacklists their IP for 15-30 minutes for
attempted DDOS. Understandably, this is making my clients furious. I
can't tell them to join the 20th century and get a new device/client, so
I have to figure out why this has suddenly started happening on the
server, and how to fix it.
I am running the latest dev release of ASSP, on 64 bit Strawberry Perl,
Windows Server 2012 R2, with all the latest Perl modules.
I tried setting SSLDebug to level 3, but no information other than what
is already being written to the log was produced.
Any ideas as to what I should be looking for, I'm very open to suggestions.
Here's an example of my own mail client attempting to send a 1MB attachment:
Nov-16-17 15:48:37 [Worker_2] [clientIP] IP [clientIP] matches
acceptAllMail - with [clientIP]/32
Nov-16-17 15:48:37 [Worker_2] Connected: session:2AB3ACC8
[clientIP]:54186 > [asspIP]:587 > [mailserverIP]:49674 >
[mailserverIP]:587 , 91-106
Nov-16-17 15:48:38 [Worker_2] [clientIP] info: send '250-STARTTLS' -
injected for [mailserverIP]
Nov-16-17 15:48:38 [Worker_2] [clientIP] info: got STARTTLS request from
[clientIP]
Nov-16-17 15:48:38 [Worker_2] [clientIP] info: STARTTLS is skipped for
[mailserverIP] - sent 'NOOP' to [mailserverIP]
Nov-16-17 15:48:38 [Worker_2] [TLS-in] [clientIP] info: started TLS-SSL
session for client [clientIP] - using TLSv1_2 , ECDHE-RSA-AES128-GCM-SHA256
Nov-16-17 15:48:38 [Worker_2] [TLS-in] [clientIP] info: authentication -
plain is used
Nov-16-17 15:48:38 [Worker_2] [TLS-in] [clientIP] authenticated to
[mailserverIP]
Nov-16-17 15:48:38 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> info: found message size announcement: 1.36 MByte
Nov-16-17 15:48:38 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> message proxied without processing - message size
(1430959) is above 500000 (npSizeOut).
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com recipient accepted:
recipi...@email.com
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com IP [clientIP] matches
whiteListedIPs - with [clientIP]/32
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: allocated 1.94 MByte
memory to process this mail
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [NoProcessing]
[clientIP] <sen...@email.com> to: recipi...@email.com message proxied
without processing (except checks enabled for noprocessing mails)
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: ssl-read -
renegotiation in progress - SSL_WANT_READ
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: ssl-read renegotiation
finished - recovered from - SSL_WANT_READ
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: SMIME/PGP message found
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com Message-ID found:
aaf66ed0-2c91-fe46-4b3e-4c00ba6c5...@hollsco.com
Nov-16-17 15:48:39 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: 1 attachment found for
Level-0
Nov-16-17 15:48:40 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: ssl-read -
renegotiation in progress - SSL_WANT_READ
Nov-16-17 15:48:40 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: ssl-read renegotiation
finished - recovered from - SSL_WANT_READ
Nov-16-17 15:48:40 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: ssl-read -
renegotiation in progress - SSL_WANT_READ
Nov-16-17 15:48:41 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: ssl-read renegotiation
finished - recovered from - SSL_WANT_READ
Nov-16-17 15:48:41 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: ssl-read -
renegotiation in progress - SSL_WANT_READ
Nov-16-17 15:48:41 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com info: SSL DoS using
consecutive renegotiations detected - connection exceeded
maxSSLRenegotiations(2) - close connection and ban IP for 15-30 minutes
(EmergencyBlock) - last command was 'DATA'
Nov-16-17 15:48:41 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com finished message - received
DATA size: 104.16 kByte - sent DATA size: 0 Byte
Nov-16-17 15:48:41 NB-65318-11410 [Worker_2] [TLS-in] [clientIP]
<sen...@email.com> to: recipi...@email.com disconnected:
session:2AB3ACC8 [clientIP] - command list was
'EHLO,STARTTLS,EHLO,AUTH,MAIL FROM,RCPT TO,DATA' - used 63 SocketCalls -
processing time 4 seconds
Nov-16-17 15:48:58 [Worker_2] [clientIP]:54209 denied by internal
EMERGENCY Blocker - this IP has possibly tried before to KILL assp
Nov-16-17 15:48:58 [Worker_2] [clientIP]:54209 ATTENTION ! The EMERGENCY
blocking for this IP will be lifted after an ASSP restart or at least in
15 minutes
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Assp-test mailing list
Assp-test@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/assp-test
