Copilot commented on code in PR #13873:
URL: https://github.com/apache/trafficserver/pull/13873#discussion_r4340824788
##########
tests/uranium_tests/h2/h2active_timeout.py:
##########
@@ -54,16 +54,28 @@ def get_socket(port: int) -> socket.socket:
return tls_socket
-def makerequest(port: int, path: str, delay: int) -> None:
- """Establish an HTTP/2 connection and send a request.
+def makerequest(port: int, path: str, active_timeout: int, max_wait: int) ->
None:
+ """Send a request, then wait for ATS to close the connection on its active
timeout.
+
+ ATS enforces the active timeout from its InactivityCop, which looks at a
+ connection only once a second, so the close lands up to a second after the
+ timeout expires, and later still on a loaded machine. Rather than guess
when
+ that is, wait for the close itself and check that it came no sooner than
the
+ timeout and within max_wait seconds.
:param port: The port to connect to.
:param path: The path to request.
- :param delay: The delay to wait between sending requests in a stream.
+ :param active_timeout: The proxy.config.http2.active_timeout_in ATS uses,
in seconds.
+ :param max_wait: The number of seconds to wait for ATS to close the
connection.
"""
tls_socket = get_socket(port)
+ # ATS starts the active timeout when it reads the connection preface, which
+ # happens after this point, so it cannot close the connection any sooner
+ # than active_timeout seconds from now.
+ start = time.monotonic()
+
h2_connection = h2.connection.H2Connection()
h2_connection.initiate_connection()
tls_socket.sendall(h2_connection.data_to_send())
Review Comment:
The timer starts before the connection preface is written to the socket.
That adds client-side latency to `elapsed`, which can mask an early-close
regression (ATS closes slightly before `active_timeout` from its own start, but
`elapsed` still lands >= `active_timeout`). Start the clock immediately after
sending the client preface bytes (or as close to the send as possible) so the
measured lower bound aligns with the event that begins the ATS timer.
##########
tests/uranium_tests/h2/h2active_timeout.py:
##########
@@ -78,65 +90,46 @@ def makerequest(port: int, path: str, delay: int) -> None:
h2_connection.send_headers(1, headers, end_stream=True)
tls_socket.sendall(h2_connection.data_to_send())
- # delay, triggering ATS timeout.
- time.sleep(delay)
-
- # The following should fail due to the timeout.
+ # Read the response, then keep reading until ATS closes the connection.
+ closed = False
try:
- # Send a second request.
- h2_connection.send_headers(3, headers, end_stream=True)
- tls_socket.sendall(h2_connection.data_to_send())
-
- response_stream_ended = False
- body = b''
- while not response_stream_ended:
- # read raw data from the socket
- data = tls_socket.recv(65536 * 1024)
+ while True:
+ remaining = start + max_wait - time.monotonic()
+ if remaining <= 0:
+ break
+ tls_socket.settimeout(remaining)
+ data = tls_socket.recv(65536)
if not data:
+ closed = True
break
-
- # feed raw data into h2, and process resulting events
- events = h2_connection.receive_data(data)
- for event in events:
- if isinstance(event, h2.events.ResponseReceived):
- # response headers received
- print("Response received:")
- for header in event.headers:
- print(f' {header[0].decode()}: {header[1].decode()}')
+ for event in h2_connection.receive_data(data):
if isinstance(event, h2.events.DataReceived):
- # update flow control so the server doesn't starve us
h2_connection.acknowledge_received_data(event.flow_controlled_length,
event.stream_id)
- # more response body data received
- body += event.data
- if isinstance(event, h2.events.StreamEnded):
- # response body completed, let's exit the loop
- response_stream_ended = True
- break
- # send any pending data to the server
tls_socket.sendall(h2_connection.data_to_send())
-
- print(f"Response fully received: {len(body)} bytes")
-
- body_str = body.decode('utf-8')
-
- # tell the server we are closing the h2 connection
- h2_connection.close_connection()
- tls_socket.sendall(h2_connection.data_to_send())
-
- # close the socket
- tls_socket.close()
- except Exception:
+ except socket.timeout:
+ pass
+ except (ConnectionError, ssl.SSLError):
+ closed = True
+ elapsed = time.monotonic() - start
+ tls_socket.close()
Review Comment:
Socket closure isn’t guaranteed if an unexpected exception occurs inside the
loop (e.g., an h2 parsing/protocol exception). Consider moving
`tls_socket.close()` into a `finally` block so resources are reliably cleaned
up and failures are easier to diagnose (you can still compute `elapsed`/print
messages after the `try` with appropriate guards).
##########
tests/uranium_tests/h2/h2active_timeout.py:
##########
@@ -78,65 +90,46 @@ def makerequest(port: int, path: str, delay: int) -> None:
h2_connection.send_headers(1, headers, end_stream=True)
tls_socket.sendall(h2_connection.data_to_send())
- # delay, triggering ATS timeout.
- time.sleep(delay)
-
- # The following should fail due to the timeout.
+ # Read the response, then keep reading until ATS closes the connection.
+ closed = False
try:
- # Send a second request.
- h2_connection.send_headers(3, headers, end_stream=True)
- tls_socket.sendall(h2_connection.data_to_send())
-
- response_stream_ended = False
- body = b''
- while not response_stream_ended:
- # read raw data from the socket
- data = tls_socket.recv(65536 * 1024)
+ while True:
+ remaining = start + max_wait - time.monotonic()
+ if remaining <= 0:
+ break
+ tls_socket.settimeout(remaining)
+ data = tls_socket.recv(65536)
if not data:
+ closed = True
break
-
- # feed raw data into h2, and process resulting events
- events = h2_connection.receive_data(data)
- for event in events:
- if isinstance(event, h2.events.ResponseReceived):
- # response headers received
- print("Response received:")
- for header in event.headers:
- print(f' {header[0].decode()}: {header[1].decode()}')
+ for event in h2_connection.receive_data(data):
if isinstance(event, h2.events.DataReceived):
- # update flow control so the server doesn't starve us
h2_connection.acknowledge_received_data(event.flow_controlled_length,
event.stream_id)
- # more response body data received
- body += event.data
- if isinstance(event, h2.events.StreamEnded):
- # response body completed, let's exit the loop
- response_stream_ended = True
- break
- # send any pending data to the server
tls_socket.sendall(h2_connection.data_to_send())
-
- print(f"Response fully received: {len(body)} bytes")
-
- body_str = body.decode('utf-8')
-
- # tell the server we are closing the h2 connection
- h2_connection.close_connection()
- tls_socket.sendall(h2_connection.data_to_send())
-
- # close the socket
- tls_socket.close()
- except Exception:
+ except socket.timeout:
+ pass
+ except (ConnectionError, ssl.SSLError):
+ closed = True
+ elapsed = time.monotonic() - start
+ tls_socket.close()
+
+ if not closed:
+ print(f"Connection still open after {max_wait} seconds")
+ elif elapsed < active_timeout:
+ print(f"Connection closed after {elapsed:.1f} seconds, before the
{active_timeout} second active timeout")
+ else:
print("CONNECTION_TIMEOUT")
Review Comment:
On failure paths (connection still open, or closed too early), the script
still exits with status 0 and relies on the caller to parse stdout. It would be
more robust to exit non-zero for the failure cases (and keep 0 only for the
`CONNECTION_TIMEOUT` success case). That makes test failures clearer and avoids
false positives if output parsing changes.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
