Arm request timeouts on an event loop - #2313
Conversation
A hashed wheel fires on the first tick at or after a deadline, so a deadline near or below the tick duration is rounded up to it, and one timer thread carries every expiry for the whole client. Both hurt short deadlines: a tick is a large fraction of the budget, and a burst of expiries has no headroom to absorb. Measured over 2000 timeouts armed as one burst on Netty 4.2.16, a 20 ms deadline overshot by a mean of 2.7 ms and a p99 of 5 ms on a 5 ms wheel, 1.3/2 ms on a 1 ms wheel, and 0/0 ms scheduled on an event loop, which derives its select timeout from the nearest deadline and so rounds nothing. Add isUseEventLoopTimeouts(), off by default, which arms the request and read timeouts on an event loop instead. On the pooled path the channel is already in hand, so its own loop is used and the timeout expires on the thread that would have to close it. On the connect path there is no channel yet, deliberately, so that the timeout also bounds address resolution and the connect: any loop will do there, since what the wheel costs is a single thread and a rounded-up tick rather than the identity of the thread. Deliberately not a wheel per event loop, which is how the Aerospike client solves this. A wheel arms in O(1) against O(log n) for a deadline queue, but at a few thousand timeouts per loop that is a dozen comparisons, while the quantization it reintroduces costs milliseconds on a 20 ms budget; it also has to be ticked forever, waking every loop even with nothing armed. Aerospike wrote its own wheel because its EventLoop abstracts over NIO, Netty and direct NIO and needed one timer; AHC is Netty-only and gets a per-loop deadline queue for free. Arming allocates nothing beyond what the scheduler needs: the cancellation handle lives on the task, and the existing done flag stands in for the scheduler's already-expired flag, so no per-timeout wrapper is required. Left off by default because the expiry, and therefore whatever the caller chained onto the response future, then runs on an I/O thread. Blocking one stalls every connection it serves. Claude Code on behalf of Pavel Ptashyts Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Review feedback on the commit before this one, which claimed that without a channel any loop would do because what a wheel costs is a single thread and a rounded-up tick rather than the identity of the thread. That was wrong in a way the wheel had been hiding. The loop came from EventLoopGroup#next(), which is almost never the loop the channel ends up on: initAndRegister calls next() again, so for an N loop group the two agreed about one time in N. Every completion then cancelled an entry on a foreign loop, and until the original deadline that entry sat in a queue whose loop it would wake for a request that had long finished; the read timeout re-armed across loops for the same reason. Drawing from the chooser only to pick a timeout thread also advanced the counter that assigns channels to loops, so a fixed number of draws per request could settle registrations onto a subset of them. The loop is now only ever the channel's own. The pooled path has the channel in hand. The connect path arms on the timer, as it did before this branch, because the timeout has to bound address resolution and the connect itself; NettyConnectListener then moves it onto the loop once there is a channel, next to the attachChannel that publishes it on the future. That listener already runs on the channel's loop, so the move costs a same-thread schedule and no wakeup. The holder keeps the switch itself rather than making every caller consult the config, which also spares the listener a dependency on the request sender it does not otherwise need there. Arming has also left the TimeoutsHolder constructor. The task holds the holder and can run the moment it is armed, and an event loop does not round a short deadline up to the next tick, so the expiry could reach a holder whose fields were not yet frozen and a future that had not yet been handed it. On the pooled path it could also reach a future with no channel attached, abort with null, and leave the pooled socket open. The caller now publishes the holder and attaches the channel first and calls start() last. Two smaller races: arm records its handle after scheduling, so an exchange that finished in that window left an entry nobody would ever cancel, cancel() being one shot; arm now re-checks the flag afterwards. And cancelArmed did not catch what arm catches, so a late cancel on a closing client threw RejectedExecutionException out of ListenableFuture#cancel, which had never thrown before. The rest is what the review asked for and worth no argument: two typed handles instead of an Object and instanceof, so a scheduler changing its return type is a compile error rather than a cancellation that silently stops working; requestTimeoutArmed dropped for a null test on the task, which is the shape the code had before; the throws clause off run(Timeout), since the package private constructor makes the subclass it defended against impossible; the rationale in isUseEventLoopTimeouts() alone with the other three copies linking to it; and the new option in the timeouts group everywhere rather than between the two failedIpCooldown entries. Dropping that throws clause is the one thing here revapi objects to, and the only way to keep the dead catch out. It is scoped to the single method: the change is binary compatible, and the only source-level effect would be on code catching a narrower checked exception around a direct run(Timeout) call, which nothing outside the library does and no outside subclass can even reach. The tests asserted on substrings of thread names, which a pool name containing "timer" or a configured thread factory would have broken with no bug present, and only ever exercised the no-channel branch. They now hand the config their own Timer and EventLoopGroup and assert against those: the timer's own thread by identity, and for the event loop cases that the expiry arrived on the loop of the channel the handler was told about. A pooled exchange and a read timeout are covered as well. Claude Code on behalf of Pavel Ptashyts Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
|
Round 1 is addressed; thanks, the two structural ones changed the shape of this for the better. What moved:
Dropping the
|
Review round two. TimeoutsHolder has a public constructor in an exported package, and splitting the arming out of it left an outside caller free to install a holder and get an exchange with no request timeout at all. start() is now called from NettyResponseFuture#setTimeoutsHolder, so installing a holder is what arms it and neither can be done without the other. The ordering that made the split necessary still holds: the holder is reachable from the future before its task can run, and the pooled path attaches the channel before it installs. Implementing Runnable has moved from TimeoutTimerTask down into the two subclasses, which leaves the base class byte identical and drops the revapi entry the previous commit added. Both subclasses already declared run(Timeout) without a throws clause, so within a subclass run() calls its own override and has nothing to catch - the dead handler is gone without narrowing anything. Only the concrete classes are both a TimerTask and a Runnable, so arm() takes that intersection. Three narrower ones, none reachable today and all cheap to close. armedOn kept whichever handle it was given and left the other in place, so a stale timer handle would have masked a live loop handle and left its entry in the queue holding the future until a deadline nobody was waiting for; each now clears the other. cancelIfRaced sat inside the try that guards schedule(), so if cancelArmed ever stopped swallowing a rejection it would have landed in the schedule's handler and re-armed on the timer for a finished exchange; only schedule() is inside the try now. And start() arms with the configured duration rather than the remaining time, as main did: it runs within microseconds of the constructor, and reading a wall clock twice only exposes the deadline to a step between the two reads. The remaining-time arithmetic is left where subtracting elapsed time is the point, on the re-homing path. The tests ran on a group of two loops, which made the wrong loop the right one half the time: a regression to picking any loop would have passed about half the runs. Eight now, and reverting timeoutExecutor to next() fails the pooled case on both runs tried. The pooled case also kept the 200 ms budget while its first request is the cold one -- class loading, the connect, the server's first response -- and is meant to succeed, so it now takes the same second the connecting case needs. Dropped the wait for onConnectionOffer with it: finishUpdate offers to the pool before future.done(), and done() releases the latch the test was already awaiting, so it was a wait for something that had happened. Claude Code on behalf of Pavel Ptashyts Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
|
Round 2 addressed. The revapi hypothesis was right, and so was the two-loop one - thanks for both, they were not obvious from where I was sitting.
|
|
Thanks a lot! |
## Problem `TimeoutsHolder` anchors the request deadline on its own construction: ```java requestTimeoutMillisTime = unpreciseMillisTime() + requestTimeoutInMs; ``` A redirect, a retry and an auth replay all continue the same exchange on the same `NettyResponseFuture`, but each builds a new holder for it. Every hop therefore starts the budget again, so with `maxRedirects=5` a chain can legitimately run for six times the configured `requestTimeout`. Nothing carries an absolute deadline across hops: `NettyResponseFuture#getStart()` exists but is only read for a diagnostic `age` in a log line. The `getRequestTimeout()` javadoc says it is "the maximum time an AsyncHttpClient waits until the response is completed", which is not what happens. ## Change `AsyncHttpClientConfig#isUseAbsoluteRequestDeadline()`, **off by default**, anchors the deadline on when the exchange was submitted instead, so a later hop gets whatever is left of the budget rather than a fresh one. Off by default because turning it on shortens exchanges that rely on the per-attempt behaviour, which is a behaviour change even if the current one contradicts the docs. The `getRequestTimeout()` javadoc now describes what actually happens and points at the flag, so it stops being wrong either way. Settable **per request** as well as per client, following the existing `followRedirect` pattern: a nullable `Boolean` on `Request` that overrides the config value. ```java client.prepareGet(url).setUseAbsoluteRequestDeadline(true).execute(handler); ``` ## Where the flag lives, and why not on the request It is resolved once, in `newNettyResponseFuture`, and kept on the `NettyResponseFuture`. The first attempt kept it only on `Request` and the two override tests failed in opposite directions. `Redirect30xInterceptor` rebuilds the request for the next hop from a hand-picked set of fields, so the override was silently dropped mid-exchange and the config value took over - precisely in the case the setting exists for. Anything carried only on the request has that problem, and every future site that rebuilds a request would have to remember it. Keeping it on the exchange also says the right thing: the deadline describes the exchange, and a redirect target cannot change it, because the budget belongs to the caller. ## Review round 1 Two of the nine were bugs rather than polish, and both are worth reading before the rest: **An attempt the deadline has no time for is no longer sent.** Clamping a spent deadline to zero only delayed the abort: the attempt still took a connection permit, took a connection and wrote the request, and the timeout arrived a tick later - so a 307 put its body on the redirect target while the caller was handed a `TimeoutException` that reads as though nothing had been sent. `scheduleRequestTimeout` now fails the exchange before the write. Every attempt passes through it, first or otherwise, and it is the last point before the request goes out; it returns whether the attempt may go ahead and its four call sites stop when it may not. Disabling that guard while keeping the new test shows the old behaviour was not even a late abort: on a wheel too coarse to expire the exchange in time, it ran both hops and **completed successfully**, the deadline exceeded and nothing reported. The budget is a static on `TimeoutsHolder`, asked of the future rather than of a holder, because a first attempt has no holder to ask - and under `ROUND_ROBIN` the up-front resolve asks for no timeout at all, so a slow resolver could spend the whole budget before one existed. `Long.MAX_VALUE` stands for an exchange that is not bounded as a whole, so a per-attempt timeout needs no special case at any call site. **The anchor is monotonic.** It was `getStart()`, which is `currentTimeMillis`. A per-attempt timeout can only be distorted by a clock step for the length of one hop; an anchor spanning a whole exchange carries the step to every hop after it, so a correction backwards hands a later hop a budget it never had and one forwards aborts it on a healthy connection. The future now records `System.nanoTime()` at submission and the budget is netted off that. Wall clock is left only where main already had it - `requestTimeoutMillisTime` is still recomputed per hop, for the read-timeout comparison. Also from the review: two fields were being dropped by hand-copied lists, which is the same fault this change exists to fix. `Redirect30xInterceptor` rebuilds the next request from a hand-picked set and carried neither the read timeout - reverting a per-request value to the config default on every hop after the first - nor the deadline flag, which left the `Request` disagreeing with what the exchange was being held to. `RequestBuilderBase`'s signature-calculator copy block dropped the read timeout the same way. And the comment justifying the clamp claimed the task still cancels its read-timeout sibling; there is no sibling at that point, the read timeout being armed after the write. ## Behaviour change outside the flag Carrying the read timeout across a redirect applies whether or not anyone turns the deadline on. A caller with a short per-request read timeout and `followRedirect` was getting the config default - 60 s unless configured otherwise - on every hop after the first, and now gets the value they set. That is a fix, but it is a visible one and belongs in the release notes. There is no release notes file in the repo, so it is called out here. ## API compatibility `revapi` passes with no entries. `DefaultRequest` keeps its existing public constructor, and the widened one taking the flag is **package private**: public, it would be pinned by revapi at twenty-seven arguments, the next per-request option would make it twenty-eight, and the two parameter lists would have to be kept in step by hand with a tail that is all reference types for the compiler to confuse. `RequestBuilderBase#build` is the only caller. `Request#getUseAbsoluteRequestDeadline()` is a `default` method returning null, so existing implementations are unaffected. `AsyncHttpClientConfig#isUseAbsoluteRequestDeadline()` returns a literal rather than reading `org.asynchttpclient.useAbsoluteRequestDeadline`, as every other option on that interface does. The javadoc now says so, so that an implementation setting the property and getting nothing is documented rather than surprising. ## Tests `AbsoluteRequestDeadlineTest` runs two hops of 400 ms against a 600 ms budget, so each hop fits on its own and the pair does not. Six cases: * default: both hops run and the exchange ends on the second (per-attempt behaviour preserved) * config on: the chain times out * config off + request override on: times out * config on + request override off: ends on the second hop * config on, single hop: completes, so the first hop is not handed a shortened budget * config on, first hop answering after the budget is gone: the second hop is never sent The cases that pass assert the final 200 and which hop it came from, not merely that nothing was thrown - a dropped `Location` header or `followRedirect` turned off would satisfy that having run a single hop. The last case pins its client to a wheel too coarse to expire anything, which is the only way to land reliably in the window where the deadline has passed and the timeout has not yet run; it was checked by mutation rather than by assumption. `TimeoutsHolderTest` covers the anchor and the clamp without a wall clock. Given no timer and no request sender, a holder computes its deadline and arms nothing, so what a second holder makes of the same exchange is the whole of the difference between the two modes: the anchor holding across hops, a per-attempt timeout starting a fresh budget, a spent deadline reporting itself as passed, and a per-attempt exchange never reporting that however long it has run. `AsyncHttpClientDefaultsTest` asserts this default and the property that sets it, along with the event-loop one merged alongside, which had the same gap. Timing-based, so `@RepeatedIfExceptionsTest`, matching the neighbouring timeout tests. ## Verification `mvnw clean verify` - BUILD SUCCESS, 1485 tests, 0 failures, 0 errors, 26 skipped. Error Prone, NullAway and Revapi all clean. Caveat on the testing gate: `AGENTS.md` requires the build to run on JDK 11 and no JDK 11 is installed on this machine, so it was run on **JDK 17** (also in the CI matrix). The JDK 11 leg of CI on this PR is the real gate. ## Relationship to #2313 Resolved: #2313 merged first and `main` is merged in here. A merge rather than a rebase, since the branch is published and `AGENTS.md` rules out force-pushing a shared one. The conflict was the four lines of the `TimeoutsHolder` constructor both changes touch, plus the two config methods landing in the same place. `start()` now arms with the remaining budget when the deadline is absolute and with the configured duration when it is per attempt, which is what #2313 left it doing. ## Noticed while running the suite Two timing tests are flaky under load and unrelated to this change, mentioned only so a red run is not mistaken for this PR: * `SemaphoreTest.checkAcquireTime` (three methods) allow 400 ms for a 100 ms timeout and use `@RepeatedTest(10)`, which does not retry, unlike the `checkRelease` tests beside them. This failed one cell of thirteen on #2313's CI (macOS, JDK 21) at 420 ms. * `NettyRequestThrottleTimeoutTest.testRequestTimeout` takes ~31 s against a 30 s latch even on an idle machine, and releases its throttle permit only from `onThrowable`, so a single request completing instead of timing out deadlocks the remaining threads. Happy to send a separate PR for both. Claude Code on behalf of @pavel-ptashyts 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
Problem
Request and read timeouts are armed on the client's
HashedWheelTimer. That has twoproperties that only show up on short deadlines:
deadline near or below
hashedWheelTimerTickDurationis rounded up to it.HashedWheelTimer'sdefault
taskExecutorisImmediateExecutor, so each expiry runs inline on the wheelthread - including
future.completeExceptionally(...)and therefore whatever the callerchained onto the response future.
On a one-second budget the first costs 0.3% and nobody notices. On a budget of tens of
milliseconds a tick is a large fraction of it, and a burst of expiries has no headroom to
absorb before the wheel starts running late.
Measured
2000 timeouts armed as one burst on Netty 4.2.16, JDK 17, tasks doing nothing but
recording their own lag. This is the floor; real work on the firing thread only adds to it.
EventLoop.scheduleEventLoop.scheduleAn event loop shows zero overshoot because it schedules by deadline and derives its own
select()timeout from the nearest one. There is no quantum to round to.This was a throwaway probe rather than JMH -
client/src/jmh/javais not currently wiredinto the build, so its benchmarks do not compile. Happy to add a proper benchmark if that
is fixed first, or as part of this.
Change
AsyncHttpClientConfig#isUseEventLoopTimeouts(), off by default, arms the request andread timeouts on an event loop instead of the timer.
its loop is used and the timeout expires on the thread that would have to close it. On the
connect path there is no channel yet - deliberately, so that the timeout also bounds
address resolution and the connect - so it is armed on the timer and moved onto the loop
once the connect succeeds. No other loop is ever used; see the review round below for why
that matters.
in a wrapper, and the existing
doneflag stands in for the scheduler's already-expiredflag, which the two schedulers spell differently.
isShuttingDown()can return false andschedulerejectimmediately after. Netty answers a rejected timeout with a logged warning rather than an
exception, which would leave the exchange with nothing to end it, so a rejection falls
back to the timer.
Off by default because the expiry - and so whatever the caller chained onto the future -
then runs on an I/O thread, and blocking one stalls every connection it serves. The javadoc
says so and points callers at
handleAsync.Why not a wheel per event loop
That is how the Aerospike client solves the same problem:
EventLoopBaseowns aHashedWheelTimerthat is aRunnablethe loop ticks itself. Deliberately not copied here.A wheel arms in O(1) against O(log n) for a deadline queue, but at a few thousand timeouts
per loop that is a dozen comparisons, while the quantization it reintroduces costs
milliseconds on a 20 ms budget - the third row above is the whole point. A wheel also has to
be ticked forever, waking every loop even with nothing armed. Aerospike wrote its own because
its
EventLoopabstracts over NIO, Netty and direct NIO and needed one timer; AHC isNetty-only and gets a per-loop deadline queue for free.
Review round 1
Most of the substance of this PR changed in review, so the sections above describe the
current shape rather than what was first pushed. Two things are worth calling out here
because they were design errors, not polish:
The loop is now only ever the channel's own. It used to come from
EventLoopGroup#next(), which is almost never the loop the channel ends up on:initAndRegisterdraws from the same chooser, so the two agreed about one time in N. Everycompletion then cancelled an entry on a foreign loop, and until the original deadline that
entry sat in a queue whose loop it would wake for a request that had long finished. Drawing
from the chooser also shifted which loops connections land on. The pooled path has the
channel in hand; the connect path arms on the timer, as before this branch, and
NettyConnectListenermoves the timeouts onto the loop once the connect succeeds, next tothe
attachChannelthat publishes it on the future. That listener already runs on thechannel's loop, so the move costs a same-thread schedule and no wakeup.
Arming left the
TimeoutsHolderconstructor. The task holds the holder and can run themoment it is armed, and an event loop does not round a short deadline up to a tick, so the
expiry could reach a holder whose fields were not yet frozen, a future that had not been
handed the holder, and on the pooled path a future with no channel attached - which aborted
with
nulland left the pooled socket open. The caller now publishes the holder, attachesthe channel, and calls
start()last.Also from the review:
armre-checkscancelledafter recording its handle, so an exchangethat finishes mid-arming cannot leave behind an entry nobody will cancel;
cancelArmedcatches the
RejectedExecutionExceptionthat Netty's off-loop cancellation path can raise ona closing client, which had never escaped
ListenableFuture#cancelbefore; the cancellationhandle is two typed fields rather than an
Objectandinstanceof;requestTimeoutArmedisgone in favour of a null test on the task; the rationale lives on
isUseEventLoopTimeouts()alone; and the new option sits in the// timeoutsgroupeverywhere rather than splitting the two
failedIpCooldownentries.API compatibility
No
revapientries.implements Runnableandrun()live on the two subclasses rather thanon
TimeoutTimerTask, which leaves that class's surface unchanged: both subclasses alreadydeclared
run(Timeout)without a throws clause, so inside a subclassrun()calls its ownoverride and has nothing to catch. No dead handler, and nothing narrowed.
The knock-on is that only the concrete classes are both a
TimerTaskand aRunnable, soTimeoutsHolder#armtakes that intersection as a type parameter. Everything else isadditive: the existing
TimeoutsHolderconstructor is kept and delegates, and nothing isremoved.
start()is called fromNettyResponseFuture#setTimeoutsHolderrather than by the sender.TimeoutsHolderhas a public constructor in an exported package, and splitting the armingout of it would otherwise leave an outside caller free to install a holder and get an
exchange with no request timeout at all.
Tests
Four cases in
EventLoopTimeoutTest, asserting where an expiry is delivered from rather thanwhat it does. They hand the config their own
TimerandEventLoopGroupso the assertionsare against those objects and not against thread names, which a pool name containing
timeror a configured thread factory would have broken with no bug present:
onTcpConnectSuccessreported;onConnectionPooledreported,which is also what says it reused the connection rather than opening one of its own;
exercises a different arming path.
The group has eight loops. With two, a timeout armed on the wrong loop is on the right one
half the time, and these assertions would have passed about half the runs against the bug they
exist to catch; at eight, reverting
timeoutExecutortonext()fails the pooled case.The connecting case, and the pooled case's first request, get a one second budget on purpose.
A deadline reached before connecting would be delivered from the timer quite correctly, there
being no channel to deliver it from, and would prove nothing either way; and the pooled case's
first request is the cold one - class loading, the connect, the server's first response - and
is meant to succeed.
One gap, called out rather than papered over: the
RejectedExecutionExceptionfallback inarmhas no test. Reaching it needs a loop that answersisShuttingDown()withfalseandthen rejects the schedule, and the executor comes from the channel, so there is no way in
through the config. A test double for
EventExecutorwould do it if that is acceptable.Verification
mvnw clean verify- BUILD SUCCESS, 1468 tests, 0 failures, 0 errors, 21 skipped. ErrorProne, NullAway clean;
revapiclean with the one scoped entry above.Caveat on the testing gate:
AGENTS.mdrequires the build to run on JDK 11 and no JDK 11 isinstalled on this machine, so it was run on JDK 17 (also in the CI matrix). The JDK 11
leg of CI on this PR is the real gate.
Claude Code on behalf of @pavel-ptashyts
🤖 Generated with Claude Code