Skip to content

fix(homeassistant): surface question reply failures and trace the reply lifecycle - #54

Merged
pedropombeiro merged 2 commits into
mainfrom
fix/question-reply-observability
Aug 18, 2026
Merged

pedropombeiro merged 2 commits into
mainfrom
fix/question-reply-observability

Conversation

@pedropombeiro

Copy link
Copy Markdown
Owner

Summary

Fixes the silent failure path that made the 0.7.1 work-laptop bug undiagnosable, and preserves the receiver on the raw post call.

The unbound-method hypothesis was disproven

Tested against a real opencode process. The generated client builds post as a closure, not a this-dependent method:

const makeMethod = (method) => {
  const fn = (options) => request({ ...options, method });   // closes over `request`
  ...
};
return { post: makeMethod("POST"), ... };

A probe plugin inside a live opencode server called the unbound post and got status=200, no error, and the agent resumed. So the extraction was not the root cause.

The receiver-preserving call is applied anyway — depending on closure-vs-method is fragile, and a mock cannot detect the difference.

Why the root cause is still unknown, and what this PR does about it

The reported timeline shows the helper cleared 5.003s after being written, which is HA's backstop, not the plugin. That points at a failure before the HTTP reply. The empty .catch(() => {}) made every one of those causes look identical.

Rather than guess again, this PR makes each cause name itself. These are now distinguishable in the log:

Outcome Example
poll never started already polling, not starting a second poll
HA config unavailable Home Assistant config unavailable (haApiUrl, haToken or ${ENV_VAR} expansion missing), not polling
entity unreadable cannot read entity input_text.… from Home Assistant
response never observed timed out after 60000ms (23 polls, 0 responses for other requests, 0 failed reads)
request ID mismatch observed a response for a different request (kind=question, requestID=que_OTHER)
poll canceled poll canceled after 1 polls (answered elsewhere)
invalid index response present but option index is not a valid index
out-of-range index option index 99 is out of range (2 options offered)
reply failed reply threw: boom / reply rejected: {…} / reply returned HTTP 404
reply succeeded reply accepted (HTTP 200)

Design notes:

  • Uses client.app.log — no console, so the repo's no-console rule holds.
  • Progress is debug, only real faults are error, so a healthy setup stays quiet.
  • Helper values are summarised as kind + request ID, never logged verbatim, so arbitrary entity content stays out of logs.
  • Reporting is best-effort and never rejects; a logging outage cannot break the plugin.
  • pollForResponse returns an explicit outcome (no-config / canceled / timeout / result) instead of undefined.

Verification

Real opencode, production timing — question waits 44s, HA writes the response, an independent backstop clears the helper 5s later:

20:51:09.631 WEBHOOK waiting reason=question id=que_016a46c91001LPdjkZHvPp1CUe
20:51:53.663 HA WROTE RESPONSE (t+44000ms) -> question:que_016a46c91001LPdjkZHvPp1CUe:1
20:51:54.132 PLUGIN CLEARED after 474ms (beat backstop by 4526ms)
helper cleared by: PLUGIN   |   pending questions: 0   |   ASSISTANT: Beta

Full lifecycle from the real opencode log:

DEBUG que_016a…: answerQuestion started, 3 options offered
DEBUG que_016a…: poll started, entity=input_text.opencode_permission_response, timeout=60000ms
DEBUG que_016a…: matched question response after 23 polls
DEBUG que_016a…: option index 1 resolved to a label
DEBUG que_016a…: sending reply
INFO  replied requestID=que_016a… answers="[[\"Beta\"]]"
DEBUG que_016a…: reply accepted (HTTP 200)

Also verified:

  • All 9 failure modes produce unique, distinguishable logs (unit harness).
  • A receiver-requiring mock passes with the fix and fails against 0.7.1's unbound call, so the test discriminates.
  • Negative paths: rejection, sync throw, HTTP 404, HTTP 500, error field, out-of-range — all observable.
  • Calling convention confirmed: {url, path, body}, path interpolated, application/json, colons/emoji in labels intact.
  • Out-of-range index surfaced in a real opencode log: level=ERROR message="question que_…: option index 99 out of range".

mise run typecheck, lint, build all pass.

Note on the work laptop

I could not reproduce the failure locally, including at 44s with the backstop race. The next step is to run this build there: the log will state whether the poll started, whether the response was seen, or whether the reply failed. My earlier class.Work double-notification theory was wrong, as the two webhook targets have separate consumers.

The question reply swallowed every failure with an empty catch, so a
failed reply was indistinguishable from a successful one. Any error now
goes to the opencode log via client.app.log, covering rejections, thrown
errors, a set error field, and non-2xx status codes, as well as an option
index that falls outside the offered options.

The raw post method is also no longer extracted from its owner. It is
called as rawClient.post(...) so the receiver is preserved. The generated
client builds post as a closure rather than a this-dependent method, so
the previous unbound call did work, but relying on that is fragile and a
mock cannot detect the difference.

Reply failures remain non-fatal: reporting is best effort and never
rejects, so a logging outage cannot break the plugin.
A failed remote answer was indistinguishable from a successful one, so
diagnosis relied on guessing which step broke. Every stage of the reply
now reports to the opencode log: poll start, config resolution, matched
or foreign responses, cancellation, timeout, index resolution and the
reply request itself.

These outcomes are now distinguishable in the log: poll never started,
Home Assistant config unavailable, entity unreadable, response never
observed, response for a different request, poll canceled, timed out,
invalid index, out-of-range index, reply failed and reply succeeded.

Progress goes to debug and only real faults to error, so a working setup
stays quiet. Observed helper values are summarised as kind plus request
ID rather than logged verbatim, keeping arbitrary entity content out of
logs. pollForResponse now returns an explicit outcome instead of
undefined so callers can tell these cases apart.
@pedropombeiro
pedropombeiro merged commit 5594e6a into main Aug 18, 2026
2 checks passed
@pedropombeiro
pedropombeiro deleted the fix/question-reply-observability branch August 18, 2026 20:55
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant