Intermittently the TLS handshake results in plaintext 400 Bad Request response

Rob Emery <apache-list@xxxxxxxxxxxxxxx> · Thu, 29 Apr 2021 13:25:47 +0100

Hello,

We have a problem where intermittently users are getting a plaintext
400 Bad Request response in the middle of the TLS handshake (always
the 6th packet in the TCP stream); it happens about 1 in 40K requests
at current. As far as we can tell, there is no difference between a
successful connection from a client and these failures (we have
confirmed that all the options in the handshake are identical apart
from the session/random level components).

We have traffic captures of the problem occurring (see attached
screenshot with the end-user’s IP redacted) and it happens fairly
frequently for us in our production environment (about 10 per hour or
similar).

We've examined the user agents etc that those requests usually come
from and see a mixture of different types of clients (PHP + Curl,
Firefox, Chrome, Safari, Java, Python) and Operating Systems (iOS,
Linux, Windows 10, Android) etc, so there doesn't appear to be any
commonality between the clients.

There’s a firewall performing NAT between the client and the httpd
instance and the error is definitely coming from httpd as the traffic
captures were taken on the physical interface that httpd is listening
on. It is happening on multiple (> 5) servers that share nothing so we
don’t think it could be a physical issue.

They’re apache2 2.4.25-3+deb9u7 on Debian 9. This is 2 minor patches
behind the latest however we have reviewed the patches and there
doesn’t seem to be any way those changes could affect this behaviour.
We have also read through the changelog for Apache2, the only possible
related change that we can see is in 2.4.38:

 *) mod_ssl: Fix the error code returned in an error path of
     'ssl_io_filter_handshake()'. This messes-up error handling performed
     in 'ssl_io_filter_error()' [Yann Ylavic]

However that change only resolves a situation where httpd returns a
502 when it should return a 400, so we don’t think that’s related. We
spent a good portion of yesterday reviewing the mod_ssl code, however
we weren't able to identify a situation where this would happen.

We have logging at “warn” everywhere, however these requests don’t
show in either the access or error log when we check for them.

We are currently trying to get this reproduced in a lab environment so
we can increase the log levels etc however any guidance as to where to
focus our efforts would be much appreciated.

Thanks
Rob

Other relevant information we can think of:

apache2 2.4.25-3+deb9u7
Linux 4.9.0-9-amd64 #1 SMP Debian 4.9.168-1 (2019-04-12) x86_64 GNU/Linux
openssl 1.1.0j-1~deb9u1

We’re using: mod_ssl and mpm_worker with:

    StartServers            2
    MinSpareThreads        25
    MaxSpareThreads        75
    ThreadLimit            64
    ThreadsPerChild        25
    MaxRequestWorkers        150
    MaxConnectionsPerChild    0

Other modules we have enabled are:

access_compat.load
alias.load
auth_basic.load
authn_core.load
authn_file.load
authz_core.load
authz_host.load
authz_user.load
deflate.load
dir.load
env.load
filter.load
headers.load
lbmethod_byrequests.load
mime.load
negotiation.load
proxy_balancer.load
proxy_html.load
proxy_http.load
proxy.load
rewrite.load
setenvif.load
slotmem_shm.load
socache_shmcb.load
status.load
Xml2enc.load

Example of the site (edited for brevity):

<VirtualHost 10.1.17.209:443>
    ServerName example.com

    ErrorLog ${APACHE_LOG_DIR}/example.com.error.log
    LogLevel warn