On 08 Feb 2022, at 19:01, Yann Ylavic <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. Regards, Graham —
