From 0efda43571f86ece3106d47bdbda7da288902302 Mon Sep 17 00:00:00 2001 From: bneradt Date: Mon, 27 Jul 2026 11:35:14 -0500 Subject: [PATCH] Add autest for http2.incomplete_header_timeout_in No off-the-shelf client can withhold the END_HEADERS flag, so this adds an ad-hoc HTTP/2 client that fragments the request header block and optionally never sends the CONTINUATION frame. The test also covers a CONTINUATION that arrives in time and a slow origin response, so that a regression in canceling the timeout at transaction start is caught too. Fixes: #11391 Co-Authored-By: Claude Opus 5 --- .../timeout/http2_incomplete_header_client.py | 290 ++++++++++++++++++ .../http2_incomplete_header_timeout.test.py | 207 +++++++++++++ ...ttp2_incomplete_header_timeout.replay.yaml | 63 ++++ 3 files changed, 560 insertions(+) create mode 100644 tests/gold_tests/timeout/http2_incomplete_header_client.py create mode 100644 tests/gold_tests/timeout/http2_incomplete_header_timeout.test.py create mode 100644 tests/gold_tests/timeout/replay/http2_incomplete_header_timeout.replay.yaml diff --git a/tests/gold_tests/timeout/http2_incomplete_header_client.py b/tests/gold_tests/timeout/http2_incomplete_header_client.py new file mode 100644 index 00000000000..d1616fef2e5 --- /dev/null +++ b/tests/gold_tests/timeout/http2_incomplete_header_client.py @@ -0,0 +1,290 @@ +#!/usr/bin/env python3 +''' +HTTP/2 client that fragments a request header block across a HEADERS frame and +an optional CONTINUATION frame in order to exercise +proxy.config.http2.incomplete_header_timeout_in. +''' +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import argparse +import socket +import ssl +import sys +import time +from typing import List, Optional, Tuple + +import hpack + +CONNECTION_PREFACE = b'PRI * HTTP/2.0\r\n\r\nSM\r\n\r\n' + +FRAME_TYPE_DATA = 0x00 +FRAME_TYPE_HEADERS = 0x01 +FRAME_TYPE_RST_STREAM = 0x03 +FRAME_TYPE_SETTINGS = 0x04 +FRAME_TYPE_GOAWAY = 0x07 +FRAME_TYPE_CONTINUATION = 0x09 + +FLAG_ACK = 0x01 +FLAG_END_STREAM = 0x01 +FLAG_END_HEADERS = 0x04 + +STREAM_ID = 1 + + +def make_socket(port: int, socket_timeout: float) -> ssl.SSLSocket: + '''Establish a TLS connection to ATS with h2 negotiated via ALPN. + + :param port: The ATS TLS port to connect to. + :param socket_timeout: The socket timeout, in seconds. + :return: The connected TLS socket. + ''' + ctx = ssl.create_default_context() + ctx.check_hostname = False + ctx.verify_mode = ssl.CERT_NONE + ctx.set_alpn_protocols(['h2']) + + raw = socket.create_connection(('127.0.0.1', port), timeout=socket_timeout) + tls = ctx.wrap_socket(raw, server_hostname='localhost') + if tls.selected_alpn_protocol() != 'h2': + raise RuntimeError(f'failed to negotiate h2, got {tls.selected_alpn_protocol()!r}') + return tls + + +def make_frame(frame_type: int, flags: int = 0, stream_id: int = 0, payload: bytes = b'') -> bytes: + '''Serialize an HTTP/2 frame. + + :param frame_type: The frame type. + :param flags: The frame flags. + :param stream_id: The stream the frame belongs to. + :param payload: The frame payload. + :return: The serialized frame. + ''' + return (len(payload).to_bytes(3, 'big') + bytes([frame_type, flags]) + (stream_id & 0x7fffffff).to_bytes(4, 'big') + payload) + + +def read_exact(sock: ssl.SSLSocket, size: int) -> bytes: + '''Read exactly @a size bytes from @a sock. + + :param sock: The socket to read from. + :param size: The number of bytes to read. + :return: The bytes read. + ''' + chunks: List[bytes] = [] + remaining = size + while remaining > 0: + chunk = sock.recv(remaining) + if not chunk: + raise EOFError('socket closed') + chunks.append(chunk) + remaining -= len(chunk) + return b''.join(chunks) + + +def read_frame(sock: ssl.SSLSocket) -> Tuple[int, int, int, bytes]: + '''Read a single HTTP/2 frame from @a sock. + + :param sock: The socket to read from. + :return: The frame type, flags, stream id, and payload. + ''' + header = read_exact(sock, 9) + length = int.from_bytes(header[0:3], 'big') + frame_type = header[3] + flags = header[4] + stream_id = int.from_bytes(header[5:9], 'big') & 0x7fffffff + payload = read_exact(sock, length) + return frame_type, flags, stream_id, payload + + +def complete_handshake(sock: ssl.SSLSocket) -> None: + '''Exchange the connection preface and SETTINGS frames. + + The handshake is completed before the request is sent so that the client + does not have to interleave reads with the deliberate delay before the + CONTINUATION frame. + + :param sock: The socket to handshake on. + ''' + sock.sendall(CONNECTION_PREFACE) + sock.sendall(make_frame(FRAME_TYPE_SETTINGS)) + + acked_peer_settings = False + received_settings_ack = False + while not (acked_peer_settings and received_settings_ack): + frame_type, flags, _, _ = read_frame(sock) + if frame_type != FRAME_TYPE_SETTINGS: + continue + if flags & FLAG_ACK: + received_settings_ack = True + else: + sock.sendall(make_frame(FRAME_TYPE_SETTINGS, FLAG_ACK, 0)) + acked_peer_settings = True + + +def request_block(path: str, uuid: str) -> bytes: + '''HPACK encode the request header block. + + :param path: The value for the :path pseudo header. + :param uuid: The value for the uuid header that the Proxy Verifier server + keys transactions off of. + :return: The encoded header block. + ''' + return hpack.Encoder().encode( + [ + (':method', 'GET'), + (':scheme', 'https'), + (':authority', 'example.com'), + (':path', path), + ('uuid', uuid), + ]) + + +def read_until_stream_ends(sock: ssl.SSLSocket, start: float) -> bool: + '''Read frames until ATS ends the stream or the connection. + + :param sock: The socket to read from. + :param start: The monotonic time at which the request HEADERS frame was sent. + :return: Whether a response status was received for the request. + ''' + decoder = hpack.Decoder() + header_fragments: List[bytes] = [] + got_status = False + + while True: + frame_type, flags, stream_id, payload = read_frame(sock) + + # Nothing is written back here. While ATS is waiting for a CONTINUATION + # frame, any other frame from the client -- a SETTINGS ACK included -- + # is a connection level PROTOCOL_ERROR, which would mask the timeout + # under test. + if frame_type == FRAME_TYPE_GOAWAY: + last_stream_id = int.from_bytes(payload[0:4], 'big') & 0x7fffffff + error_code = int.from_bytes(payload[4:8], 'big') + print(f'GOAWAY error_code={error_code} last_stream_id={last_stream_id} ' + f'elapsed={time.monotonic() - start:.2f}') + return got_status + + if stream_id != STREAM_ID: + continue + + if frame_type == FRAME_TYPE_RST_STREAM: + error_code = int.from_bytes(payload[0:4], 'big') + print(f'stream {stream_id}: RST_STREAM error_code={error_code} elapsed={time.monotonic() - start:.2f}') + return got_status + + if frame_type in (FRAME_TYPE_HEADERS, FRAME_TYPE_CONTINUATION): + header_fragments.append(payload) + if flags & FLAG_END_HEADERS: + fields = dict(decoder.decode(b''.join(header_fragments))) + header_fragments = [] + status = fields.get(':status') + if status is not None: + got_status = True + print(f'stream {stream_id}: status={status} elapsed={time.monotonic() - start:.2f}') + + if (flags & FLAG_END_STREAM) and frame_type in (FRAME_TYPE_DATA, FRAME_TYPE_HEADERS): + print(f'stream {stream_id}: END_STREAM elapsed={time.monotonic() - start:.2f}') + return got_status + + +def check_elapsed(elapsed: float, min_elapsed: Optional[float], max_elapsed: Optional[float]) -> bool: + '''Verify that ATS ended the stream within the expected window. + + :param elapsed: How long ATS took to end the stream, in seconds. + :param min_elapsed: The lower bound, or None for no lower bound. + :param max_elapsed: The upper bound, or None for no upper bound. + :return: Whether @a elapsed is within the expected window. + ''' + if min_elapsed is not None and elapsed < min_elapsed: + print(f'FAIL: ATS ended the stream after {elapsed:.2f}s, sooner than the expected {min_elapsed}s', file=sys.stderr) + return False + if max_elapsed is not None and elapsed > max_elapsed: + print(f'FAIL: ATS ended the stream after {elapsed:.2f}s, later than the expected {max_elapsed}s', file=sys.stderr) + return False + print(f'timing ok: elapsed={elapsed:.2f}') + return True + + +def run(args: argparse.Namespace) -> int: + '''Send the request and report what ATS does with the stream. + + :param args: The parsed command line arguments. + :return: The process exit code. + ''' + block = request_block(args.path, args.uuid) + print(f'end_headers={args.end_headers} continuation_delay={args.continuation_delay}') + + with make_socket(args.port, args.socket_timeout) as sock: + complete_handshake(sock) + + flags = FLAG_END_STREAM + fragment = block + if args.end_headers: + flags |= FLAG_END_HEADERS + else: + # Withholding END_HEADERS leaves ATS waiting for a CONTINUATION + # frame, which is what incomplete_header_timeout_in bounds. + fragment = block[:len(block) // 2] + start = time.monotonic() + sock.sendall(make_frame(FRAME_TYPE_HEADERS, flags, STREAM_ID, fragment)) + + if args.continuation_delay is not None: + time.sleep(args.continuation_delay) + print(f'sending CONTINUATION elapsed={time.monotonic() - start:.2f}') + sock.sendall(make_frame(FRAME_TYPE_CONTINUATION, FLAG_END_HEADERS, STREAM_ID, block[len(block) // 2:])) + + try: + got_status = read_until_stream_ends(sock, start) + except EOFError: + print(f'EOF elapsed={time.monotonic() - start:.2f}') + got_status = False + except socket.timeout: + print(f'FAIL: no response from ATS within the {args.socket_timeout}s socket timeout', file=sys.stderr) + return 1 + + elapsed = time.monotonic() - start + print(f'got_status={got_status}') + return 0 if check_elapsed(elapsed, args.min_elapsed, args.max_elapsed) else 1 + + +def parse_args() -> argparse.Namespace: + '''Parse the command line arguments. + + :return: The parsed arguments. + ''' + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument('port', type=int, help='ATS TLS port') + parser.add_argument('--path', default='/incomplete', help='request :path') + parser.add_argument('--uuid', default='incomplete_header', help='request uuid header') + parser.add_argument( + '--end-headers', action='store_true', help='send the complete header block with END_HEADERS in a single HEADERS frame') + parser.add_argument( + '--continuation-delay', + type=float, + default=None, + help='seconds after the HEADERS frame to send the END_HEADERS CONTINUATION frame; omit to never send it') + parser.add_argument('--min-elapsed', type=float, default=None, help='fail if ATS ends the stream sooner than this') + parser.add_argument('--max-elapsed', type=float, default=None, help='fail if ATS ends the stream later than this') + parser.add_argument('--socket-timeout', type=float, default=60.0, help='socket timeout in seconds') + return parser.parse_args() + + +def main() -> int: + return run(parse_args()) + + +if __name__ == '__main__': + raise SystemExit(main()) diff --git a/tests/gold_tests/timeout/http2_incomplete_header_timeout.test.py b/tests/gold_tests/timeout/http2_incomplete_header_timeout.test.py new file mode 100644 index 00000000000..aad0449282e --- /dev/null +++ b/tests/gold_tests/timeout/http2_incomplete_header_timeout.test.py @@ -0,0 +1,207 @@ +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import sys +from typing import Optional + +Test.Summary = 'Verify http2.incomplete_header_timeout_in' + +# VC_EVENT_ACTIVE_TIMEOUT. The incomplete header timeout is an active timeout on +# the stream, so ATS reports this event rather than VC_EVENT_INACTIVITY_TIMEOUT +# (105). +VC_EVENT_ACTIVE_TIMEOUT = 106 + +# Http2ErrorCode::HTTP2_ERROR_COMPRESSION_ERROR. ATS tears down the connection +# rather than just the stream because the undelivered CONTINUATION frame leaves +# its HPACK dynamic table out of sync. +HTTP2_ERROR_COMPRESSION_ERROR = 9 + + +class TestHttp2IncompleteHeaderTimeout: + """Configure a test for http2.incomplete_header_timeout_in. + + The client sends a HEADERS frame without the END_HEADERS flag, which leaves + ATS waiting for a CONTINUATION frame. incomplete_header_timeout_in bounds + how long ATS waits. + """ + + client_script: str = 'http2_incomplete_header_client.py' + replay_file: str = 'replay/http2_incomplete_header_timeout.replay.yaml' + counter: int = 0 + + def __init__( + self, + name: str, + incomplete_header_timeout_in: int, + path: str, + uuid: str, + end_headers: bool = False, + continuation_delay: Optional[float] = None, + min_elapsed: Optional[float] = None, + max_elapsed: Optional[float] = None, + expect_timeout: bool = False): + """Initialize the test. + + :param name: The name of the test run. + :param incomplete_header_timeout_in: The value to configure for + proxy.config.http2.incomplete_header_timeout_in. + :param path: The :path pseudo header the client requests. + :param uuid: The uuid of the replay file transaction to request. + :param end_headers: Whether the client sends the complete header block + with END_HEADERS in a single HEADERS frame. + :param continuation_delay: How long after the HEADERS frame the client + waits before sending the END_HEADERS CONTINUATION frame. None means + that the client never sends it. + :param min_elapsed: Fail if ATS ends the stream sooner than this. + :param max_elapsed: Fail if ATS ends the stream later than this. + :param expect_timeout: Whether ATS is expected to time out the stream. + """ + self._name = name + self._incomplete_header_timeout_in = incomplete_header_timeout_in + self._path = path + self._uuid = uuid + self._end_headers = end_headers + self._continuation_delay = continuation_delay + self._min_elapsed = min_elapsed + self._max_elapsed = max_elapsed + self._expect_timeout = expect_timeout + + def _configure_server(self, tr: 'TestRun') -> None: + """Configure the origin server. + + :param tr: The TestRun object to associate the server process with. + """ + self._server = tr.AddVerifierServerProcess(f'server-{self.counter}', self.replay_file) + + def _configure_traffic_server(self, tr: 'TestRun') -> None: + """Configure Traffic Server. + + :param tr: The TestRun object to associate the ts process with. + """ + ts = tr.MakeATSProcess(f'ts-{self.counter}', enable_tls=True, enable_cache=False) + self._ts = ts + + ts.addSSLfile('ssl/cert.crt') + ts.addSSLfile('ssl/private-key.key') + ts.Disk.ssl_multicert_yaml.AddLines( + f""" +ssl_multicert: + - dest_ip: "*" + ssl_cert_name: {ts.Variables.SSLDir}/cert.crt + ssl_key_name: {ts.Variables.SSLDir}/private-key.key +""".split('\n')) + + ts.Disk.records_config.update( + { + 'proxy.config.diags.debug.enabled': 1, + 'proxy.config.diags.debug.tags': 'http2', + 'proxy.config.ssl.server.cert.path': ts.Variables.SSLDir, + 'proxy.config.ssl.server.private_key.path': ts.Variables.SSLDir, + 'proxy.config.http2.incomplete_header_timeout_in': self._incomplete_header_timeout_in, + }) + + ts.Disk.remap_config.AddLine(f'map / http://127.0.0.1:{self._server.Variables.http_port}') + + def _configure_client(self, tr: 'TestRun') -> None: + """Configure the ad hoc HTTP/2 client. + + :param tr: The TestRun object to associate the client process with. + """ + tr.Setup.Copy(self.client_script) + command = ( + f'{sys.executable} {self.client_script} {self._ts.Variables.ssl_port} ' + f'--path {self._path} --uuid {self._uuid}') + if self._end_headers: + command += ' --end-headers' + if self._continuation_delay is not None: + command += f' --continuation-delay {self._continuation_delay}' + if self._min_elapsed is not None: + command += f' --min-elapsed {self._min_elapsed}' + if self._max_elapsed is not None: + command += f' --max-elapsed {self._max_elapsed}' + + tr.Processes.Default.Command = command + tr.Processes.Default.ReturnCode = 0 + + def _configure_expectations(self, tr: 'TestRun') -> None: + """Configure the testers for the test run. + + :param tr: The TestRun object to associate the testers with. + """ + timeout_error = 'ERROR: HTTP/2 stream error timeout' + if self._expect_timeout: + tr.Processes.Default.Streams.stdout += Testers.ContainsExpression( + f'GOAWAY error_code={HTTP2_ERROR_COMPRESSION_ERROR} last_stream_id=1', + 'ATS should close the connection with COMPRESSION_ERROR because the HPACK table is out of sync.') + self._ts.Disk.traffic_out.Content += Testers.ContainsExpression( + f'timeout event={VC_EVENT_ACTIVE_TIMEOUT}', + 'ATS should time out the incomplete header with the stream active timeout.') + # The default diags.log check rejects any ERROR:, but this test + # expects the incomplete header timeout to be reported. + self._ts.Disk.diags_log.Content = Testers.ContainsExpression( + timeout_error, 'ATS should log the incomplete header timeout.') + else: + tr.Processes.Default.Streams.stdout += Testers.ContainsExpression( + 'stream 1: status=200', 'ATS should proxy the request rather than time out the stream.') + tr.Processes.Default.Streams.stdout += Testers.ExcludesExpression('GOAWAY', 'ATS should not close the connection.') + self._ts.Disk.diags_log.Content += Testers.ExcludesExpression( + timeout_error, 'ATS should not report an incomplete header timeout.') + + def run(self) -> None: + """Run the test.""" + tr = Test.AddTestRun(self._name) + self._configure_server(tr) + self._configure_traffic_server(tr) + self._configure_client(tr) + self._configure_expectations(tr) + + tr.Processes.Default.StartBefore(self._server) + tr.Processes.Default.StartBefore(self._ts) + TestHttp2IncompleteHeaderTimeout.counter += 1 + + +# A client that never completes the header block should be timed out at the +# configured timeout, well before the 10 second default. +TestHttp2IncompleteHeaderTimeout( + 'Incomplete header block times out', + incomplete_header_timeout_in=3, + path='/incomplete', + uuid='incomplete_header', + continuation_delay=None, + min_elapsed=2.5, + max_elapsed=7, + expect_timeout=True).run() + +# A client that completes the header block before the timeout expires should be +# proxied normally. +TestHttp2IncompleteHeaderTimeout( + 'CONTINUATION frame arrives before the timeout', + incomplete_header_timeout_in=5, + path='/incomplete', + uuid='incomplete_header', + continuation_delay=1, + expect_timeout=False).run() + +# The timeout is canceled when the transaction starts, so a slow origin +# response must not be mistaken for an incomplete header block. +TestHttp2IncompleteHeaderTimeout( + 'Timeout is canceled once the transaction starts', + incomplete_header_timeout_in=2, + path='/delayed', + uuid='delayed_response', + end_headers=True, + min_elapsed=4.5, + expect_timeout=False).run() diff --git a/tests/gold_tests/timeout/replay/http2_incomplete_header_timeout.replay.yaml b/tests/gold_tests/timeout/replay/http2_incomplete_header_timeout.replay.yaml new file mode 100644 index 00000000000..3bfa0315a31 --- /dev/null +++ b/tests/gold_tests/timeout/replay/http2_incomplete_header_timeout.replay.yaml @@ -0,0 +1,63 @@ +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +# The client side of these transactions is driven by +# http2_incomplete_header_client.py, which fragments the request header block. +# Only the server side of this file is used. + +meta: + version: "1.0" + +sessions: +- transactions: + + # Requested by the client that completes its header block with a + # CONTINUATION frame before incomplete_header_timeout_in expires. + - client-request: + method: GET + url: /incomplete + version: '1.1' + headers: + fields: + - [ Host, example.com ] + - [ uuid, incomplete_header ] + + server-response: + status: 200 + reason: OK + headers: + fields: + - [ Content-Length, 16 ] + + # Requested by the client that sends a complete header block. The response is + # delayed past incomplete_header_timeout_in to verify that the timeout is + # canceled once the transaction starts. + - client-request: + method: GET + url: /delayed + version: '1.1' + headers: + fields: + - [ Host, example.com ] + - [ uuid, delayed_response ] + + server-response: + delay: 5s + status: 200 + reason: OK + headers: + fields: + - [ Content-Length, 16 ]