You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@trafficserver.apache.org by bc...@apache.org on 2026/09/15 22:16:49 UTC
(trafficserver) branch master updated: Pace the rate_limit SNI queue test on the plugin's own log lines (#13681)
This is an automated email from the ASF dual-hosted git repository.
bryancall pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/trafficserver.git
The following commit(s) were added to refs/heads/master by this push:
new 804e5e2dd1 Pace the rate_limit SNI queue test on the plugin's own log lines (#13681)
804e5e2dd1 is described below
commit 804e5e2dd100f4ebae7f600f287b337be34b1f22
Author: Bryan Call <bc...@apache.org>
AuthorDate: Tue Sep 15 15:16:42 2026 -0700
Pace the rate_limit SNI queue test on the plugin's own log lines (#13681)
The test paced its setup with wall-clock sleeps, so on a loaded runner the
holder could miss the slot and nothing queued, while on macOS the holder never
released and the resume and release paths never ran -- it passed against the
unfixed plugin. Every step now waits on the plugin's own debug line, and every
connection is held open on a FIFO and ended by signal, so neither platform's
s_client EOF behaviour matters. It also asserts the sweep reserved a slot before
resuming the queued connection and that no release wraps the counter, so the
queue path cannot be skipped silently.
---
.../rate_limit/rate_limit_sni_queue.test.py | 40 +++-
.../rate_limit/rate_limit_sni_queue_client.sh | 202 +++++++++++++++++----
2 files changed, 194 insertions(+), 48 deletions(-)
diff --git a/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue.test.py b/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue.test.py
index 5904275262..15d332f0a6 100644
--- a/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue.test.py
+++ b/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue.test.py
@@ -1,9 +1,16 @@
'''
-Regression test for a queue-accounting balance bug in the rate_limit SNI limiter: a
-queued connection never reserves a slot, but its VCONN_CLOSE unconditionally releases
-one, so a queued connection that closes underflows the active-slot counter and the next
-reserve() trips a release assertion, aborting the server. ATS must survive the queue
-churn.
+Regression test for the rate_limit SNI limiter's queue accounting. A queued connection never
+reserves a slot, so the sweep must reserve one before resuming it and a close must release
+only a slot the connection owns. When the sweep resumes a queued connection while the limiter
+is still full, the holder's close lands the active-slot counter on zero, the resumed
+connection's close releases a slot it never held and wraps the counter below zero, and the
+next reserve() trips a release assertion that aborts the server. ATS must survive the queue
+churn without the counter wrapping.
+
+The client drives resume-then-close rather than closing a connection while it is parked,
+because ATS does not read the socket while the ClientHello hook is invoked: a FIN from a
+parked client is invisible until the sweep reenables the VC. The close-while-queued branch
+is out of scope for this test and cannot be reached from a client.
'''
# Licensed to the Apache Software Foundation (ASF) under one
# or more contributor license agreements. See the NOTICE file
@@ -69,17 +76,32 @@ class RateLimitSniQueueTest:
'proxy.config.diags.debug.tags': 'rate_limit',
})
- # The queue path is reached...
+ # The queue path is reached and the sweep resumes the queued connection once the
+ # holder has released its slot...
ts.Disk.traffic_out.Content = Testers.ContainsExpression('Queueing the VC', 'a connection was queued')
- # ...and the active-slot counter never underflows into the release assertion. Match
- # both the specific assertion (pins the failure to this bug) and the generic abort.
+ ts.Disk.traffic_out.Content += Testers.ContainsExpression(
+ 'Enabling queued VC', 'the sweep resumed the queued connection into a reserved slot')
+ # ...nothing is turned away: with one holder and a queue of one, a rejection means the
+ # holder never released and the probe hit a full queue, so the release path went
+ # unexercised...
+ ts.Disk.traffic_out.Content += Testers.ExcludesExpression(
+ 'Rejecting connection', 'no connection is rejected; the holder must release its slot')
+ # ...and the active-slot counter never underflows. free() logs the counter after
+ # dropping the lock, so a concurrent reserve() can legitimately make a release read back
+ # as 1; only a wrapped counter is a defect, and an unmatched decrement of a uint32 at
+ # limit 1 is unmistakable -- it reads 4294967295, never a small number.
+ ts.Disk.traffic_out.Content += Testers.ExcludesExpression(
+ r'Releasing a slot, active entities == [0-9]{4,}', 'a release must never wrap the counter')
ts.Disk.traffic_out.Content += Testers.ExcludesExpression(
'_active <= _limit|received signal', 'the active-slot counter must not underflow and abort ATS')
def _configure_client(self, tr: 'TestRun') -> None:
ts = self._ts
client = os.path.join(Test.TestDirectory, 'rate_limit_sni_queue_client.sh')
- tr.Processes.Default.Command = f'bash {client} 127.0.0.1 {ts.Variables.ssl_port} rate.limited.com'
+ # The client paces itself on the plugin's debug lines in traffic.out, so it needs the
+ # path rather than a guess at how long each step takes.
+ tr.Processes.Default.Command = (
+ f'bash {client} 127.0.0.1 {ts.Variables.ssl_port} rate.limited.com {ts.Disk.traffic_out.AbsPath}')
tr.Processes.Default.ReturnCode = 0
tr.Processes.Default.StartBefore(ts)
tr.Processes.Default.Streams.stdout = Testers.ContainsExpression(
diff --git a/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh b/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh
index 0ce7e56f3b..27c995b92d 100644
--- a/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh
+++ b/tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh
@@ -20,59 +20,183 @@
# and check that the active-slot counter stays balanced and the server survives.
#
# 1. holder completes its handshake and holds the single slot (counter = 1);
-# 2. one connection enqueues because the slot is full, then closes while parked;
-# 3. the sweep reserves a slot and resumes a queued connection;
-# 4. the holder is closed and releases its slot;
+# 2. one connection enqueues because the slot is full and stays parked at the ClientHello hook;
+# 3. the sweep runs while the slot is still held and must leave the queued connection parked;
+# 4. the holder is closed and releases its slot; the next sweep reserves that slot and resumes
+# the queued connection, which is then closed and releases the slot it now owns;
# 5. a probe connection reserves the freed slot.
#
-# Against the plugin before 508c1bea26 this aborts the server: the sweep resumed a queued
-# connection without a reservation, whose close then decremented the counter unmatched until it
-# wrapped and reserve() tripped TSReleaseAssert(_active <= _limit). The test asserts the counter
-# never wraps and no signal is logged, so it pins that fix as well as this change.
+# The accounting under test: a queued connection holds no slot, so the sweep must reserve one
+# before resuming it. A resume without that reservation aborts the server, because the holder's
+# close lands the counter on zero and the resumed connection's close, releasing a slot it never
+# held, wraps it below zero, so the probe's reserve() trips TSReleaseAssert(_active <= _limit).
+# Step 4 asserts the reservation directly and fails there, naming the defect rather than the crash
+# it leads to. The test's traffic.out testers reject that wrap and that abort however they arise,
+# and stay the backstop for both.
#
-# args: host port sni
+# The connection is resumed and then closed, never closed while parked, because a client cannot
+# close a parked connection as far as ATS is concerned: while the ClientHello hook is invoked ATS
+# does not read the socket, so a FIN sits in the kernel until the sweep reenables the VC. The
+# close-while-queued branch of sni_limiter.cc is therefore out of scope here and cannot be driven
+# from a client, so a "closes while parked" step would only resolve to the resume-then-close path
+# this script already drives.
+#
+# Every step waits for the plugin's own debug line in traffic.out rather than sleeping for a
+# guessed interval, so a loaded runner cannot let a connection miss the holder and skip the queue
+# path unnoticed. Every connection reads stdin from a FIFO that never delivers data, and is ended
+# with kill -TERM on openssl's own PID.
+# Neither the moment a connection opens nor the moment it closes is left to s_client: how it
+# reacts to EOF on stdin differs between OpenSSL and LibreSSL, so a connection that must stay up
+# is given stdin that never becomes readable, and one that must go is killed outright. The plugin
+# only needs the VCONN_CLOSE that the resulting FIN produces.
+#
+# args: host port sni traffic_out
set -u
host="$1"
port="$2"
sni="$3"
+traffic_out="$4"
-OSSL="openssl s_client -connect ${host}:${port} -servername ${sni} -quiet -no_ign_eof"
-
-# Run a command in the background and terminate it after a deadline. coreutils "timeout" is not
-# available everywhere (notably macOS), so do it with sleep and kill.
-run_for() {
- deadline="$1"
- shift
- "$@" &
- target=$!
- (
- sleep "${deadline}"
- kill -TERM "${target}" 2>/dev/null
- ) &
-}
+OSSL="openssl s_client -connect ${host}:${port} -servername ${sni} -quiet"
+
+# Ceiling per step. It only bounds a broken run; a healthy one moves on as soon as the line
+# appears.
+WAIT_LIMIT=30
+
+holder=""
+queued=""
+probe=""
-# 1. Holder: hold the single slot. Its stdin is a FIFO kept open on fd 3, so we end the
-# holder deterministically in step 4 (closing fd 3 -> EOF -> clean TLS close -> FIN).
+# Shared stdin for every connection: a FIFO held open read-write on fd 3 that nothing ever
+# writes to, so reads block and polls stay idle until the process is killed. Opening it
+# read-write does not block, and the connections inherit fd 3 rather than opening the path,
+# so the directory can go straight away.
fifo_dir="$(mktemp -d "${TMPDIR:-/tmp}/rl_holder.XXXXXX")"
-fifo="${fifo_dir}/fifo"
-mkfifo "$fifo"
-${OSSL} <"$fifo" >/dev/null 2>&1 &
-exec 3<>"$fifo"
+mkfifo "${fifo_dir}/fifo"
+exec 3<>"${fifo_dir}/fifo"
rm -rf "$fifo_dir"
-sleep 3 # let the holder reserve the one slot
-# 2. One queued connection: enqueues because the slot is full, then closes while still parked
-# at the ClientHello hook.
-run_for 0.3 sh -c "${OSSL} </dev/null >/dev/null 2>&1"
-sleep 2 # >= 2 sweep periods (300ms each), so the sweep runs while the connection is queued
+# Poll traffic.out until the fixed string has appeared at least count times. Diags serialises
+# each debug line and flushes it whole, so polling can never see a half-written line and a line
+# is visible as soon as the plugin emits it. On timeout, fail loudly with what was expected and
+# what the log holds so the sandbox is diagnosable.
+wait_for() {
+ needle="$1"
+ count="$2"
+ end=$((SECONDS + WAIT_LIMIT))
+ while :; do
+ seen=$(grep -c -F -- "$needle" "$traffic_out" 2>/dev/null || true)
+ if [ "${seen:-0}" -ge "$count" ]; then
+ return 0
+ fi
+ if [ "$SECONDS" -ge "$end" ]; then
+ echo "timed out after ${WAIT_LIMIT}s waiting for occurrence ${count} of '${needle}' (saw ${seen:-0})" >&2
+ echo "--- tail of ${traffic_out}:" >&2
+ tail -n 20 "$traffic_out" >&2
+ exit 1
+ fi
+ sleep 0.1
+ done
+}
+
+# Close a connection by killing openssl itself. Escalate to KILL rather than waiting forever:
+# a TERM-immune s_client would otherwise stall the run until autest's process timeout, turning a
+# seconds-long failure into a ten-minute one.
+#
+# The whole body is redirected because the shell announces a signal-killed background job on the
+# script's stderr as it reaps it ("Terminated: 15"), at whatever command happens to be running --
+# redirecting the wait alone does not catch it. That noise would sit in stream.stderr.txt next to
+# this script's real diagnostics, so keep it out and report an escalation on the saved fd instead.
+end_connection() {
+ exec 4>&2
+ {
+ kill -TERM "$1" 2>/dev/null || true
+ waited=0
+ while kill -0 "$1" 2>/dev/null; do
+ if [ "$waited" -ge 30 ]; then
+ echo "pid $1 ignored TERM after 3s; escalating to KILL" >&4
+ kill -KILL "$1" 2>/dev/null || true
+ break
+ fi
+ waited=$((waited + 1))
+ sleep 0.1
+ done
+ wait "$1" || true
+ } 2>/dev/null
+ exec 4>&-
+}
+
+# Give every child still running the same bounded teardown on the way out, including on an early
+# exit from a wait_for timeout or a failed assertion below. A TERM-immune s_client would otherwise
+# outlive the run still holding the inherited FIFO and a live TLS connection into ATS, and leak
+# into the next test in the shard. Each pid is cleared as it is reaped, so neither this trap nor a
+# later step can signal a pid the kernel has since handed to an unrelated process.
+cleanup() {
+ local pid
+
+ for pid in ${holder} ${queued} ${probe}; do
+ end_connection "$pid"
+ done
+}
+trap cleanup EXIT
+
+# 1. Holder: take the single slot.
+${OSSL} <&3 >/dev/null 2>&1 &
+holder=$!
+wait_for 'Reserving a slot, active entities == 1' 1
+
+# 2. Queued connection: the slot is full, so it is parked at the ClientHello hook.
+${OSSL} <&3 >/dev/null 2>&1 &
+queued=$!
+wait_for 'Queueing the VC, we are at capacity' 1
+
+# 3. Let the sweep (every 300ms) run while the slot is still held. This is a lower bound, not a
+# race: a correct sweep leaves the connection parked, which produces no line to wait for,
+# and a slower runner only gives it more sweeps. A sweep that dequeues here is the bug this
+# test pins; step 4 is where that is caught, so there is nothing to wait for now.
+sleep 1
+
+# 4. End the holder. The sweep then reserves the freed slot and resumes the queued connection;
+# ending that connection must release exactly the slot it was granted. The waits key on the
+# release line alone, not its value, so a wrapped counter still lets the probe run and trip
+# the assertion the test guards; the value is checked by the test's traffic.out testers.
+end_connection "$holder"
+holder=""
+wait_for 'Releasing a slot, active entities ==' 1
+wait_for 'Enabling queued VC' 1
+
+# That wait counts resumes, so by itself it is equally satisfied by a resume the sweep emitted
+# back in step 3 while the limiter was still full -- the one event this test exists to reject.
+# Assert the invariant rather than the count: the sweep reserves a slot and then logs the resume
+# from the same continuation, so a legitimate resume always has the sweep's own reservation ahead
+# of it in program order, never subject to which thread logs first. A resume that reserved nothing
+# leaves only the holder's reservation ahead of it, which is what this rejects. Ordering the resume
+# against the holder's release would be a race instead, because free() logs after dropping the
+# lock. It is checked here rather than left to the counter wrap downstream, so a resume that skips
+# the reservation without going on to wrap the counter is still caught, and is named where it
+# happens.
+resume_line=$(grep -n -F -- 'Enabling queued VC' "$traffic_out" | head -n 1 | cut -d: -f1)
+reserved_before=$(head -n "${resume_line:-0}" "$traffic_out" | grep -c -F -- 'Reserving a slot, active entities ==' || true)
+if [ "${reserved_before:-0}" -lt 2 ]; then
+ echo "the sweep resumed the queued connection without reserving a slot for it:" \
+ "${reserved_before:-0} reservation(s) logged before the resume, expected the holder's and the sweep's" >&2
+ exit 1
+fi
-# 4. End the holder, releasing its slot.
-exec 3>&- # close the FIFO write end -> holder sees EOF -> clean TLS close (FIN)
-sleep 2
+# The kill can land before ATS has acted on the reenable, or mid-handshake. Either way the read
+# error closes the VC and the VCONN_CLOSE hook still fires, so the release below is not a race.
+end_connection "$queued"
+queued=""
+wait_for 'Releasing a slot, active entities ==' 2
# 5. Probe: reserve() must succeed against a balanced counter rather than tripping the
-# TSReleaseAssert(_active <= _limit) that a wrapped counter causes.
-run_for 2 sh -c "${OSSL} </dev/null >/dev/null 2>&1"
-sleep 3
+# TSReleaseAssert(_active <= _limit) that a wrapped counter causes. This is the third
+# reservation: holder, sweep, probe.
+${OSSL} <&3 >/dev/null 2>&1 &
+probe=$!
+wait_for 'Reserving a slot, active entities == 1' 3
+end_connection "$probe"
+probe=""
+wait_for 'Releasing a slot, active entities ==' 3
echo "rate_limit-queue-crash-done"