Skip to content

feat(daemon): expose the unmount abort outcome in telemetry - #6

Open
mengmengmengqiang wants to merge 2 commits into
mainfrom
feat/unmount-observability
Open

mengmengmengqiang wants to merge 2 commits into
mainfrom
feat/unmount-observability

Conversation

@mengmengmengqiang

@mengmengmengqiang mengmengmengqiang commented Oct 28, 2026 •

Copy link
Copy Markdown
Collaborator

What and why

Issue #2 asks for the aborted normal unmount to be visible: a structured daemon warning and structured custody/abort facts in the SDK trace line, including the success path — an abort-on-Join success currently reports only Unmounted.

Upstream Ephemeral-AI-Lab#500 (already merged) reworked Ephemeral-AI-Lab#496 with exact abort custody: a normal unmount whose drain stops at Join makes the connection's one abort write and completes with Unmounted; a short or failed write, a second stall, or a later Revoke/Close stop keeps the exact custody in TeardownCustody.forced. Those facts were visible only to a caller that read the receipt or the failure custody, never to the trace line.

This PR attaches the same facts to the reply as a daemon unmount observation, inside the already existing Reply::Observed { reply, telemetry } envelope, on success and on a retained stop. It adds no wire field, no reply record, no custody or stalled-unmount behaviour change, no retry, no second abort or detach, and no dependency.

