diff --git a/modules/http2/h2_c2.c b/modules/http2/h2_c2.c index 79f76c0a70f..0c8bad93096 100644 --- a/modules/http2/h2_c2.c +++ b/modules/http2/h2_c2.c @@ -397,6 +397,13 @@ static apr_status_t h2_c2_filter_out(ap_filter_t* f, apr_bucket_brigade* bb) ap_bucket_response *resp = e->data; if (resp->status >= HTTP_OK) { conn_ctx->has_final_response = 1; + if (AP_STATUS_IS_HEADER_ONLY(resp->status)) { + /* A header-only response (204/304) is complete without + * a body EOS; mark it complete so c2_process() does not + * abort/reset it as an "incomplete" response (which + * would re-open PR 69580). */ + conn_ctx->response_eos_seen = 1; + } break; } } @@ -406,6 +413,19 @@ static apr_status_t h2_c2_filter_out(ap_filter_t* f, apr_bucket_brigade* bb) } } #endif /* AP_HAS_RESPONSE_BUCKETS */ + /* Note when the response body completes (an EOS passes out). A c2 that + * finishes WITHOUT having seen an EOS (e.g. the CGI/handler timed out + * mid-body) produced an incomplete response and must reset the stream. */ + if (!conn_ctx->response_eos_seen) { + apr_bucket *e; + for (e = APR_BRIGADE_FIRST(bb); e != APR_BRIGADE_SENTINEL(bb); + e = APR_BUCKET_NEXT(e)) { + if (APR_BUCKET_IS_EOS(e)) { + conn_ctx->response_eos_seen = 1; + break; + } + } + } rv = beam_out(f->c, conn_ctx, bb); ap_log_cerror(APLOG_MARK, APLOG_TRACE2, rv, f->c, @@ -804,7 +824,20 @@ static apr_status_t c2_process(h2_conn_ctx_t *conn_ctx, conn_rec *c) * request pool may have been deleted. */ r = NULL; if (conn_ctx->beam_out) { - h2_beam_close(conn_ctx->beam_out, c); + if (conn_ctx->has_final_response && !conn_ctx->response_eos_seen) { + /* A final response was started but never completed (no EOS), e.g. + * the CGI/handler timed out mid-body. Abort the output beam so the + * HTTP/2 stream is RST_STREAM'd. Otherwise s_c2_done() sees the closed + * beam as a complete response, sends no reset, and the client is left + * waiting for data/EOS that never arrive. Header-only responses + * (204/304/HEAD) are marked complete earlier (see the + * AP_STATUS_IS_HEADER_ONLY handling) so they are NOT aborted here; + * aborting them would re-open PR 69580. */ + h2_beam_abort(conn_ctx->beam_out, c); + } + else { + h2_beam_close(conn_ctx->beam_out, c); + } } ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, c, diff --git a/modules/http2/h2_c2_filter.c b/modules/http2/h2_c2_filter.c index 17a2c131d8c..40bb79171f2 100644 --- a/modules/http2/h2_c2_filter.c +++ b/modules/http2/h2_c2_filter.c @@ -549,6 +549,12 @@ static apr_status_t pass_response(h2_conn_ctx_t *conn_ctx, ap_filter_t *f, if (response->status >= HTTP_OK) { conn_ctx->has_final_response = 1; + if (AP_STATUS_IS_HEADER_ONLY(response->status)) { + /* A header-only response (204/304) is complete without a body + * EOS; mark it complete so c2_process() does not abort/reset it as + * an "incomplete" response (which would re-open PR 69580). */ + conn_ctx->response_eos_seen = 1; + } } ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, parser->c, APLOGNO(03197) "h2_c2(%s): passed response %d", @@ -757,6 +763,10 @@ apr_status_t h2_c2_filter_response_out(ap_filter_t *f, apr_bucket_brigade *bb) } if (r->header_only || AP_STATUS_IS_HEADER_ONLY(r->status)) { + /* A header-only response (HEAD, or 204/304) is complete without a body + * EOS; mark it complete so c2_process() does not abort/reset it as an + * "incomplete" response (which would re-open PR 69580). */ + conn_ctx->response_eos_seen = 1; ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, f->c, "h2_c2(%s): headers only, cleanup output brigade", conn_ctx->id); b = body_bucket? body_bucket : APR_BRIGADE_FIRST(bb); diff --git a/modules/http2/h2_conn_ctx.h b/modules/http2/h2_conn_ctx.h index 3b44856f95a..96228245b5d 100644 --- a/modules/http2/h2_conn_ctx.h +++ b/modules/http2/h2_conn_ctx.h @@ -60,6 +60,7 @@ struct h2_conn_ctx_t { apr_pollfd_t pfd; /* c1: poll socket input, c2: NUL */ int has_final_response; /* final HTTP response passed on out */ + int response_eos_seen; /* c2: response body completed (EOS seen on out) */ apr_status_t last_err; /* APR_SUCCES or last error encountered in filters */ apr_off_t bytes_sent; /* c2: bytes acutaly sent via c1 */ diff --git a/modules/http2/h2_mplx.c b/modules/http2/h2_mplx.c index c50e15ccd5d..2463e869c62 100644 --- a/modules/http2/h2_mplx.c +++ b/modules/http2/h2_mplx.c @@ -1005,7 +1005,14 @@ static void s_c2_done(h2_mplx *m, conn_rec *c2, h2_conn_ctx_t *conn_ctx) if (conn_ctx->beam_out) h2_beam_abort(conn_ctx->beam_out, c2); } - else if (!conn_ctx->beam_out || !h2_beam_is_complete(conn_ctx->beam_out)) { + else if (!conn_ctx->beam_out + || (!h2_beam_is_complete(conn_ctx->beam_out) + && !conn_ctx->response_eos_seen)) { + /* h2_beam_is_complete() cannot tell a header-only response (204/304, + * legitimately no body EOS) from a truncated one. response_eos_seen is + * set when an EOS passed out OR the response was header-only, so spare + * those here; only abort genuinely incomplete output. Without this, a + * body-less mod_cache 304 revalidation gets RST_STREAM'd. */ ap_log_cerror(APLOG_MARK, APLOG_TRACE1, conn_ctx->last_err, c2, "h2_c2(%s-%d): processing finished with incomplete output", conn_ctx->id, conn_ctx->stream_id); diff --git a/test/modules/http2/htdocs/cgi/h2cgi_slow.py b/test/modules/http2/htdocs/cgi/h2cgi_slow.py new file mode 100755 index 00000000000..e48588c7f50 --- /dev/null +++ b/test/modules/http2/htdocs/cgi/h2cgi_slow.py @@ -0,0 +1,13 @@ +#!/usr/bin/env python3 +# Start a response (status + headers + a little body), then go silent for +# longer than the server's `Timeout`. Over HTTP/2 this makes Apache's content +# filter time out reading from the CGI (AH01220): the response was started but +# never completed (no EOS). A correct server RST_STREAMs the stream; a buggy +# one leaves the client hanging. Used by test_105_timeout.py. +import sys +import time + +sys.stdout.write("Content-Type: application/octet-stream\r\n\r\n") +sys.stdout.write("X" * 16384) +sys.stdout.flush() +time.sleep(30) diff --git a/test/modules/http2/test_105_timeout.py b/test/modules/http2/test_105_timeout.py index 22160b45853..0bfeced4dc9 100644 --- a/test/modules/http2/test_105_timeout.py +++ b/test/modules/http2/test_105_timeout.py @@ -1,5 +1,6 @@ import socket import time +from datetime import timedelta import pytest @@ -164,3 +165,84 @@ def test_h2_105_12(self, env): piper.close() assert piper.response, f'{piper}' assert piper.response['status'] == 408, f"{piper.response}" + + # A CGI that starts a response (status + headers + some body) and then goes + # silent past `Timeout` must lead to the HTTP/2 stream being RST_STREAM'd, + # not leave the client hanging. Regression test for the mod_http2 hang where + # a c2 that finished an *incomplete* response (no EOS, e.g. CGI timed out + # mid-body) was treated as complete and no reset was ever sent. + def test_h2_105_20(self, env): + conf = H2Conf(env) + conf.add("Timeout 1") + conf.add("PassEnv PATH") # let the CGI find its interpreter + conf.add_vhost_cgi() + conf.install() + assert env.apache_restart() == 0 + url = env.mkurl("https", "cgi", "/h2cgi_slow.py") + # Open many streams at once on ONE h2 connection. A correct server + # RST_STREAMs every silent CGI, so the whole batch finishes in ~Timeout. + # A buggy server fails to reset at least one of them (the missed reset is + # racy per-stream, but with many streams in flight it is reliably hit), + # so curl --parallel waits until its --max-time. Key on elapsed time, not + # exit code: --parallel makes the exit code ambiguous, and a hang here is + # a multi-second stall versus a sub-second clean teardown. --max-time + # also bounds the client so a hang cannot wedge the test. + # + # Why 10 streams: a single silent stream hangs only racily (about 80%), + # and the racy/deterministic knee is sharp. A sweep on a fast idle box + # measured 80% hang at 1 to 2 streams but 100% at 3 or more (1 and 2 are + # equally racy because the streams are correlated under one session + # connection, so it is a threshold, not an independent-probability + # curve). The knee rises on faster or less-loaded machines (the server + # wins the per-stream reset race more often), so 10 keeps a wide margin + # for CI hardware variance. The streams are concurrent, so the larger + # count costs no wall-clock, and 10 is well under the default 100 max + # concurrent streams. + count = 10 + max_time = 10 + r = env.curl_raw([url] * count, options=[ + "--parallel", "--parallel-immediate", "--max-time", str(max_time)]) + assert r.duration < timedelta(seconds=max_time - 2), \ + f'streams hung waiting for RST_STREAM (batch took {r.duration}): {r}' + # Resetting each silent CGI is logged as a CGI timeout (cgid) and the + # failed body read that follows it (core); both are expected here. + time.sleep(1) # let the log flush + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01220", # cgid: Timeout waiting for output from CGI script + "AH00574", # core: ap_content_length_filter, apr_bucket_read() failed + ] + ) + + # Complement to test_h2_105_20: a body-less response that is missing an EOS + # must NOT be reset over HTTP/2. mod_cache revalidation of a cached, + # immediately-stale resource emits exactly such a 304 (EOR + Flush, no EOS). + # This guards the incomplete-response reset against re-opening PR 69580: + # only a response that began a body and is missing EOS should be + # reset, never a header-only one. + def test_h2_105_21(self, env): + cacheroot = f"{env.server_dir}/cacheroot" + env.mkpath(cacheroot) + conf = H2Conf(env) + conf.add(f""" + CacheRoot "{cacheroot}" + CacheEnable disk / + Header set Cache-Control "public, max-age=0" + """) + conf.add_vhost_test1() + conf.install() + assert env.apache_restart() == 0 + url = env.mkurl("https", "test1", "/006/006.css") + # prime the cache (stored, immediately stale via max-age=0) + r = env.curl_get(url) + assert r.exit_code == 0, f'{r}' + assert r.response["status"] == 200 + lm = r.response["header"]["last-modified"] + # revalidate: mod_cache freshens the stale entry and the origin returns a + # body-less 304. The h2 stream must close cleanly; a regression shows up + # as a curl exit (92, "stream not closed cleanly"), not as a 304. + for _ in range(5): + r = env.curl_get(url, options=["-H", "Cache-Control: max-age=0", + "-H", f"if-modified-since: {lm}"]) + assert r.exit_code == 0, f'304 stream was reset (curl {r.exit_code}): {r}' + assert r.response["status"] == 304, f'{r.response}'