Bug 65731 - Empty response body after MaxRequestsPerChild reached for HTTP/2.0
Summary: Empty response body after MaxRequestsPerChild reached for HTTP/2.0
Status: RESOLVED FIXED
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_http2 (show other bugs)
Version: 2.4.41
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-12-08 17:38 UTC by Antonios Tsianakas
Modified: 2022-01-03 18:04 UTC (History)
2 users (show)



Attachments
Apache Trace8 Log (75.01 KB, text/plain)
2021-12-09 12:00 UTC, Antonios Tsianakas
Details
patch on 2.4.x code base (2.98 KB, patch)
2021-12-09 14:17 UTC, Stefan Eissing
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Antonios Tsianakas 2021-12-08 17:38:46 UTC
When requesting a simple image file with HTTP2 every time MaxRequestsPerChild is reached, an empty response is sent to the client. This is even reproducible.

Server Version: Apache/2.4.41 (Ubuntu) OpenSSL/1.1.1f
Server MPM: event
OS: Ubuntu 20.04

Server Version: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1
Server MPM: worker
OS: Ubuntu 18.04

Same issue exists with mpm_event and mpm_worker.

My configuration:

<IfModule mpm_event_module>
    StartServers 8
    MinSpareThreads 4
    MaxSpareThreads 12
    ThreadLimit 64
    ThreadsPerChild 16
    MaxRequestsPerChild 100
    ServerLimit 64
    MaxClients 64
</IfModule>

mod_http2 no custom configuration in use.

Test command:
for i in {1..2000}; do if [[ $(curl -o /dev/null -s -k --http2 https://example.net/2101583.jpg?test=$i -w '%{size_download}') == 0 ]]; then break; fi; done

Access log output:
8.8.8.8 - - [08/Dec/2021:18:20:32 +0100] "GET /2101583.jpg?fakeVar=33 HTTP/2.0" 200 17115 "-" "curl/7.68.0"
8.8.8.8 - - [08/Dec/2021:18:20:33 +0100] "GET /2101583.jpg?fakeVar=34 HTTP/2.0" 200 17115 "-" "curl/7.68.0"
8.8.8.8 - - [08/Dec/2021:18:20:33 +0100] "GET /2101583.jpg?fakeVar=35 HTTP/2.0" 200 0 "-" "curl/7.68.0"
8.8.8.8 - - [08/Dec/2021:18:20:33 +0100] "GET /2101583.jpg?fakeVar=36 HTTP/2.0" 200 17115 "-" "curl/7.68.0"
8.8.8.8 - - [08/Dec/2021:18:20:33 +0100] "GET /2101583.jpg?fakeVar=37 HTTP/2.0" 200 17115 "-" "curl/7.68.0"
8.8.8.8 - - [08/Dec/2021:18:20:33 +0100] "GET /2101583.jpg?fakeVar=38 HTTP/2.0" 200 17115 "-" "curl/7.68.0"
8.8.8.8 - - [08/Dec/2021:18:20:33 +0100] "GET /2101583.jpg?fakeVar=39 HTTP/2.0" 200 17115 "-" "curl/7.68.0"
...
8.8.8.8 - - [08/Dec/2021:18:20:37 +0100] "GET /2101583.jpg?fakeVar=135 HTTP/2.0" 200 0 "-" "curl/7.68.0"
...
8.8.8.8 - - [08/Dec/2021:18:20:42 +0100] "GET /2101583.jpg?fakeVar=235 HTTP/2.0" 200 0 "-" "curl/7.68.0"
...
8.8.8.8 - - [08/Dec/2021:18:20:47 +0100] "GET /2101583.jpg?fakeVar=335 HTTP/2.0" 200 0 "-" "curl/7.68.0"
Comment 1 Ruediger Pluem 2021-12-09 08:24:11 UTC
Does this happen as well with 2.4.51 compiled from source?
Comment 2 Antonios Tsianakas 2021-12-09 12:00:50 UTC
Created attachment 38125 [details]
Apache Trace8 Log
Comment 3 Antonios Tsianakas 2021-12-09 12:01:45 UTC
Yes, and with 2.4.51 the responses with an empty body wasn't logged in the access log.

When this happens curl reports "curl: (16) Error in the HTTP2 framing layer". Attached is the trace8 output of such a request.

Server version: Apache/2.4.51 (Unix)
Server built:   Dec  9 2021 12:24:50
Server's Module Magic Number: 20120211:118
Server loaded:  APR 1.6.5, APR-UTIL 1.6.1
Compiled using: APR 1.6.5, APR-UTIL 1.6.1
Architecture:   64-bit
Server MPM:     event
  threaded:     yes (fixed thread count)
    forked:     yes (variable process count)
Comment 4 Stefan Eissing 2021-12-09 12:27:30 UTC
Thanks for the log. I can see that mod_http2 sees the MPM stopping and sends a GOAWAY frame *before* the HTTP/2 session has been fully started. That is indeed a violation of the H2 protocol.

Working on a test and patch.
Comment 5 Stefan Eissing 2021-12-09 14:17:04 UTC
Created attachment 38127 [details]
patch on 2.4.x code base

Proposed fix for 2.4.x code base.
Comment 6 Stefan Eissing 2021-12-09 14:19:22 UTC
I was able to reproduce this in a test case and made a fix to be backported to 2.4.x in the next release.

I attached the patch for the 2.4.x codebase, if you can build from source. If you want to build from the github module version, there is <https://github.com/icing/mod_h2/releases/tag/v1.15.27>.
Comment 7 Graham Leggett 2021-12-13 10:37:02 UTC
Backported to v2.4.52:

 *) mod_http2: fixes PR65731 and https://github.com/icing/mod_h2/issues/212
    trunk patch: na, fixed on 2.4.x source base
    backport PR: https://github.com/apache/httpd/pull/281
    +1: icing, minfrin, ylavic