test: give the redis counter poll five seconds instead of one - #13892
Open
nic-6443 wants to merge 2 commits into
Open
test: give the redis counter poll five seconds instead of one#13892nic-6443 wants to merge 2 commits into
nic-6443 wants to merge 2 commits into
Conversation
wait_counters_above() polled 100 times at 10ms, so it gave up after one second. That single second has to cover the whole asynchronous path from "client has the response" to "counter is visible in redis", which is not always enough on a loaded CI runner.
An iteration count only bounds the sleeps. Every pass also does a full sum_counters() round trip, so the effective ceiling grows with redis latency -- exactly when the wait matters. Use a five second deadline.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
注册 for free
to join this conversation on GitHub.
Already have an account?
登录 to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Description
t/lib/test_redis.lua'swait_counters_above()gave up after about one second, and one second is not always enough for the counter it waits on to show up. This bounds the wait by a five second deadline instead.Some context on why the wait exists at all, since that is where the flakiness comes from.
ai-rate-limitingcommits token usage in itslogphase, which APISIX runs fromlog_by_lua_block— after the response has already gone out to the client. Cosockets are not available there, solimit-count-redis'slog_phase_incoming()defers the actual write withngx.timer.at(0, ...). That means when the test client holds request N's response, the counter for N is still unwritten: the log phase has to run, the zero-delay timer has to be picked up by the event loop, and the redis roundtrip has to complete. Fire request N+1 immediately and its access phase reads a budget that still looks unspent — which is the off-by-one-request symptom these tests used to show, wrong status codes andX-AI-RateLimit-Remainingvalues lagging by one request.wait_counters_above()bridges that gap: snapshot withsum_counters()before the request, then poll until the total grows.The flaky part is the ceiling on that poll, not the logic. 100 iterations of
ngx.sleep(0.01)is about one second of wall clock, and that second has to cover all three hops above plus the poller's ownKEYS+GETagainst the same redis. On a loaded runner — parallel jobs sharing one redis container, a worker that doesn't get scheduled promptly — the write is still in flight when the poll runs out, so the helper returns an error and the caller'sassertfails even though the counter lands a moment later. Nothing about it is deterministic, which is why it turns up on PRs that touch nothing in this area.I bumped the ceiling to five seconds, but as a wall-clock deadline rather than a bigger iteration count. An iteration count bounds only the sleeps: each pass also does a full
sum_counters()round trip, so the real ceiling stretches with redis latency — precisely the condition the wait exists to absorb. At 100ms per poll, 500 iterations would run for the better part of a minute while the comment above it claimed five seconds. A deadline says what it means.The loop still returns as soon as the counter moves, so a healthy run costs exactly what it did before.
The only caller today is
t/plugin/ai-rate-limiting.tTEST 37.Checklist
This is a test-only change to a test helper, so no new tests or documentation.