Skip to content

Pace the rate_limit SNI queue test on the plugin's own log lines - #13681

Merged
bryancall merged 3 commits into
apache:masterfrom
bryancall:fix-flaky-rate-limit-sni-queue
Sep 15, 2026
Merged

bryancall merged 3 commits into
apache:masterfrom
bryancall:fix-flaky-rate-limit-sni-queue

Conversation

@bryancall

@bryancall bryancall commented Sep 15, 2026

Copy link
Copy Markdown
Contributor

Fixes: #13679

Problem

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. The only positive
assertion was ContainsExpression('Queueing the VC'), which does not say which
connection queued, so two separate failure modes hid behind it.

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 508c1be and re-running confirmed it: the old
test passes against the unfixed plugin on macOS.
It has not been guarding
anything on that platform.

Changes

  • Paced on the plugin's own output: every step in
    rate_limit_sni_queue_client.sh waits for the plugin's debug line in
    traffic.out instead of sleeping, with a 30s per-step ceiling that fails loudly
    and dumps the log tail.
  • Connection lifetime taken away from s_client: every connection reads 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 with a bounded TERM/KILL/wait.
  • Resume ordering asserted directly: the script counts the reservations logged
    ahead of the first Enabling queued VC and fails if the sweep's own reservation
    is not among them, naming the defect where it happens rather than waiting for the
    counter wrap downstream.
  • Queue path can no longer be skipped silently: the test adds
    ContainsExpression('Enabling queued VC') (the sweep really resumed it),
    ExcludesExpression('Rejecting connection') (the holder really released), and
    ExcludesExpression(r'Releasing a slot, active entities == [0-9]{4,}') (no wrap).
    The existing ExcludesExpression('_active <= _limit|received signal') is
    unchanged and still hard.
  • EXIT trap on every child: a TERM-immune s_client can no longer outlive the
    run holding the inherited FIFO and a live TLS connection into ATS, and leak into
    the next test in the shard.
  • Comments say what the test does, not what it used to do: the historical
    commentary and per-change commit citations are gone; the accounting invariant is
    stated in the present tense.

Approach

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.

The release assertion matches only a wrapped value, not any non-zero one, because
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 — it reads 4294967295, never a
small number. For the same reason the resume is ordered against the sweep's own
reservation (same-thread program order) rather than against the holder's release,
which would be a race.

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.

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.

Testing

Both platforms ran byte-identical files (md5 checked). Oracle = revert the
508c1be 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 test choreographed its setup with wall-clock sleeps, so on a loaded
runner the holder could fail to hold the single slot, nothing queued,
and the run failed on its own precondition rather than on the behaviour
under test. The same guesswork let it pass without exercising anything:
on macOS the holder never released, so the resume and release paths
never ran and the test passed against the unfixed plugin.

Every step now waits for the plugin's debug line instead of sleeping,
and every connection is held open on a FIFO and ended by signal, so
neither platform's s_client EOF behaviour matters. The test also
asserts the sweep resumed the queued connection and that no release
wraps the counter, so the queue path cannot be silently skipped.

Fixes: apache#13679
Copilot AI lite review requested due to automatic review settings September 15, 2026 02:39
@bryancall bryancall self-assigned this Sep 15, 2026
@bryancall bryancall added this to the 11.0.0 milestone Sep 15, 2026
@bryancall
bryancall requested review from bneradt and zwoop September 15, 2026 02:40

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

Two moderate issues remain in event-order validation and child-process cleanup.

Get a fresh assessment by requesting another Copilot review.

Pull request overview

Updates the rate_limit SNI queue test to synchronize with plugin logs and control TLS client lifetimes deterministically.

Changes:

  • Replaces timing races with log-driven waits and bounded diagnostics.
  • Uses FIFO-backed connections and PID-based teardown.
  • Adds queue-resumption, rejection, and counter-wrap assertions.
