You are viewing a plain text version of this content. The canonical link for it is here.
Posted to github@trafficserver.apache.org by "bryancall (via GitHub)" <gi...@apache.org> on 2026/09/15 02:39:13 UTC
[PR] Pace the rate_limit SNI queue test on the plugin's own log lines [trafficserver]
bryancall opened a new pull request, #13681:
URL: https://github.com/apache/trafficserver/pull/13681
Fixes #13679.
`rate_limit_sni_queue` choreographed its setup with wall-clock sleeps racing live
TLS handshakes. That made it fail intermittently on loaded CI runners, and, less
obviously, let it pass without exercising the queue at all.
## What was actually wrong
The only positive assertion was `ContainsExpression('Queueing the VC')`, which does
not say *which* connection queued. Two separate failure modes hid behind that:
**On Linux, under load, the holder never holds.** Reproduced on a 32-core Fedora 44
box with 96 busy loops, 4 of 8 runs failed with exactly the CI signature:
```
Reserving a slot, active entities == 1
Releasing a slot, active entities == 0 <- holder gone 6ms after connecting
Reserving a slot, active entities == 1
Releasing a slot, active entities == 0
```
No `Queueing the VC` anywhere. The second connection found the slot free and was
served rather than queued, so the precondition failed while every other assertion
passed and ATS stayed healthy.
**On macOS, the holder never releases, and the guard was inert.** LibreSSL's
`s_client` does not exit on the FIFO EOF the script used to end the holder, so the
run went:
```
Reserving a slot == 1 (holder)
Queueing the VC (second connection)
Rejecting connection, we're at capacity and queue is full (probe)
```
No `Releasing`, no `Enabling queued VC`. The resume and release paths never ran.
Reverting the one-line fix from 508c1bea26 and re-running confirmed it: **the old
test passes against the unfixed plugin on macOS.** It has not been guarding
anything on that platform.
## The change
Every step now waits for the plugin's own debug line in `traffic.out` instead of
sleeping, with a 30s ceiling that fails loudly and dumps the log tail. Every
connection takes stdin from a FIFO the parent holds open read-write on fd 3 and
inherits via `<&3`, so nothing depends on how `s_client` reacts to EOF, and each is
ended by signalling openssl's own PID. The one remaining `sleep` is a deliberate
lower bound that lets the 300ms sweep tick while the slot is held; a correct sweep
emits nothing to wait on, and a slower runner only gives it more ticks.
Assertions added so the queue path cannot be skipped silently:
- `ContainsExpression('Enabling queued VC')` - the sweep really resumed it
- `ExcludesExpression('Rejecting connection')` - the holder really released
- `ExcludesExpression(r'Releasing a slot, active entities == [0-9]{4,}')` - no wrap
The existing `ExcludesExpression('_active <= _limit|received signal')` is unchanged
and still hard.
Note the release assertion matches only a wrapped value, not any non-zero one:
`Limiter::free()` logs `_active` after dropping the lock, so a concurrent `reserve()`
can legitimately make a release read back as 1. An unmatched decrement of a `uint32`
at limit 1 is unmistakable regardless.
## Scope note
The header now says explicitly that a client cannot close a connection parked in the
ClientHello hook, so the "closes while parked" step the old script appeared to
perform never did anything. ATS does not read the socket while the hook is invoked,
so the FIN sits in the kernel until the sweep reenables the VC. Measured on both
platforms: no release for the full 2s a connection sat parked and killed, with the
release appearing only after `Enabling queued VC`. The old 0.3s kill therefore always
resolved to the same resume-then-close path this script now drives deterministically.
## Verification
Both platforms ran byte-identical files (md5 checked). Oracle = revert the
508c1bea26 one-liner in `sni_selector.cc`, rebuild `rate_limit.so`, reinstall, rerun.
| Check | macOS 15 arm64, LibreSSL 3.3.6, 14 cores | Fedora 44, OpenSSL 3.5.8, 32 cores |
| --- | --- | --- |
| Fixed, idle | 3/3 pass, 4s (was 25s) | 5/5 pass, 4-5s |
| Fixed, under load | 8/8 (42 hogs) | 8/8 (96 hogs), 6/6 (64 hogs) |
| Original, idle | pass | pass |
| Original, under load | 8/8 pass (does not flake here) | **4/8 fail** |
| Original vs unfixed plugin | **passes - guard inert** | n/a |
| Fixed vs unfixed plugin | **fails** | **fails** |
The oracle run on both platforms:
```
Enabling queued VC after 153ms <- resumed with no reservation
Releasing a slot, active entities == 0
Releasing a slot, active entities == 4294967295
Fatal: limiter.h:262: failed assertion `_active <= _limit`
traffic_server: received signal 6
```
The two platforms failed the old test for opposite reasons, which is why the fix
removes the dependency on `s_client` lifetime behaviour entirely rather than tuning
a timeout.
--
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: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Pace the rate_limit SNI queue test on the plugin's own log lines [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on code in PR #13681:
URL: https://github.com/apache/trafficserver/pull/13681#discussion_r4017585538
##########
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:
See...this history is not going to be helpful to the user reading this. A summary of what it does is OK, but most importantly is a description of why it does something if it is non-obvious. Describing how it used to do something wrong earlier is going to be noise that is not helpful here to the user.
##########
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:
Same comment as above - and it looks like the original here had git commit history in it.
##########
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:
Let's clean up the comment to not have the github history in it - if people are interested they can find this PR with a blame.
--
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: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Pace the rate_limit SNI queue test on the plugin's own log lines [trafficserver]
Posted by "Copilot (via GitHub)" <gi...@apache.org>.
Copilot commented on code in PR #13681:
URL: https://github.com/apache/trafficserver/pull/13681#discussion_r4011438468
##########
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:
This branch only prints a diagnostic and continues, so an `Enabling queued VC` emitted during the preceding full-slot interval is still counted by the later `wait_for` at line 162. The test therefore does not enforce the ordering it claims to verify: a regression that resumes while the limiter is full can pass this precondition as long as it avoids the specific counter wrap. Make an early resume fail the client (or otherwise compare the event count before and after the holder release) instead of merely reporting it.
--
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: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Pace the rate_limit SNI queue test on the plugin's own log lines [trafficserver]
Posted by "bryancall (via GitHub)" <gi...@apache.org>.
bryancall commented on PR #13681:
URL: https://github.com/apache/trafficserver/pull/13681#issuecomment-5683953814
Two points from the automated reviews that came through as suppressed comments,
so there was no thread to answer in place.
**EXIT trap not escalating** -- fixed in 9e106d6a11. `cleanup` now reuses
`end_connection` for every non-empty child pid, so the bounded TERM -> poll
`kill -0` -> KILL -> `wait` applies on an early exit from a `wait_for` timeout or
a failed assertion, not only on the deliberate teardowns. Each pid is cleared as
it is reaped, so neither the trap nor a later step can signal a pid the kernel
has since recycled. Verified with a TERM-immune child:
```
pid 7224 ignored TERM after 3s; escalating to KILL
```
**`exec 4>&2` supposedly capturing /dev/null** -- this one is not a defect, and
no change was made. `exec 4>&2` is outside the `{ ... } 2>/dev/null` group, not
inside it, so fd 4 duplicates the real stderr and the group's redirection only
applies to fd 2 within the group. Reduced:
```bash
probe() {
exec 4>&2
{ echo "MSG-VIA-FD4" >&4
echo "MSG-VIA-FD2" >&2
} 2>/dev/null
exec 4>&-
}
probe
```
With stderr sent to a file, the file contains `MSG-VIA-FD4` and not
`MSG-VIA-FD2`: fd 4 reaches real stderr, fd 2 is discarded, which is the whole
point of saving it. The escalation diagnostic above was produced the same way,
with the script's own `end_connection` and `2>` redirected to a file, so the
diagnostic the comment promises does arrive.
--
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: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Pace the rate_limit SNI queue test on the plugin's own log lines [trafficserver]
Posted by "bryancall (via GitHub)" <gi...@apache.org>.
bryancall merged PR #13681:
URL: https://github.com/apache/trafficserver/pull/13681
--
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: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Pace the rate_limit SNI queue test on the plugin's own log lines [trafficserver]
Posted by "bryancall (via GitHub)" <gi...@apache.org>.
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: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org