On 2/9/22 1:25 PM, Graham Leggett wrote:
> On 08 Feb 2022, at 19:01, Yann Ylavic <ylavic....@gmail.com
> <mailto:ylavic....@gmail.com>> wrote:
>
>>> The most concurrent requests I can get out of MacOS appears to be roughly
>>> 2000 concurrent requests before “connection reset by
>>> peer” kills the test.
>>>
>>> One small detail I have uncovered is that a small percentage of requests
>>> fail, caused by httpd gracefully shutting the
>>> connection down before returning a response. Stopping ab in a debugger
>>> confirms that openssl returns SSL_ERROR_ZERO_RETURN on
>>> read, which is what openssl does when the other side gracefully triggers
>>> close notify.
>>>
>>> Is this something anyone has seen before while I go digging?
>>
>> I tried with ab too and indeed there was some (dead-)locking issue at
>> some point, could you please retry with the latest pushes I just made
>> to the PR?
>
> I tried with the latest patch, then I tried with no patch (vanilla trunk) and
> got the same results.
>
> Working backwards looking for graceful attempts to shut down the SSL
> connection, I found this:
>
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [info] [pid 8747]
> mod_ssl.c(681): [client ::1:56237] AH01964: Connection to child
> 29 established (server localhost:443)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> ssl_engine_kernel.c(2402): [client ::1:56237] AH02043: SSL
> virtual host for servername localhost found
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> ssl_engine_kernel.c(2262): [client ::1:56237] AH02041: Protocol:
> TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> ssl_engine_kernel.c(415): [client ::1:56237] AH02034: Initial
> (No.1) HTTPS request received for child 29 (server localhost:443)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> mod_authz_core.c(843): [client ::1:56237] AH01628: authorization
> result: granted (no directives)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> ssl_engine_kernel.c(415): [client ::1:56237] AH02034: Subsequent
> (No.2) HTTPS request received for child 27 (server localhost:443)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> mod_authz_core.c(843): [client ::1:56237] AH01628: authorization
> result: granted (no directives)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> ssl_engine_kernel.c(415): [client ::1:56237] AH02034: Subsequent
> (No.3) HTTPS request received for child 37 (server localhost:443)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> mod_authz_core.c(843): [client ::1:56237] AH01628: authorization
> result: granted (no directives)
> ::1:56237 ::1:56237 [Wed Feb 09 09:52:21 2022] [debug] [pid 8747]
> ssl_engine_io.c(1184): [client ::1:56237] AH02001: Connection
> closed to child 29 with standard shutdown (server localhost:443)
>
> It seems reasonably normal, except what looks like is happening is when
> "Connection closed to child 29 with standard shutdown” is
> run, this seems to happen before a response is sent to the client.
>
> ab then goes “that’s weird, I was trying to read a response, but got a
> connection closed instead”, and marks that request as failed.
>
> This is limited to keepalive requests, and happens after a number of
> keepalive requests have been correctly handled.
Probably you get hit by this?
https://github.com/apache/httpd/blob/46a9db4c6f9fadca4e362872021fa62a37908ece/server/mpm/event/event.c#L2096-L2101
If a client sends a request on a keepalive connection it should be prepared
that the connection gets closed without a reply and it
should retry if the request is idempotent. This is how I read RFC7230 6.3.1:
https://datatracker.ietf.org/doc/html/rfc7230#section-6.3.1
Regards
Rüdiger
