Evaluate Retriever Lookup Timeout Budget
TL;DR - The timeout of a shepherd->retriever lookup call currently does not
include the time it takes to make the initial /asyncquery call. It starts after* that.
But that call can take a non-negligible amount of time in some cases.
Additionally, the timeout for a Shepherd query is passed along to Retriever unchanged,
If Retriever takes it literally and approaches meeting it, there's potentially no room
for its callback to reach Shepherd before Shepherd stops waiting for it.
We should discuss what the total timeout should include and whether it should be different
for Retriever and Shepherd.
Lookup timeout budget: ACK wait is additive, not bounded by the client's timeout, and handed to Retriever with no margin
Follow-up to the PR #154 that stops lookup workers from deleting callback ids on
ReadTimeout ("Keep callback ids for lookups that time out waiting for the
ACK"). That PR fixes the callback-rejection bug and makes the ACK timeout
configurable, but deliberately leaves the surrounding timeout semantics as
they were. Reviewing them turned up the following. All apply to both
workers/aragorn_lookup/worker.py and workers/bte_lookup/worker.py.
1. The lookup deadline clock starts after submission
start_time = time.time() is taken after the asyncio.gather of
submissions returns, so the client's parameters.timeout bounds only the
callback wait. The ACK phase is additive on top of it.
Worst case with defaults is now kg_retrieval_submit_timeout (100) +
lookup_timeout (210) = 310s, which exceeds the 300s query_timeout_sec
whole-query budget. That's not a crash (the budget is checked at hop pickup,
so the next stage just hands the query to finish_query), but it means
parameters.timeout doesn't mean what a client would assume.
Proposed: take start_time before the submission block, so a slow ACK
eats into the callback wait rather than adding to it.
2. The ACK timeout isn't capped by the client's timeout
If kg_retrieval_submit_timeout is set larger than a client's
parameters.timeout, a hung ACK holds the worker for the full setting
before the callback wait even begins.
Proposed: submit_timeout = min(settings.kg_retrieval_submit_timeout, parameters["timeout"]). Never wait longer for the ACK than for the answer.
3. Retriever receives the same timeout we wait for
parameters.timeout is forwarded unchanged in every expanded message, so
Retriever's budget and Shepherd's wait are the same number (210s by default).
There is no margin for Retriever to finish, serialize, and POST the callback.
A Retriever that uses its whole budget delivers results after
cleanup_callbacks has deleted the rows, and the callback is rejected with
500 — the same symptom the parent PR fixed for the ACK case.
Doing (1) makes this slightly worse: Shepherd's deadline moves from a hair
after Retriever's to a hair before.
Needs verifying: does Retriever actually honor parameters.timeout? If
so, send it timeout - margin (something like 15s) and keep waiting for the
full timeout.
4. Three different default timeouts
| Where |
Default |
Lookup wait (settings.lookup_timeout) |
210s |
Whole-query budget (settings.query_timeout_sec) |
300s |
Sync /query poll (base_routes.py, hard-coded) |
360s |
The ordering is right (lookup < budget < poll) but the sync poll's extra 60s
over the budget is dead wait, and the 360 literal isn't a setting.
Proposed: derive the sync poll default from query_timeout_sec, or at
least make it a setting alongside the other two.
5. parameters.timeout: null crashes the lookup worker
The request body is an untyped dict (no schema validation), so an explicit
"timeout": null reaches the worker. parameters.get("timeout", settings.lookup_timeout) returns None for an explicit null, and the
deadline arithmetic then raises TypeError. task_deadline.query_budget
already tolerates this input (and has tests for None and non-numeric
strings), so the workers should too.
Same line exists in five workers: aragorn_lookup, bte_lookup,
example_lookup, aragorn_pathfinder, arax_pathfinder.
Proposed: parameters.get("timeout") or settings.lookup_timeout in all
five (treats 0/null/missing as "use the default").
Suggested order
(5) is a one-liner and independent. (1) + (2) go together and are small.
(3) depends on an answer about Retriever. (4) is cleanup.
Evaluate Retriever Lookup Timeout Budget
TL;DR - The timeout of a shepherd->retriever lookup call currently does not
include the time it takes to make the initial /asyncquery call. It starts after* that.
But that call can take a non-negligible amount of time in some cases.
Additionally, the timeout for a Shepherd query is passed along to Retriever unchanged,
If Retriever takes it literally and approaches meeting it, there's potentially no room
for its callback to reach Shepherd before Shepherd stops waiting for it.
We should discuss what the total timeout should include and whether it should be different
for Retriever and Shepherd.
Lookup timeout budget: ACK wait is additive, not bounded by the client's timeout, and handed to Retriever with no margin
Follow-up to the PR #154 that stops lookup workers from deleting callback ids on
ReadTimeout("Keep callback ids for lookups that time out waiting for theACK"). That PR fixes the callback-rejection bug and makes the ACK timeout
configurable, but deliberately leaves the surrounding timeout semantics as
they were. Reviewing them turned up the following. All apply to both
workers/aragorn_lookup/worker.pyandworkers/bte_lookup/worker.py.1. The lookup deadline clock starts after submission
start_time = time.time()is taken after theasyncio.gatherofsubmissions returns, so the client's
parameters.timeoutbounds only thecallback wait. The ACK phase is additive on top of it.
Worst case with defaults is now
kg_retrieval_submit_timeout(100) +lookup_timeout(210) = 310s, which exceeds the 300squery_timeout_secwhole-query budget. That's not a crash (the budget is checked at hop pickup,
so the next stage just hands the query to
finish_query), but it meansparameters.timeoutdoesn't mean what a client would assume.Proposed: take
start_timebefore the submission block, so a slow ACKeats into the callback wait rather than adding to it.
2. The ACK timeout isn't capped by the client's timeout
If
kg_retrieval_submit_timeoutis set larger than a client'sparameters.timeout, a hung ACK holds the worker for the full settingbefore the callback wait even begins.
Proposed:
submit_timeout = min(settings.kg_retrieval_submit_timeout, parameters["timeout"]). Never wait longer for the ACK than for the answer.3. Retriever receives the same timeout we wait for
parameters.timeoutis forwarded unchanged in every expanded message, soRetriever's budget and Shepherd's wait are the same number (210s by default).
There is no margin for Retriever to finish, serialize, and POST the callback.
A Retriever that uses its whole budget delivers results after
cleanup_callbackshas deleted the rows, and the callback is rejected with500 — the same symptom the parent PR fixed for the ACK case.
Doing (1) makes this slightly worse: Shepherd's deadline moves from a hair
after Retriever's to a hair before.
Needs verifying: does Retriever actually honor
parameters.timeout? Ifso, send it
timeout - margin(something like 15s) and keep waiting for thefull
timeout.4. Three different default timeouts
settings.lookup_timeout)settings.query_timeout_sec)/querypoll (base_routes.py, hard-coded)The ordering is right (lookup < budget < poll) but the sync poll's extra 60s
over the budget is dead wait, and the 360 literal isn't a setting.
Proposed: derive the sync poll default from
query_timeout_sec, or atleast make it a setting alongside the other two.
5.
parameters.timeout: nullcrashes the lookup workerThe request body is an untyped
dict(no schema validation), so an explicit"timeout": nullreaches the worker.parameters.get("timeout", settings.lookup_timeout)returnsNonefor an explicit null, and thedeadline arithmetic then raises
TypeError.task_deadline.query_budgetalready tolerates this input (and has tests for
Noneand non-numericstrings), so the workers should too.
Same line exists in five workers:
aragorn_lookup,bte_lookup,example_lookup,aragorn_pathfinder,arax_pathfinder.Proposed:
parameters.get("timeout") or settings.lookup_timeoutin allfive (treats
0/null/missing as "use the default").Suggested order
(5) is a one-liner and independent. (1) + (2) go together and are small.
(3) depends on an answer about Retriever. (4) is cleanup.