fix(plugins): plugin output reaches the console's log page, and /tmp is no longer hidden from the runner #27

Merged

enricobuehler merged 4 commits from worktree-plugin-logs-and-vh-fixes into main 2026-08-03 16:44:33 +00:00

Conversation 0 Commits 4 Files Changed 18

+1262 -45

enricobuehler commented 2026-08-03 16:32:36 +00:00

Owner

Copy Link

Copy Source

A user (RoobN) could not get the VirtualHere plugin to use their VirtualHere client and asked, reasonably, where the logs were. There was no good answer, and the reason they were stuck turned out to be ours.

The runner could not see /tmp

punktfunk-scripting.service set PrivateTmp=yes, which hands the unit a private tmpfs. But integrating with things already running on the box is the entire job of a plugin, and on Linux those talk over /tmp: VirtualHere's client IPC is the FIFO pair /tmp/vhclient + /tmp/vhclient_response, X11 is /tmp/.X11-unix.

So the plugin launched the vendor binary happily and could then never reach the daemon behind it — while the same command worked perfectly in the operator's own shell, because that shell has the real /tmp. No config change could fix it, which is exactly the loop the report described.

PrivateTmp is now off, with /tmp added to ReadWritePaths (which ProtectSystem=strict would otherwise make read-only).

Plugin logs now land in the console

Plugins are not host child processes — the runner is a separate bun process that import()s each plugin in-process — so nothing they print passed through the host's tracing, and the console's Logs page could not show a single plugin line.

The fallback was journalctl on Linux; on Windows the runner's scheduled task writes no log file at all, so a failing plugin was diagnosable only by stopping the task and re-running the runner by hand. Both mean shell access on the host box, which is what the console exists to avoid — and it left the one question a stuck user asks with no answer.

The runner now tees its output to POST /api/v1/plugins/logs, and those lines join the host's own ring under one cursor, targeted plugin:<name>. The console grows a Host / Plugins switch beside the level filter; an empty Plugins view says the thing that is actually usually wrong (the runner isn't running) rather than "adjust the filter".

The shipper keeps stdout authoritative — journald and foreground output are unchanged whatever the host is doing — and is built so that logging can never hurt the thing being logged: it never throws into a caller, holds a bounded queue that drops oldest and then says how many, backs off when the host is away (a restart is normal), and re-sends a batch the host failed to take.

Runner lines reporting a failure (a refused unit file, a crashed plugin, a give-up) now go out at warn/error instead of all arriving as INFO, so the console's level filter means something for them.

Two bugs in the shipper, found by re-reading it

Both had the same symptom — a missing log line — which is the one failure a logging path must not have.

• The recursion guard was held across the whole await fetch, and enqueue checked it, so every line logged while a POST was open was silently dropped. That window is milliseconds when the host is healthy and much longer when it is not, so the shipper was least reliable exactly when most needed. The flag now guards flush re-entry only.
• An explicit flush() hit that same guard and returned having sent nothing — that is the shutdown path, where the last lines are the ones that say whether the shutdown was clean. It now waits for an in-flight flush first.

Both are covered by tests that fail against the previous code. The first needed a mock server that signals when it has the request: logging merely "after calling flush()" passes against the bug, because flush yields at its own awaits long before the fetch starts.

Verification

Run in a linux/amd64 container, each run carrying proof-greps that the committed bytes were present (guarding against a vacuous green):

• cargo clippy --workspace --all-targets --locked -- -D warnings — green
• cargo fmt --all --check — clean
• cargo test -p punktfunk-host — 377 passed, 1 failed
• SDK 72/72 + typecheck clean; plugin-kit 20/20 against the modified SDK
• web codegen + lint clean, no drift

The one failure is gamestream::stream::tests::sender_delivers_batches, a UDP-loopback test that dies with EINTR under qemu. This diff touches no gamestream file, and my notes record it failing identically on clean origin/main in the same container while real CI is green. Not re-verified against origin/main this session — flagging it as attributed rather than freshly proven.

Companion PR in the plugin repo fixes two bugs the same report turned up: unom/punktfunk-plugin-virtualhere#1.

🤖 Generated with Claude Code