File summaries
File Summary
tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue.test.py Passes the traffic log path and adds stronger queue-path assertions.
tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh Implements deterministic queue choreography; moderate issues remain with early-resume enforcement and failure cleanup.
Review details

Suppressed comments (1)

tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh:70

  • On a timeout or other early failure, the EXIT trap only sends TERM and returns without waiting or escalating. This script explicitly treats a TERM-immune s_client as possible in end_connection, so a stuck child can survive the test while retaining the inherited FIFO/TLS connection and leave resources in ATS for subsequent tests. Reuse the bounded TERM/KILL-and-wait cleanup for every non-empty child PID.
cleanup() {
  kill -TERM ${holder:-} ${queued:-} ${probe:-} 2>/dev/null || true
}
  • Files reviewed: 2/2 changed files
  • Comments generated: 1
  • Review effort level: Lite

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh Outdated
The post-release wait counted resumes with an absolute count, so a
sweep that resumed while the limiter was still full satisfied it with
the very event the test rejects. Assert the sweep's own reservation
ahead of the resume instead -- same-thread program order rather than a
race against the holder's release -- and give the EXIT trap the
bounded TERM/KILL/wait that end_connection already uses, so a
TERM-immune s_client cannot outlive the run.
Copilot AI review requested due to automatic review settings September 15, 2026 04:22

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔵 Needs a closer look

Preserve stderr before redirecting it so forced process termination diagnostics remain available.

Review details

Suppressed comments (1)

tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh:110

  • exec 4>&2 runs inside the { ... } 2>/dev/null group, so fd 4 is duplicated from /dev/null, not the original stderr. If s_client ignores TERM and the KILL escalation is needed, the diagnostic promised by the comment is silently discarded, making this failure mode harder to diagnose. Save fd 4 before redirecting stderr (or order the group redirections as 4>&2 2>/dev/null).
  exec 4>&2
  • Files reviewed: 2/2 changed files
  • Comments generated: 0 new
  • Review effort level: Lite

Comment thread tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue.test.py Outdated
Comment thread tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh Outdated
Comment thread tests/gold_tests/pluginTest/rate_limit/rate_limit_sni_queue_client.sh Outdated

@bneradt bneradt left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed 9e106d6. No additional actionable findings beyond the existing inline requests to remove historical commentary.

The reservation-before-resume check agrees with the plugin's execution order: reserve() logs under the active-slot lock, and the sweep logs the resume after that call returns. The release check appropriately allows concurrent reservation to affect the logged counter value.

Validation: Bash syntax and Python parsing passed. A temporary mock client exercised the shell helper's expected sequence (exit 0), resume without a reservation (exit 1), and early resume while the holder remains active (exit 1). These checks exercise shell control flow only; I did not run the ATS/TLS AuTest because this checkout has no configured build.

The comments described how the test used to be wrong and cited the
commit and issue behind each change, which is noise for someone reading
the test today and is recoverable from blame anyway. Keep what the test
does and why it does it that way, and state the accounting invariant in
the present tense.
Copilot AI review requested due to automatic review settings September 15, 2026 16:19
@bryancall

Copy link
Copy Markdown
Contributor Author

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 9e106d6. 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:

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.

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The supplied review assessments identify no blocking issues.

Review details
  • Files reviewed: 2/2 changed files
  • Comments generated: 0 new
  • Review effort level: Lite

@bryancall
bryancall requested a review from bneradt September 15, 2026 18:20

@bneradt bneradt left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed 5a5b7eb. The historical commentary concerns are addressed. Verified that the shell executable lines are unchanged and the Python AST is unchanged apart from the module docstring. No new actionable findings; all 14 reported CI checks pass, including all four AuTest shards.

@bryancall
bryancall merged commit 804e5e2 into apache:master Sep 15, 2026
14 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

rate_limit_sni_queue AuTest is flaky: the queue precondition races a TLS handshake on a 0.3s timer

3 participants