fix(container-runtime): report RPC failures by ErrorKind, and log them to the service - #3640
fix(container-runtime): report RPC failures by ErrorKind, and log them to the service#3640helix-nine wants to merge 2 commits into
Conversation
|
rebase this. also "Javascript Engine Error" is a legacy error code from when we had an embedded deno runtime. You can replace this error code with a "Service Runtime Error". |
031a61b to
d3538d3
Compare
…m to the service The runtime sent `code: 0` / `code: 1` with `message: typeof error` — the string "object" — on its two catch-all error paths, and a third path in `getResult` put free error text in `message` with no `data` at all. StartOS reads `code` as a `start-core` ErrorKind and takes its text from `data.details`, so every runtime failure arrived as `Unknown Error`, and the `getResult` text survived only through the `message` fallback. Each path now sends the ErrorKind its failure actually is and the fixed label for that code, with the text in `data.details`, matching the two sites in this file that already answered `-32601` / `-32602` that way. `handleRpc`'s catch also never printed the exception. A package's log stream is this container's own journal, so a service whose `main` threw went silent in `Logs` at the moment it failed while the actor retried every ten seconds — the exception reached only the host journal. It is now logged next to the procedure that raised it. RPCSpec.md gains the error object it never documented.
The name dates from the embedded Deno runtime. Both of its call sites run a package's own bundled `index.js`, and it is now also what a container-runtime procedure failure reports, so "Service Runtime Error" is what it names. Discriminant 59 is unchanged — it is the wire value the container runtime and older clients send.
d3538d3 to
27763f4
Compare
|
Rebased onto Renamed the kind rather than adding one — Split into its own commit so the rename reads separately from the RPC fix. Verified: The two questions from the description are still open whenever you get to them: whether the Embassy-v1 |
Alternative to #3613, which @dr-bonez rejected on the grounds that a JSON-RPC
messageshould be stable and enumerable — which is why the text lives indata.details. He is right, and the situation is a bit worse than "wrong fix": on the two paths #3613 patches, the OS cannot readmessageat all.What the protocol actually is
From<Error> for RpcError(error.rs:512) sendscode: kind as i32andmessage: kind.as_str()— an i18n lookup.From<RpcError> for Error(:529) readscodeback into anErrorKindand takes the text fromdata.details, falling back tomessageonly whendatais absent (ErrorData::from(&RpcError),:474-489).start_core::Errorhas nomessagefield for it to land in. Socodeis the machine key,messageis that key's fixed label,data.detailsis the text.RpcListener.tsalready answers that way twice —-32601Method not foundand-32602invalid params, both withdata.details. Three other sites don't.Why #3613 changes nothing
Both paths it patches always populate
data.details, somessageis discarded before every human-facing sink:Display for Erroris"{kind.as_str()}: {details}";statusInfo.errorstores anErrorData, which has nomessagefield; the UI card renderserror?.details;start-cliprints the OS's own message plusdetails. The text was already arriving. What was lost is the category.What is actually broken
code.0is not anErrorKindvariant (the enum starts at 1) and1isUnknown, so every container-runtime failure renders asUnknown Error: <text>even though a real variant for it exists at 59 and is translated into all five locales.getResult(:450-461) — untouched by #3613, and the one site that genuinely does what @dr-bonez is objecting to: it puts free text inmessageand sends nodata, so the Rust fallback lifts it intodetails. That is the path every action,getInputandcreateBackuptakes. It also forwarded an Embassy-v1 package-definederror-codestraight intocode, where the OS reads it as anErrorKind— a v1 package returning7would have been reported asIncorrect Password.handleRpc's catch never printed anything. This is the operator-visible half, and it is what #3613 was reaching for. A package's log stream is this container's own journal —PersistentContainer::newbind-mounts the log dir to/var/log/journal/<machine_id>,LogSource::Packagereads it withjournalctl -u container-runtime.service -D …(logs.rs:628), andpipe-wraprelays node's stderr into it, which is whyInitializing...shows up inpackage logstoday. So when a package'smainrejected, the runtime serialised the exception to the socket and dropped it,service_actor.rs:75sent it to the host journal vialog_err(), and the service's own log went quiet at the exact moment it died while the actor retried every 10s. Oneconsole.errorputs it in the log the operator is already reading.This PR
errorKindtable;messageis selected from it, never computed.handleRpc→ServiceRuntime(59).mapError→InvalidRequest(38): a malformed line or a dispatch failure is a different class from "we called into the service's code and it threw", and the OS has a variant for each.ErrorKind::Javascript→ServiceRuntime("Service Runtime Error") per @dr-bonez — the old name dates from the embedded Deno runtime. Discriminant 59 is unchanged, since it is the wire value. Its two existing call sites inpack.rsboth run a package's own bundledindex.js, so the new name fits them too.getResultmoves its text todata.details, gainsdebug, and stops forwarding the v1error-codeas anErrorKind. The OS gets the samedetailsstring it got before.handleRpclogs the exception with the procedure that raised it, using the idiom already atRpcListener.ts:244.RPCSpec.mddocuments the error object, which it never did — the enumeration written down is the durable half of this.Notes
Two things worth a decision rather than my assumption:
error-codepassthrough.SystemForEmbassy(index.ts:174,178) throws{ error, code }, wherecodeis the package's own number. Feeding it into anErrorKindslot is the bug above, but if you want it preserved it should go somewhere the OS won't misread —data.info, or appended todetails.SYNC_RETRY_COOLDOWN_SECONDSis a flat 10s with no cap, so a service that fails to start now writes a stack into its journal every 10s indefinitely. That is the same rate it already floods the host journal at, but it is an argument for taking the backoff /statusInfo.errorhalf of A package whose main rejects restart-loops silently: the error reaches neither the service log nor statusInfo.error #3614 in the same release rather than after it.The rest of #3614 — routing the transition error into
statusInfo.error, bounding the retry, discharging the// TODO: ideally this error should be sent to service logs— is Rust-side and stays open.Credit to @JesseMarkowitz, who found this and wrote #3613; happy to close this in favour of that branch if he'd rather carry it.
Changelog: entry added under the existing
## [0.4.0.2], which has no origin tag (latest isstart-os/v0.4.0.1), so no new heading and no version module.Verification
cargo check -p start-core— cleanmake container-runtime-test— 2 suites, 12 tests, 6 snapshots, passnpm --prefix projects/start-os/container-runtime run check— cleanprettier --checkon the touched TS/markdown,rustfmt --checkon the touched Rust — cleanErrorKind::ServiceRuntime.as_str()resolves in all five locales and that the discriminant is still 59 — passed, then removed