A user (RoobN) could not get the VirtualHere plugin to use their VirtualHere client and asked, reasonably, where the logs were. There was no good answer, and the reason they were stuck turned out to be ours. ## The runner could not see `/tmp` `punktfunk-scripting.service` set `PrivateTmp=yes`, which hands the unit a private tmpfs. But integrating with things already running on the box is the entire job of a plugin, and on Linux those talk over `/tmp`: VirtualHere's client IPC is the FIFO pair `/tmp/vhclient` + `/tmp/vhclient_response`, X11 is `/tmp/.X11-unix`. So the plugin launched the vendor binary happily and could then never reach the daemon behind it — while the same command worked perfectly in the operator's own shell, because that shell has the real `/tmp`. No config change could fix it, which is exactly the loop the report described. `PrivateTmp` is now off, with `/tmp` added to `ReadWritePaths` (which `ProtectSystem=strict` would otherwise make read-only). ## Plugin logs now land in the console Plugins are not host child processes — the runner is a separate bun process that `import()`s each plugin in-process — so nothing they print passed through the host's `tracing`, and the console's Logs page could not show a single plugin line. The fallback was `journalctl` on Linux; on Windows the runner's scheduled task writes **no log file at all**, so a failing plugin was diagnosable only by stopping the task and re-running the runner by hand. Both mean shell access on the host box, which is what the console exists to avoid — and it left the one question a stuck user asks with no answer. The runner now tees its output to `POST /api/v1/plugins/logs`, and those lines join the host's own ring under one cursor, targeted `plugin:<name>`. The console grows a **Host / Plugins** switch beside the level filter; an empty Plugins view says the thing that is actually usually wrong (the runner isn't running) rather than "adjust the filter". The shipper keeps stdout authoritative — journald and foreground output are unchanged whatever the host is doing — and is built so that logging can never hurt the thing being logged: it never throws into a caller, holds a bounded queue that drops oldest and then says how many, backs off when the host is away (a restart is normal), and re-sends a batch the host failed to take. Runner lines reporting a failure (a refused unit file, a crashed plugin, a give-up) now go out at warn/error instead of all arriving as INFO, so the console's level filter means something for them. ## Two bugs in the shipper, found by re-reading it Both had the same symptom — a missing log line — which is the one failure a logging path must not have. - The recursion guard was held across the whole `await fetch`, and `enqueue` checked it, so **every line logged while a POST was open was silently dropped**. That window is milliseconds when the host is healthy and much longer when it is not, so the shipper was least reliable exactly when most needed. The flag now guards flush re-entry only. - An explicit `flush()` hit that same guard and returned having sent nothing — that is the **shutdown path**, where the last lines are the ones that say whether the shutdown was clean. It now waits for an in-flight flush first. Both are covered by tests that fail against the previous code. The first needed a mock server that signals when it *has* the request: logging merely "after calling `flush()`" passes against the bug, because flush yields at its own awaits long before the fetch starts. ## Verification Run in a `linux/amd64` container, each run carrying proof-greps that the committed bytes were present (guarding against a vacuous green): - `cargo clippy --workspace --all-targets --locked -- -D warnings` — green - `cargo fmt --all --check` — clean - `cargo test -p punktfunk-host` — **377 passed, 1 failed** - SDK 72/72 + typecheck clean; plugin-kit 20/20 against the modified SDK - web `codegen` + `lint` clean, no drift The one failure is `gamestream::stream::tests::sender_delivers_batches`, a UDP-loopback test that dies with `EINTR` under qemu. This diff touches no gamestream file, and my notes record it failing identically on clean `origin/main` in the same container while real CI is green. **Not re-verified against `origin/main` this session** — flagging it as attributed rather than freshly proven. Companion PR in the plugin repo fixes two bugs the same report turned up: `unom/punktfunk-plugin-virtualhere#1`. 🤖 Generated with [Claude Code](https://claude.com/claude-code)

enricobuehler added 4 commits 2026-08-03 16:32:38 +00:00

fix(plugins): plugin output reaches the console's log page, and /tmp is no longer hidden from the runner ... 365caa23be

A user could not get the VirtualHere plugin to use their VirtualHere client
and asked, reasonably, where the logs were. There was no good answer, and the
reason they were stuck turned out to be ours.

**The runner could not see /tmp.** `punktfunk-scripting.service` set
PrivateTmp=yes, which hands the unit a private tmpfs. But integrating with
things already running on the box is the entire job of a plugin, and on Linux
those talk over /tmp: VirtualHere's client IPC is the FIFO pair /tmp/vhclient +
/tmp/vhclient_response, X11 is /tmp/.X11-unix. So the plugin launched the vendor
binary happily and could then never reach the daemon behind it — while the same
command worked perfectly in the operator's own shell, because that shell has the
real /tmp. No config change could fix it, which is exactly the loop the report
described. PrivateTmp is now off, with /tmp added to ReadWritePaths (which
ProtectSystem=strict would otherwise make read-only).

