Repository navigation
fix(server): log the status an error response sends - #1117
Conversation
A write the server cannot settle answers 500 `outcome_unknown`, whatever code its cause maps to. `ApiError::status()` returned the cause code's first status, so the containment logs, which read it, recorded the cause's status: a query execution failure inside an owned write logged 400 while the client received 500. `status()` is now the status the response sends. It judges the error's facts through `answered_code`, the one place a code becomes `outcome_unknown`, and both the response builder and the logs read it; `status_of`, the second mapping, is gone. The facts must be final where a log reads them. The engine-failure warning in `from_omni` first takes its request's record of a submitted write, and an owned write runs with that record set, so an error it translates is judged as following it. The write's error is marked as one the owned write returned before the containment log reads it, rather than when the waiter takes it.
|
I would merge this. There are no blocking findings. There is one optional finding. WhyA write the server cannot settle answers HTTP 500 with code The affected class is every uncertain engine failure whose own code has a first status other than 500, once the write fact is present. What
The two log sites read
The HTTP status and the error body stay the same. The two log lines change. Tradeoff and liabilityThe response and the logs now share one status rule.
Further log lines should call this This branch is based on Open PR 1096 edits the same two log sites and the same section of OptionalThe warning still runs inside ValidationA Before: parent Failed. The response status was 500. The warning line was After: head The same test, plus
The log test, repeated 10 times with CI on this commit is green, including Test Workspace, Lint (clippy), Format (rustfmt), and the GQT jobs. I did not re-run those suites locally. I did not execute every HTTP route. The read-path |
What & why
The review of #1078 found that the server's containment logs record the wrong status:
The code is on main through #1076. This PR makes both log lines record the status the client receives. The status comes from the method the response is built from, so a log line and its response cannot disagree.
Backing issue / RFC
None of the three applies. This is a follow-up to a finding in the #1078 review, which said a follow-up could fix it. No issue tracks it, so the test names carry no
issue_N.How
ApiError::status()now returns the status the response sends. It reads the error's disposition and gets the answered code from the newanswered_code. That method is now the only place where a code becomesoutcome_unknown;into_judged_outputcalls it too. The status comes from that code, or from thebranch_start_refusalreason when the code isbranch_start_refusal. This is the same rule asErrorOutput::http_status.IntoResponseadds the request's facts first, then takes the response status fromerror.status(), then builds the body.status_of, the second status mapping, is removed.from_omniapplieswith_request_facts()before its warning. This is the same merge thatinto_outputandspawn_readalready do, and it only ever sets the flag to true, so no response changes.OperationRuntime::submitruns the owned write with the request'sSUBMITTED_WRITErecord set to true, so an error translated inside the write is judged as one that follows the write. The write's error is now markedafter_owned_writeinside the owned task, before the containment log reads it. Before, the mark was added when the waiter took the error.OwnedResponse::resultstill marks its own "result was lost" error.status():redact_blob_api_errorandlog_blob_transport_internalinhandlers.rs(the== INTERNAL_SERVER_ERRORchecks) andRefusal::resource_errorinmcp.rsserve BlobGET/HEADand MCP resource reads. Those are reads. Their request never submits an owned write, and their errors never cross the owned-write boundary, so the code is never rewritten tooutcome_unknownand the old status was already the sent status. They are correct as they are. They now use the same method as the response, so a later change cannot split them apart.No HTTP response, body or disposition changes; only the two log lines change.
The storage-failures page also said an unsettled write answers
outcome_unknown"on MCP"; since #1076 HTTP answers it too, and the sentence now says so.Checklist
docs/user/operations/storage-failures.mdnow says both lines record the status the response sends;changelog.d/containment-logs-record-the-sent-status.fixed.mdTests
api_error_tests::the_answered_code_fixes_the_status_and_retry_after(extended): every row now also checks thaterror.status()before conversion equals the status of the response.api_error_tests::an_uncertain_engine_failure_logs_the_status_its_response_sends(new): aDataFusionfailure in three contexts, with the server's log subscriber captured for each:The test first triggers both log sites once. tracing caches whether a log site is enabled the first time it is hit. While at most one dispatcher exists, it asks only the default of the thread that hits the site. A concurrent test that hits the site with no subscriber installed then caches it as never enabled, and the capture sees nothing; this happened in the first run. A capture installed after the sites are registered rebuilds that cache.
Before the fix (fix hunks reverted, tests kept;
cargo test -p omnigraph-server --lib --locked -- api_error_tests:: operations::):After:
36 passed; 0 failed.Local verification
RUST_MIN_STACK=16777216 cargo test -p omnigraph-server --lib --locked: 214 passed, 2 ignored (run three times, all green)RUST_MIN_STACK=16777216 cargo test -p omnigraph-server --tests --locked: lib 214,boot_settings43 (1 ignored),integration274,multi_graph8, all passcargo clippy -p omnigraph-server --all-targets --locked -- -D warnings -W clippy::dbg_macro: cleancargo fmt --all --check,python3 scripts/check-docs.py,typoson the changed files: cleanNotes for reviewers
The
outcome_unknownrewrite used to run once for the body and once more, throughErrorOutput::http_status, for the response status. Nowanswered_codedecides it, and the body's code and the response's status both come from that decision.