Skip to content

fix(updater): thread job_id, relay child breadcrumbs, drop dead cosign_skipped - #1935

Open
thinmintdev wants to merge 2 commits into
mainfrom
fix/updater-journal-breadcrumbs
Open

fix(updater): thread job_id, relay child breadcrumbs, drop dead cosign_skipped#1935
thinmintdev wants to merge 2 commits into
mainfrom
fix/updater-journal-breadcrumbs

Conversation

@thinmintdev

Copy link
Copy Markdown
Contributor

⚠️ SELF-UPDATE PATH — operator review required, no automerge

Refs #1901

Summary

Fixes the three observability gaps named in #1901 (found by rc-validate v1.0.0-rc.6, update-audit-trail-gaps). Verification logic itself is untouched — this is journal/logging only.

  1. job_id=None on every updater.* journal line. The three background job runners (_run_apply_job, _run_prepare_job, _run_commit_job) constructed Updater(channel=channel) without the job_id the constructor already accepts and threads through to every log call. Now: Updater(channel=channel, job_id=job_id).
  2. No prepare/verify breadcrumb reaches the journal on success. The routed hal0-update stage/activate/discard child pins its structured log to stderr so stdout carries only the result envelope. UpdateSeam._invoke only folded that stderr into the raised error on failure — on success it was captured by subprocess.run and silently discarded, so sha256_ok/cosign_verify_ok/prepare_ok/etc. never reached the journal on a successful run. Added _relay_child_log, which replays each captured stderr line into the parent's own structured log (tagged with verb + job_id) once _invoke sees a zero return code.
  3. cosign_skipped is a dead job field. stage_release() never emits it, and cosign verification has no bypass (_verify_cosign's own docstring: "Verification is always mandatory — there is no bypass"), so the field always read null. Removed the producer-less consumer rather than inventing a fake producer.

Explicitly out of scope (hard fences from the wave planner)

  • version:null on a prepare job — that's the operator's pin, paired with resolved_version. Not touched.
  • Absence of digest fields on the job record while the cached manifest exists. Not touched.
  • Sha256 / cosign verification logic. Not touched — read-only investigation confirmed the cached manifest is written only after both checks pass (stage_release, steps 3–6 then cache write), consistent with the issue's own note. No new finding to escalate.

Test plan

  • make lint
  • uv run ruff format --check src tests
  • env -u FORCE_COLOR HAL0_HOME=$(mktemp -d) uv run --extra dev pytest tests/updater tests/api/test_updater_routes.py -q — 328 passed
  • New/updated tests:
    • test_job_runners_thread_job_id_into_updater (parametrized apply/prepare/commit) — regression for gap 1
    • test_successful_stage_relays_the_childs_breadcrumbs_into_the_journal + test_failed_stage_does_not_double_relay_stderr_as_breadcrumbs — regression for gap 2
    • test_prepare_job_never_reports_cosign_skipped — regression for gap 3

…n_skipped

Three observability gaps in the updater's job/log correlation (#1901),
found by rc-validate v1.0.0-rc.6:

- The three background job runners (_run_apply_job, _run_prepare_job,
  _run_commit_job) built Updater(channel=channel) without the job_id the
  constructor already accepts, so every parent-side updater.* journal
  line logged job_id=None regardless of which job produced it.
- The routed hal0-update stage/activate/discard child pins its
  structured log to stderr so stdout carries only the result envelope;
  the parent only folded that stderr into the raised error on failure,
  so no sha256_ok/cosign_verify_ok/prepare_ok breadcrumb ever reached
  the journal on a successful run. UpdateSeam._invoke now replays each
  captured stderr line into the parent's own log on success.
- cosign_skipped was a job field with no producer (stage_release never
  emits it, and cosign verification has no bypass), so it always read
  null. Removed rather than given a fake producer.

Verification logic itself is untouched — this is journal/logging only.

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: f71dcbca1a

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

Comment thread src/hal0/updater/privileged.py Outdated
"seam_bin": self._seam_bin,
},
)
_relay_child_log(stderr, verb=parts[0], job_id=self._job_id)

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 Badge Relay the full successful child log

On hosts with several stale quarantine or staging directories, a successful extraction emits one cleanup log line per directory after the SHA-256 and cosign events. _invoke() truncates stderr to its final 4,000 characters before passing it here, so those cleanup lines can push the verification breadcrumbs out of the relayed data and leave the audit gap this change is intended to close. Keep a full stderr value for successful replay (or stream it), while retaining a bounded tail only for error details.

Useful? React with 👍 / 👎.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed in b979d82 — _invoke() now only truncates stderr to the last 4000 chars on the error-details path; the success-path relay (_relay_child_log) sees the full, untruncated stderr, so a long cleanup-line tail can no longer push the sha256/cosign breadcrumbs out. Added test_successful_stage_relay_survives_a_long_cleanup_tail as a regression.

Codex review on #1935 (P2): _invoke() truncated stderr to its last 4000
chars before deciding what to relay, so a successful extraction that
logs one cleanup line per stale quarantine/staging directory after the
sha256/cosign breadcrumbs could push those breadcrumbs out of the
relayed data — reopening the exact audit gap the previous commit closed.
Truncation now only applies to the bounded error-details path; the
success-path relay sees the full stderr.
@thinmintdev

Copy link
Copy Markdown
Contributor Author

Independent review — approve, 0 blocking

Reviewed as an outside pair of eyes (I did not write this), with extra scrutiny because this sits next to the sha256/cosign verification path. Everything below was executed, not read off the diff.

Hard fences — respected

