bryancall commented on code in PR #13681:
URL: https://github.com/apache/trafficserver/pull/13681#discussion_r4017847457
##########
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. Before 508c1bea26 the sweep resumed a queued
connection
+while the limiter was still full: the holder's close then landed the
active-slot counter on
+zero, the resumed connection's close released a slot it never held and wrapped
the counter
+below zero, and the next reserve() tripped a release assertion that aborted
the server. ATS
+must survive the queue churn without the counter wrapping.
Review Comment:
Done in 5a5b7eb21b. The docstring now states the accounting invariant and its
failure mode in the present tense, with no commit reference.
##########
tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh:
##########
@@ -20,59 +20,182 @@
# 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.
+# Against the plugin before 508c1bea26 the sweep resumed the queued connection
in step 3 without
+# a reservation. Step 4 asserts that reservation and fails there, naming the
defect itself. Left
+# to run, that same resume aborts the server: 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). The test's traffic.out
testers reject that
+# wrap and that abort however they arise, and stay the backstop for both.
Review Comment:
Done in 5a5b7eb21b. Dropped the commit reference here, and also the "do not
reintroduce a closes-while-parked step" aside, which was really describing an
older shape of the test rather than anything a reader needs. What is left is
the
invariant and why the close-while-queued branch cannot be driven from a
client.
##########
tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh:
##########
@@ -20,59 +20,182 @@
# 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.
+# Against the plugin before 508c1bea26 the sweep resumed the queued connection
in step 3 without
+# a reservation. Step 4 asserts that reservation and fails there, naming the
defect itself. Left
+# to run, that same resume aborts the server: 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). 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; do not reintroduce a "closes while parked" step, it only ever
resolved to the
+# resume-then-close path this script now drives deterministically.
+#
+# Every step waits for the plugin's own debug line in traffic.out rather than
sleeping for a
+# guessed interval: on a loaded runner a fixed sleep let the second connection
miss the holder
+# entirely, so the queue path was silently never exercised (#13679). Every
connection reads
Review Comment:
Agreed on the principle, and applied it across both files in 5a5b7eb21b: no
commit SHAs, no issue numbers, and nothing about how the test used to behave.
That paragraph now says only why the steps key on the plugin's own debug
lines
instead of sleeps, and why each connection's open and close is taken out of
s_client's hands.
The change is comments only -- stripping comments from the shell script
leaves it
byte-identical to the previous commit, and the test.py AST outside the
docstring
is unchanged. Still passes on Linux and macOS.
##########
tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh:
##########
@@ -20,59 +20,158 @@
# 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.
+# Against the plugin before 508c1bea26 this aborts the server: the sweep
resumed the queued
+# connection in step 3 without a reservation, so the holder's close in step 4
landed the counter
+# on zero and the resumed connection's close, releasing a slot it never held,
wrapped the counter
+# below zero; the probe's reserve() then tripped TSReleaseAssert(_active <=
_limit). The test
+# asserts no release wraps and no signal is logged, so it pins that fix.
#
-# 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; do not reintroduce a "closes while parked" step, it only ever
resolved to the
+# resume-then-close path this script now drives deterministically.
+#
+# Every step waits for the plugin's own debug line in traffic.out rather than
sleeping for a
+# guessed interval: on a loaded runner a fixed sleep let the second connection
miss the holder
+# entirely, so the queue path was silently never exercised (#13679). 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"
-OSSL="openssl s_client -connect ${host}:${port} -servername ${sni} -quiet
-no_ign_eof"
+# Ceiling per step. It only bounds a broken run; a healthy one moves on as
soon as the line
+# appears.
+WAIT_LIMIT=30
-# 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
- ) &
+holder=""
+queued=""
+probe=""
+
+cleanup() {
+ kill -TERM ${holder:-} ${queued:-} ${probe:-} 2>/dev/null || true
}
+trap cleanup EXIT
-# 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>&-
+}
+
+# 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.
+sleep 1
+
+# A resume here means the sweep dequeued while the limiter was still full,
which is the bug this
+# test pins. Only report it: the run must continue so the wrapped counter and
the abort still
+# reach the test's traffic.out assertions, but naming the first wrong event
keeps it from being
+# buried behind the probe's timeout 30s later.
+resumed=$(grep -c -F -- 'Enabling queued VC' "$traffic_out" 2>/dev/null ||
true)
+if [ "${resumed:-0}" -ne 0 ]; then
+ echo "the sweep resumed the queued connection while the limiter was still
full" >&2
+fi
Review Comment:
Fixed in 9e106d6a11. The absolute count did make that wait vacuous: a resume
emitted during the full-slot interval satisfied `wait_for 'Enabling queued
VC' 1`
on its own.
I did not use a before/after count, because the obvious ordering check is
racy.
Comparing the resume against the holder's `Releasing a slot` would flake:
`free()` logs *after* dropping `_active_lock`, so the sweep can reserve,
resume
and log in the gap between the decrement and the release's own `Dbg`, and a
correct build would log the resume first.
The test now asserts the sweep's own reservation ahead of the resume. The
sweep
reserves a slot and then logs the resume from the same continuation, so
those two
lines are in program order rather than thread-scheduling order -- both are
`ET_TASK 0`:
```
7: [ET_NET 7] Reserving a slot, active entities == 1 <- holder
9: [ET_NET 8] Queueing the VC, we are at capacity
10: [ET_NET 7] Releasing a slot, active entities == 0
11: [ET_TASK 0] Reserving a slot, active entities == 1 <- sweep
12: [ET_TASK 0] Enabling queued VC after 1293ms
```
With the one-line revert of 508c1bea26 the sweep resumes without reserving,
so
only the holder's reservation is above the resume:
```
7: [ET_NET 7] Reserving a slot, active entities == 1
9: [ET_NET 8] Queueing the VC, we are at capacity
10: [ET_TASK 0] Enabling queued VC after 114ms <- no reservation
```
This also made the unfixed-build failure far faster and more legible. It took
30.6s before, because the client burned its whole `WAIT_LIMIT` waiting for a
third reservation that could never arrive -- ATS had already aborted. It now
fails in 1.5s, naming the cause:
```
the sweep resumed the queued connection without reserving a slot for it:
1 reservation(s) logged before the resume, expected the holder's and the
sweep's
```
The `traffic.out` testers are unchanged and stay hard, and the counter-wrap
tester still fires on the unfixed build, since the EXIT trap closes the
resumed
connection. Verified on Linux and macOS: 8/8 clean and 8/8 under CPU load on
each, and the revert fails on both.
--
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]