Base: main at 35d3657 (the Ephemeral-AI-Lab#500 merge). Builds on the telemetry envelope that Ephemeral-AI-Lab#500 merged, and changes no part of its custody correction. The same commit is the head of fork PR #6.

CI lane routing

The SDK-side target layerfs-api::unmount_observability mounts a real Workspace, so it needs root, /dev/fuse and CAP_SYS_ADMIN. It is now one of the named SDK mount targets in tools/ci_tests.py: the fast lane neither builds nor selects it, and the nightly mount lane runs it in its own container with /dev/fuse and SYS_ADMIN. Before that registration the fast lane ran it as a non-root runner, the daemon exited before printing LAYERFS_DAEMON_LISTEN, and the test panicked there (Ephemeral-AI-Lab#501 run 40781324309). When that line is still missing, start now panics with the daemon's stderr instead of an opaque unwrap, and a Drop guard removes the fixture directory on every exit.

Telemetry key set

A traced Unmount that took the abort path carries a nested unmount map (stable keys, in this order):

key meaning
stage Join (the stalled drain was ended by the abort), Abort (the one write was short or failed), or Revoke/Close when a later step stopped with the abort recorded
abort Written, Short or Failed
bytes the count of a Short write only
errno the original errno of a Failed write only (e.g. EIO)
detached kernel detach was already known when the abort was made
loops_exited, loops_joined receive loops exited and joined at that stop or completion
active, retained request owner counts at the same observation
waited_ms milliseconds from the start of the connection drain to the end of the abort path

The daemon also writes one LAYERFS_DAEMON_UNMOUNT_ABORT workspace=… namespace=… stage=… abort=… [bytes=|errno=] detached=… loops_exited=… loops_joined=… active=… retained=… waited_ms=… stderr line when that path ends, traced or not. It is one diagnostic line per abort, never per-request logging. The line's stage is the abort path's own (Join, or Abort for a short/failed write); a later Revoke/Close stop is reported by the retained entry's section for the reply that reports that custody.

The SDK needs no change: api/agent/src/trace.js already records the whole daemon telemetry map, so the facts appear as daemon.unmount in the trace line.

Success and failure behaviour

  • Success: still Reply::Unmounted(token); the section says stage: Join, abort: Written. The drained receipt is unchanged.
  • Short or failed abort write: still Retained at Abort with the original errno/count in detail and TeardownCustody.forced; the section adds abort: Short|Failed with bytes/errno.
  • Second drain stop: still Retained at Join with abort: Written.
  • Revoke/Close stop after a successful abort: custody unchanged; the entry keeps the observation and the reply's section names Revoke/Close.
  • An unmount that never stalled: no section and no stderr line. Forced teardown is untouched — it already reports ForcedFacts in its reply.

E2E on a real Sandbox (SDK, isolated worker)

Success path (create → mount → 1500 ms → unmount): the reply is Unmounted, the trace line's daemon telemetry carries

{"stage":"Join","abort":"Written","detached":true,"loops_exited":2,"loops_joined":2,"active":0,"retained":0,"waited_ms":5083}

and the Sandbox's docker logs contain exactly one LAYERFS_DAEMON_UNMOUNT_ABORT … line with the same fields. A normal mount → exec → unmount emits no section and no line (5/5), and workspace.exec still sees the FUSE mount and passes exit code 7 through. Stall window: clean at 700 ms, abort at 800/900/1000/1500 ms.

Benchmark (min / p50 / p90 / max ms, n): early-mount unmount 5033.6 / 5055.7 / 5122.6 / 5175.1 (n=10); normal unmount 11.5 / 14.6 / 17.2 / 17.8 and exec 27.7 / 33.1 / 35.2 / 35.5 (n=5); control (restart, same build) 5038.3 / 5049.7 / 5136.4 / 5187.7 (n=5). The ~5 s early-mount is expected here: this PR adds the telemetry, not the private namespace or the 1 s join grace, so the abort path waits the full drain.

Where the unmount outcome belongs

Four layers: the daemon renders one Reply::Observed telemetry section and one debug line; the SDK trace records the daemon map; the Host (dsh-layerfs) journals and counts — no counter or metric name in the engine.

Tests and exact results

Linux ARM64, Rust 1.85.1, locked dependencies, Disposable Store only (Durable NOT_RUN, owner-disabled):

  • layerfs-api unmount_observability, in a privileged container with /dev/fuse, SYS_ADMIN and --test-threads=1 (the mount-lane container shape) — 3 passed, 11.27 s; repeated 3 passed in 11.46 s and 11.30 s. The first case starts the actual daemon executable, mounts a Workspace, holds the mount in a copied mount namespace, and drives a traced unmount: asserts the exact unmount key set and values (Join, Written, detached, loops, waited_ms), that the daemon wrote exactly one LAYERFS_DAEMON_UNMOUNT_ABORT line with the same fields, and that a second Workspace unmounted without a copy has no section and adds no line. The two new cases drive the retained Revoke and Close stops through the SDK control owner with the real in-process Service: the later boundary is staged through the entry's own owner (a poisoned overlay job for Revoke, an already-closed overlay for Close), and the test asserts Reply::Retained custody and the same unmount section at the named stage.
  • layerfs-daemon unmount_observability — 3 passed, 0.09 s. Pins the key set for Written, Short and Failed (bytes/errno present only then), the stderr line fields, and no observation for a normal unmount.
  • layerfs-daemon stalled_unmount — 6 passed, 21.66 s. The existing six stalled cases also assert the observation on the success reply and the observation the retained entry keeps, including its Revoke/Close stage; custody, detail and forced are unchanged.
  • Negative check: dropping the unmount field from the test's observed reply fails the retained test at "the retained stop's telemetry section"; the assertion is live (no false pass).
  • A container without /dev/fuse: tools/ci_tests.py mount-targets selects (layerfs-api, unmount_observability); targets fast does not name it; the fast nextest filter excludes binary_id(layerfs-api::unmount_observability); python3 -B -m unittest tools.test_ci_tests — 6 tests OK.
  • The exact mount-lane build (cargo test --locked -p layerfs-daemon -p layerfs-api $(python3 -B tools/ci_tests.py mount-targets) --no-run --message-format json, piped through tools/ci_tests.py executables) yields both unmount_observability binaries and stalled_unmount (45 mount binaries); the ordinary layerfs-daemon binary is built beside them.
  • cargo check --locked --workspace --exclude layerfs-node — Finished, exit 0.
  • cargo fmt --all -- --check — exit 0.
  • cargo clippy --manifest-path Cargo.toml --locked --workspace --exclude layerfs-node --all-targets -- -D warnings — Finished, exit 0.
  • python3 -B tools/check_product_boundary.py --skip-sdk — PASS: scanned 821 production Rust/SQL/JavaScript files. (Run with the tree at a path whose components are not src; mounted at /src the guard misreads the mount as a module path and reports the same 2 pre-existing findings as the untouched parent tree.)
  • python3 -B -m unittest discover -s tools -p 'test_*.py' — 155 tests OK; tools/check_fuser_integrity.py — exit 0; pinned ruff 0.17.2 format --diff on the changed tools — already formatted.

Test invocations are capped well under the 120 s ceiling. No lints or guards were suppressed with #[allow].

CI on the new head

Head fe6e9935a94b3e9024e446c7a52b9e34d7dc5604:

  • Fast lane, ci run 40785503559 — success (fmt and guards, clippy, test). The whole run log contains no unmount_observability: the target is not built or selected by the fast lane.
  • Mount lane, nightly run 40785540999 (same commit, dispatched on the fork), mount job — success. Both unmount_observability binaries ran in their own containers with /dev/fuse and SYS_ADMIN: the SDK binary 3 passed in 11.12 s (both retained cases and the actual-daemon case) and the daemon binary 3 passed in 0.03 s.

Files changed

  • engine/crates/layerfs-daemon/src/control/unmount_abort.rs (new): the observation type.
  • engine/crates/layerfs-daemon/src/control/{detach,unmount,serving,registry,types,force,status,operations,attach,mod}.rs: build, carry and keep the observation; no custody change.
  • engine/crates/layerfs-daemon/src/telemetry.rs: the unmount section and the stderr line, from one field list.
  • engine/crates/layerfs-daemon/src/application/diagnostics.rs: merge the observation into the traced reply's telemetry.
  • engine/crates/layerfs-daemon/tests/{stalled_unmount,unmount_observability}.rs, engine/crates/layerfs-api/tests/unmount_observability.rs: tests above, plus the in-process retained-stop seam and the daemon start-up diagnostics.
  • tools/ci_tests.py: the target's SDK mount-target registration; tools/test_ci_tests.py: the selection assertion.
  • core/docs/architecture/76-native-mount-session.md, 80-forced-teardown.md, README.md: key set, line, retained-stop coverage, lane routing, and the Host follow-up.

Limitations

  • Host aggregation is a dsh-layerfs follow-up, outside this repository (it is the "Host counting" item of [draft] Observability: count and expose unmount Join stalls #2): this PR makes the facts available in the daemon reply/trace and writes the line; it adds no Host view.
  • waited_ms is an observation of the drain wait and abort path, not a latency budget or a benchmark claim.
  • The retained Revoke/Close section is now also covered end-to-end through a traced reply, but the reply envelope in that test is composed by the test adapter: a retained stop can only be staged in-process, and the daemon application's startup owner is not a library API (exposing it for the test would be a test-only production API). The custody, the abort observation and the section are production values; the one composition link the test does not exercise is the three-line abort selection in application/diagnostics.rs. No production source changed.
  • No full SDK E2E or benchmark qualification.

Related: Ephemeral-AI-Lab#500 (merged; the envelope this builds on) and #2 (the observation request, closed by fork PR #6).

)

A normal unmount that has to end a stalled, already-detached connection with
the connection's one abort write now reports that path beside the ordinary
reply: a traced Unmount carries an `unmount` telemetry section inside the
existing `Observed` envelope, on success (still `Unmounted`, still no replay)
and on a retained stop, where the entry keeps the observation for the reply
that later reports that custody. Its stable keys are `stage` (`Join`, `Abort`,
`Revoke` or `Close`), `abort` (`Written`, `Short` or `Failed`), `bytes` for a
short write or `errno` for a failed one, `detached`, `loops_exited`,
`loops_joined`, `active`, `retained` and `waited_ms` from the stalled drain to
the end of the abort path. The daemon also writes one
`LAYERFS_DAEMON_UNMOUNT_ABORT <field>=<value>` stderr line when that path
ends, traced or not, with the same fields; it is one line per abort, never
per-request logging. An unmount that never stalls carries neither.

The observation is daemon-internal and encoded in no reply field: `Success`
carries it, `TeardownCustody` and the `Observed` envelope are unchanged, and
the application merges it into the telemetry it already builds. No retry,
second abort, second detach, syscall, dependency or test hook is added.
Deleted tests: none.

Validation on Linux ARM64, Rust 1.85.1, locked dependencies, disposable Store
only (Durable NOT_RUN, disabled by owner):
- The actual daemon executable under a copied mount namespace: the traced
  stalled unmount's `unmount` section and its one stderr line, and a plain
  unmount with neither (layerfs-api unmount_observability: 1 passed, 5.2 s).
- The stable key set for Written/Short/Failed and the stderr line, plus no
  observation for a normal unmount (layerfs-daemon unmount_observability:
  3 passed, 0.1 s).
- stalled_unmount with the new attachment and retention assertions: 6 passed,
  21.9 s; the six existing cases keep their exact custody.
- cargo check -p layerfs-daemon -p layerfs-api --all-targets: pass.
- cargo fmt --all -- --check: pass.
- cargo clippy --manifest-path Cargo.toml --locked --workspace --exclude
  layerfs-node --all-targets -- -D warnings: pass.
- python3 -B tools/check_product_boundary.py --skip-sdk: PASS (821 files),
  run with the tree at a path without a `src` component; mounted at `/src` the
  guard misreads the mount itself as a module path (the same 2 pre-existing
  findings appear on the untouched parent tree).
No full SDK/benchmark qualification; the Host view that aggregates these facts
is a dsh-layerfs follow-up, outside this repository.

Production LOC: 102831 -> 103059 (delta +228)
First-parent comparison: 35d3657 to the
committed tree.
Scopes: core 38395 -> 38395 (0); engine 61777 -> 62005 (+228); api
2659 -> 2659 (0); reference absent (retired R9c; last counted 65,417 at tree
498dd19).
Method: tools/production_loc.py --root <exported tree>, first-party production
Rust, runtime SQL and JavaScript; tests, docs, tooling, generated and
third-party code excluded.
@mengmengmengqiang

Copy link
Copy Markdown
Collaborator Author

Superseded by the upstream PR Ephemeral-AI-Lab#501 (same head commit b0f7d43); this fork PR is kept only as a mirror and is closed so the upstream PR is the single review surface.

…er a retained stop

The layerfs-api `unmount_observability` target mounts a real Workspace, but it
was not one of the named SDK mount targets, so the fast lane ran it as a
non-root runner without `/dev/fuse`: the daemon exited before printing
`LAYERFS_DAEMON_LISTEN`, and the test panicked at the line that parses it
(upstream Ephemeral-AI-Lab#501, run 40781324309). Register the target in
`tools/ci_tests.py` `API_MOUNT_TARGETS` (the same routing the Linux-only daemon
FUSE targets use) and assert it in `tools/test_ci_tests.py`; the nightly mount
lane now builds it and runs it in its own container with `/dev/fuse`,
SYS_ADMIN and an unconfined AppArmor profile. The test's assertions are
unchanged; it is skipped by lane selection in the fast lane, not failed.

Two hardened start-up observations from the failure: when the LISTEN line is
still missing (for example a direct run in a non-privileged container), `start`
now panics with the daemon's stderr instead of an opaque `unwrap`, and it does
not join the blocked stdout reader on that path (the killed child ends it). A
Drop guard removes the fixture directory on every exit, including a panic.

The retained Revoke/Close stop now reaches a traced reply. The new test drives
the real in-process `Service` over the SDK control owner, stages the later
boundary through the entry's own owner (a poisoned overlay job for Revoke, an
already-closed overlay for Close), and asserts the `Reply::Retained` custody
and the same `unmount` telemetry section a completed abort path carries, at
the named stage. A retained stop cannot be staged through a separately spawned
daemon, and the daemon application's startup owner is not a library API, so
the reply envelope is the test adapter's; the custody, the abort observation
and the section are production values (`Service::retained_abort`,
`telemetry::unmount_abort`, `Reply::Retained`), `src/` is unchanged, and no
test-only production API or test hook is added. The test lives in
`layerfs-api/tests`, the SDK-facing daemon integration boundary; the adapter
selection in `application/diagnostics.rs` remains the one composition link the
test does not exercise (documented in the test header and architecture docs).

Deleted tests: none.

Validation on Linux ARM64, Rust 1.85.1, locked dependencies, Disposable Store
only (Durable NOT_RUN, disabled by owner), each invocation under 120 s:
- layerfs-api unmount_observability (privileged container, /dev/fuse +
  SYS_ADMIN, --test-threads=1): 3 passed, 11.27 s; repeated 11.46 s and
  11.30 s. Includes the completed abort path through the actual daemon binary
  and the retained Revoke and Close traced replies.
- Negative check: dropping the `unmount` field from the test's observed reply
  fails the retained test at "the retained stop's telemetry section" (the
  assertion is live; no false pass).
- layerfs-daemon unmount_observability: 3 passed, 0.09 s; stalled_unmount:
  6 passed, 21.66 s.
- A container without /dev/fuse: `tools/ci_tests.py mount-targets` selects
  `(layerfs-api, unmount_observability)`; `targets fast` does not name it; the
  fast nextest filter excludes
  `binary_id(layerfs-api::unmount_observability)`; `tools.test_ci_tests`
  passes (6 tests).
- The exact mount-lane build (`cargo test --locked -p layerfs-daemon
  -p layerfs-api $(python3 -B tools/ci_tests.py mount-targets) --no-run
  --message-format json` piped through `ci_tests.py executables`) yields both
  unmount_observability binaries and stalled_unmount (45 mount binaries); the
  ordinary layerfs-daemon binary is built beside them.
- cargo check --locked --workspace --exclude layerfs-node: pass.
- cargo fmt --all -- --check: pass.
- cargo clippy --manifest-path Cargo.toml --locked --workspace --exclude
  layerfs-node --all-targets -- -D warnings: pass.
- python3 -B tools/check_product_boundary.py --skip-sdk: PASS (821 files, run
  at a path without a `src` component; at `/src` the guard misreads the mount
  and reports the same 2 pre-existing findings as the untouched parent).
- python3 -B -m unittest discover -s tools -p 'test_*.py': 155 tests OK.
- tools/check_fuser_integrity.py: exit 0 (no dependency/config change).
- Pinned ruff 0.17.2 `format --diff` on the changed Python tools: already
  formatted.

Production LOC: 103059 -> 103059 (delta 0)
First-parent comparison: b0f7d43 to the
committed tree.
Scopes: core 38395 -> 38395 (0); engine 62005 -> 62005 (0); api
2659 -> 2659 (0); reference absent (retired R9c; last counted 65,417 at tree
498dd19).
Method: tools/production_loc.py --root <exported tree>, first-party production
Rust, runtime SQL and JavaScript; tests, docs, tooling, generated and
third-party code excluded.
@mengmengmengqiang

Copy link
Copy Markdown
Collaborator Author

Reopened per request: kept as the fork-side mirror of the upstream PR Ephemeral-AI-Lab#501 (same head b0f7d43).

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