git diff 4234801d..b979d820 touches exactly 4 files and never touches src/hal0/updater/updater.py — the sha256/cosign verification logic, the manifest write ordering, version:null on prepare jobs, and the digest-field absence are all untouched. The only production-behaviour changes are (a) the job_id= kwarg on three Updater(...) constructions, (b) one _relay_child_log call on the rc==0 path, (c) full_stderr computed before the truncation, (d) one deleted job["cosign_skipped"] assignment.

Gap 1 — job_id threading

Updater(channel=channel, job_id=job_id) in _run_apply_job / _run_prepare_job / _run_commit_job; Updater.__init__ already stored it and _seam() already forwards it to UpdateSeam(job_id=...). The two remaining bare Updater(channel=channel) sites (rollback_update L918, set_channel's validation check() L987) are not job-backed — no id exists to thread. Correct scope.

updater.swap_ok (updater.py:3674) is emitted inside the Updater class, i.e. in the hal0-api process — so this is exactly the line the issue's repro observed as job_id=None. Fix hits the reported symptom.

Gap 2 — success-path relay

Confirmed the mechanism: _pin_logs_to_stderr (privileged.py:373) pins the child's structlog to stderr, subprocess.run(capture_output=True) captures it, and before this PR the rc==0 branch dropped it on the floor. Relay is placed after the rc!=0 raise and before _parse_result, so it only fires on success.

Gap 3 — cosign_skipped removal is the right call, not a missing producer

_verify_cosign (updater.py:850-863) states verification is always mandatory — there is no bypass, and stage_release never emits the key. There is no state the field could ever legitimately report, so inventing a producer would be inventing a bypass-shaped field next to a no-bypass guarantee. Post-removal grep -rn cosign_skipped over the whole tree returns hits only in tests/ and tests/release-validation/ — no CLI, UI, docs or schema consumer is orphaned.

Self-caught truncation bug (b979d82)

Verified the asymmetry is real and intentional: the relay sees full_stderr, the raised error keeps full_stderr[-4000:], _parse_result keeps the bounded tail. Without the fix a long post-verification cleanup tail (_reap_stale_quarantines / _reap_stale_staging_dirs, one line per stale dir) evicts the sha256_ok / cosign_verify_ok breadcrumbs from the relayed window.

Relay safety

  • Log injection: contained. Each child line is a value of line= on a fixed updater.privileged_child_log event, and structlog's ConsoleRenderer repr()s it. Empirically: a child line cosign fake job_id=forged event=updater.swap_ok renders as ... job_id=real line='cosign fake job_id=forged event=updater.swap_ok' verb=stage — the forged pairs stay inside quotes, the real job_id is a separate key, and event= cannot be displaced. splitlines() also means an embedded newline becomes its own tagged relay line rather than a forged journal record; a literal \n inside one line is repr-escaped. No forgery path found.
  • Memory: the full stderr is already resident from capture_output=True; splitlines() roughly doubles it transiently. Bounded in practice by the child's own log volume (a handful of breadcrumbs + one line per stale dir).

No double-relay on failure

Confirmed by code order and by reverting: on rc!=0 the raise precedes the relay, so stderr is recorded once (in details).

Revert-and-confirm-red (all four)

Revert Result
Updater(channel=channel, job_id=job_id) → drop job_id test_job_runners_thread_job_id_into_updater3 failed (apply/prepare/commit)
delete the _relay_child_log(...) call test_successful_stage_relays_the_childs_breadcrumbs_into_the_journal + the long-tail test — 2 failed
relay full_stderr[-4000:] (the first-pass code) test_successful_stage_relay_survives_a_long_cleanup_tail1 failed, other two pass. The regression test genuinely pins commit 2.
re-add job["cosign_skipped"] = ... test_prepare_job_never_reports_cosign_skipped1 failed

Full suite on the head commit: 329 passed (tests/updater tests/api/test_updater_routes.py, HAL0_HOME=$(mktemp -d), FORCE_COLOR unset). ruff format --check and ruff check clean; PR checks green.

Non-blocking findings

  1. The failure path still has the truncation hazard the success path just lost. On rc!=0 nothing is relayed and only full_stderr[-4000:] reaches details. A failure after cosign passed (e.g. during activate) with a long cleanup/error tail loses the sha256_ok / cosign_verify_ok evidence entirely — which is the run where you most want to know what was verified before things went sideways. test_failed_stage_does_not_double_relay_stderr_as_breadcrumbs cements the asymmetry. Consider relaying the full stderr on the failure path too (journal) while keeping the bounded tail in details (error envelope) — those are different sinks, so it isn't a true double-record. Follow-up, not a blocker for updater: job_id=None on every updater.* journal line, no prepare/verify breadcrumbs on success, cosign_skipped has no producer #1901's stated scope.

  2. Routed path: the child still logs job_id=None inside the relayed text. On a real box hal0-api runs as the hal0 service user, so stage/activate go through the sudo seam and the child is not told the job id (_seam_argv passes only verb/channel/version). The parent's relay event carries the real job_id, but the child's own breadcrumbs inside line='...' still read job_id=None — the issue's own repro grep will still report job_id=None hits. I'd not fix this here (extending the argv means touching the sudoers-pinned wrapper contract for an observability nicety), but it's worth a line in the issue close-out so the next validator doesn't re-file it.

  3. Informational: one log.info per child line and no cap. Realistic volume is small; only a pathological run (>10k lines/30s) would meet journald's default rate limit, at which point relayed lines could be dropped. Not worth guarding today, but a head+tail cap would be the shape if it ever bites — a plain "first N lines" cap would reintroduce the bug commit 2 fixed in mirror image.

Verdict: approve. The three gaps map cleanly onto the issue's constructs, the fences are intact, the self-caught truncation bug is genuinely pinned by its regression test, and the relay has no injection or double-record path I could construct.

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