**Plugin logs now land in the console.** Plugins are not host child processes —
the runner is a separate bun process that import()s each plugin in-process — so
nothing they print passed through the host's tracing, and the console's Logs
page could not show a single plugin line. The fallback was journalctl on Linux;
on Windows the runner's scheduled task writes no log file at all, so a failing
plugin was diagnosable only by stopping the task and re-running the runner by
hand. Both mean shell access on the host box, which is what the console exists
to avoid — and it left the one question a stuck user asks with no answer.

So the runner now tees its output to POST /api/v1/plugins/logs, and those lines
join the host's own ring under one cursor, targeted plugin:<name>. The console
grows a Host/Plugins switch beside the level filter; an empty Plugins view says
the thing that is actually usually wrong (the runner isn't running) rather than
"adjust the filter".

The shipper keeps stdout authoritative — journald and foreground output are
unchanged whatever the host is doing — and is built so that logging can never
hurt the thing being logged: it never throws into a caller, holds a bounded
queue that drops oldest and then says how many, backs off when the host is away
(a restart is normal), and re-sends a batch the host failed to take. Lines
logged while a POST is in flight are kept, which cost one round to get right:
the first version held its recursion guard across the await and silently dropped
exactly the lines a busy plugin produces.

Runner lines that report a failure (a refused unit file, a crashed plugin, a
give-up) now go out at warn/error instead of all arriving as INFO, so the
console's level filter means something for them.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

fix(sdk/log-ship): a busy plugin's lines survive a POST, and the shutdown tail is actually sent ... 1e56705b86

Two bugs in the log shipper, both found by re-reading it rather than by a
failing test, and both of the kind where the symptom is a missing log line —
which is the one failure a logging path must not have.

The recursion guard was held across the whole `await fetch`, and `enqueue`
checked it. So every line logged while a POST was open was dropped, silently.
That window is milliseconds when the host is healthy and much longer when it is
not, and the lines lost are whatever a busy plugin happened to be saying — so
the shipper was least reliable exactly when it was most needed. The flag now
guards flush re-entry only (the interval can fire while a slow POST is still
open, and two concurrent flushes would splice disjoint batches out of one queue
and deliver them out of order). Nothing on the shipping path logs, so the
recursion it was guarding cannot form; that is now a stated rule at the top of
the file rather than a flag that costs real lines.

An explicit `flush()` hit that same re-entry guard and returned having sent
nothing. That is the shutdown path: the runner flushes once more after its
units' finalizers have run, and those last lines are the ones that say whether
the shutdown was clean. It now waits for an in-flight flush before starting its
own.

Both are covered by tests that fail against the previous code. The first needed
a server that signals when it has the request — logging merely "after calling
flush()" passes against the bug, because flush yields at its own awaits long
before the fetch starts.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

test(mgmt): pin the two things that would silently break plugin logging ... 442ea12b96

The runner holds the PLUGIN token and nothing else — on Windows its LocalService
principal cannot read the admin one at all. `plugin_may_access` is an exclusion
list, so `/plugins/logs` is reachable today only because it happens not to match
`/ui-credential`. If that ever changed, plugin logs would go quiet in the console
with no other symptom and no failing test. Now asserted on that lane directly.

The second test covers ingest end to end through `GET /logs`: the `plugin:` target
prefix the console's Host/Plugins filter keys on, the level coercion (an unranked
level would sort as 0 and hide under every filter setting), a sourceless line
being attributed to the runner rather than to nothing, the caller's timestamp
surviving the trip, and an oversized batch being refused whole.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

docs(plugins): don't name a release that doesn't exist yet ... db1faef9fb

The /tmp troubleshooting note said PrivateTmp=yes shipped "until 0.23.1".
0.23.0 is the latest tag and the next number isn't decided, so that could be
wrong on arrival. "In earlier releases" is true whichever number it gets.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

enricobuehler merged commit b8b38d082e into main 2026-08-03 16:44:33 +00:00

enricobuehler deleted branch worktree-plugin-logs-and-vh-fixes 2026-08-03 16:44:33 +00:00

enricobuehler referenced this pull request 2026-08-03 17:47:50 +00:00

chore(release): bump workspace version to 0.24.0 #29

Sign in to join this conversation.

Reviewers

No Reviewers

Labels

No items

No labels

Milestone

No items

No Milestone

Projects

Clear projects

No projects

Assignees

Clear assignees

FernandoMX enricobuehler (Enrico Bühler) kszlim nannku neoney sassycrown

No Assignees

1 Participants

Notifications

Subscribe

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: unom/punktfunk#27