Stop devpod's stream logger from mangling a command's stderr

CHANGELOG.md

@@ -32,6 +32,57 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
   reach a terminal either way, so a person watching a build sees exactly what they
   saw before.
 
+- **A command's stderr now comes back as the command wrote it.** `dl <ws> -- <cmd>`
+  reaches the container through `devpod ssh --command`, which asks for no pty, and
+  without a pty the container's stderr is folded into devpod's own -- through
+  devpod's stream logger, which reformats every line it carries. Measured against
+  devpod 0.26.1, `dl ws -- sh -c 'echo ERR >&2'` gave back a timestamp, a coloured
+  `info` tag, the text, and `stream_logger.go:492`. stdout was already clean and
+  had been for as long as anyone had looked, so a caller could parse a command's
+  JSON and not its compiler's diagnostics, and `docs/agents-using-dl.md` carried a
+  whole section saying so beside a `2>&1` workaround. That section is gone; stderr
+  is the fifth clause of the published contract now, and
+  `test_stderr_is_the_commands_output_verbatim` has stopped being a strict xfail.
+
+  The fix is devpod's own `--log-output json`, on the `devpod ssh` invocation and
+  nowhere else. Its neighbour `raw` is the obvious choice and is a trap worth
+  naming, because taking it would have broken the *first* clause of the same
+  contract while fixing the last. devpod means to pass a remote exit status
+  through and cannot: its top-level handler type-asserts on `*ssh.ExitError` after
+  wrapping it three times with `%w`, so every nonzero remote exit lands on the
+  generic failure path and exits 1 with the real status buried in a `fatal` line.
+  dl recovers the number by reading that line, and it anchors on the word `fatal`
+  to be sure the sentence is devpod's report and not a remote program printing the
+  same words. Under `raw` the report is `tunnel to container: run in container:
+  ssh session: Process exited with status 42` with no tag at all, the recovery
+  returns nothing, and `dl ws -- 'exit 42'` quietly stops exiting 42. `--silent`
+  fails the other way and swallows the command's stderr outright.
+
+  json keeps the level as a field. So the fatal is now read off `"level":"fatal"`
+  rather than off a coloured tag in the text, which is both a stronger anchor and
+  one a remote program cannot forge: devpod wraps whatever the container writes in
+  a record of its own at `info`, escaping it, so a container printing an entire
+  fatal record verbatim arrives as that record's `message` and is forwarded as the
+  text it is. Everything else is forwarded as the bare `message`, which for the
+  command's stderr is the command's bytes. A line that is not a record at all --
+  an older devpod, the plain log of the attach route, anything on the stream that
+  is not a log line -- falls through to the predicates that were already there, so
+  nothing about a devpod that does not know the flag changes.
+
+  Deliberately not passed on a bare `dl <ws>` attach. That route gets a pty, and
+  under one the container's stderr never touches this stream: the only thing json
+  would change is the look of devpod's own warnings to the person sitting in front
+  of them, trading a coloured `warn` tag for nothing. So an interactive session
+  logs exactly as it did, and the flag goes only where there is something to
+  unwrap.
+
+  Two things the clause does not promise, both now written on the page. Lines are
+  still read one at a time, so a command's unterminated last line arrives with a
+  newline it did not write; and devpod's logger strips ANSI escapes from what it
+  carries, so a tool that colours its errors arrives uncoloured -- which, since
+  the command is looking at a pipe rather than a terminal, most tools would have
+  done for themselves.
+
 ## [0.48.0] - 2026-09-13
 
 ### Fixed

docs/agents-using-dl.md

@@ -13,7 +13,7 @@ that matter most to a caller are exactly the parts a refactor cannot see it is b
 
 ## The subprocess contract
 
-`dl <workspace> -- <command>` is an ordinary subprocess, and four things about it are
+`dl <workspace> -- <command>` is an ordinary subprocess, and five things about it are
 promised rather than incidental.
 
 **The exit status is the command's.** `dl ws -- sh -c 'exit 42'` exits 42. `dl`'s own
@@ -54,6 +54,31 @@ all, so the guard and the page agreed with each other and not with the binary. A
 that parsed `dl ws -- cat some.json` worked until the first time somebody stopped the
 workspace.
 
+**stderr is the command's too.** `dl ws -- sh -c 'echo boom >&2'` puts `boom` on stderr
+and nothing else around it, so a compiler's diagnostics and a test runner's traceback
+arrive parseable. `dl`'s own narration shares that stream, and it all comes before the
+command starts, so the command's output is the tail of it.
+
+Two caveats worth knowing before you match on it. The command's stderr is still read a
+line at a time on the way out, so a partial last line arrives with a newline appended
+that the command did not write. And devpod's transport strips ANSI escapes from it, so
+a tool that colours its errors arrives uncoloured; since the command sees a pipe rather
+than a terminal, most tools emit no colour there anyway.
+
+This clause used to be the one the transport did not keep, and callers were told to
+merge the streams inside the container instead. That merge still works and is still the
+right call when you want one interleaved stream rather than two:
+
+```bash
+dl ws -- sh -c 'make test 2>&1'
+```
+
+Note where the redirection is. Inside the command `dl` is asked to run, both streams
+arrive on stdout in the order the command wrote them. `dl ws -- make test 2>&1` merges
+on the host instead, and folds `dl`'s own narration in with the output. It is no longer
+a workaround for anything, though, so reach for it only when you actually want the
+interleaving.
+
 **stdin is the command's.** `echo input | dl ws -- cat` reaches the command inside the
 container.
 
@@ -66,38 +91,10 @@ folder is the devcontainer's own choice and not something `dl` imposes, so read
 rather than assuming a path: `pwd` in the container is the honest answer, and it is
 `/workspaces/<workspace-id>` only for devcontainers that do not say otherwise.
 
-These four are pinned by `test/e2e/test_agent_subprocess_contract.py`, which builds one
+These five are pinned by `test/e2e/test_agent_subprocess_contract.py`, which builds one
 real workspace and asks each of them of it. They are e2e and skipped by default, because
 they need a Docker daemon.
 
-## stderr is not yours yet
-
-The one place the contract does not hold. A command's stderr comes back through devpod's
-stream logger rather than as itself:
-
-```
-$ dl ws -- sh -c 'echo boom >&2'
-11:18:55 info boom stream_logger.go:492
-```
-
-Timestamped, level-prefixed, ANSI-coloured and with a Go source location appended. For a
-caller that is reading a compiler's diagnostics or a test runner's traceback off stderr,
-this is the difference between output it can parse and output it cannot.
-
-Until that is fixed, merge the streams inside the container rather than outside it:
-
-```bash
-dl ws -- sh -c 'make test 2>&1'
-```
-
-The merge happens before devpod sees the output, so both streams arrive on stdout
-verbatim and the exit status is still the command's. This is the recommended form for
-any programmatic call whose stderr matters, which is most of them.
-
-Note what the workaround is not. `dl ws -- make test 2>&1` merges on the *host*, after
-the mangling has already happened, and gives you the logger's version of stderr mixed
-into good stdout. The redirection has to be inside the command `dl` is asked to run.
-
 ## The unit of isolation is the branch
 
 A workspace id is derived from the `(owner, repo, branch)` triple, so one branch is one

rust/aid/tests/interactive.rs

@@ -325,7 +325,7 @@ fn a_typed_prompt_reaches_the_agent_with_no_shell_in_the_way() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
+            "devpod ssh {MAIN} --log-output json --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions --remote-control={MAIN} \
              '\"'\"'fix the \"flaky\" test'\"'\"''"
         )
@@ -350,7 +350,7 @@ fn a_pasted_multi_line_prompt_arrives_whole_rather_than_leaking() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
+            "devpod ssh {MAIN} --log-output json --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions --remote-control={MAIN} \
              '\"'\"'fix this\nand then that'\"'\"''"
         )
@@ -367,7 +367,7 @@ fn an_empty_enter_is_the_plain_session_it_always_was() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
+            "devpod ssh {MAIN} --log-output json --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions --remote-control={MAIN}'"
         )
     );
@@ -396,7 +396,7 @@ fn the_boot_runs_while_the_prompt_is_still_being_typed() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
+            "devpod ssh {MAIN} --log-output json --command bash -lc 'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions --remote-control={MAIN} go'"
         )
     );

rust/aid/tests/rewrite.rs

@@ -289,7 +289,7 @@ fn a_prompt_reaches_the_agent_as_one_argument_through_dls_own_launch() {
              IS_SANDBOX=1 claude --dangerously-skip-permissions \
              --remote-control=devlaunch-main-3j1t 'fix the bug'",
             "Workspace devlaunch-main-3j1t is already running, attaching...",
-            "SSH command: devpod ssh devlaunch-main-3j1t --command bash -lc \
+            "SSH command: devpod ssh devlaunch-main-3j1t --log-output json --command bash -lc \
              'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions --remote-control=devlaunch-main-3j1t \
              '\"'\"'fix the bug'\"'\"''",
@@ -300,7 +300,7 @@ fn a_prompt_reaches_the_agent_as_one_argument_through_dls_own_launch() {
         [
             format!("devpod status {MAIN} --output json"),
             format!(
-                "devpod ssh {MAIN} --command bash -lc \
+                "devpod ssh {MAIN} --log-output json --command bash -lc \
                  'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
                  --dangerously-skip-permissions --remote-control={MAIN} \
                  '\"'\"'fix the bug'\"'\"''"
@@ -321,7 +321,7 @@ fn no_remote_control_is_the_one_way_back_to_a_purely_local_session() {
         assert_eq!(
             world.devpod_calls().last().expect("a session"),
             &format!(
-                "devpod ssh {MAIN} --command bash -lc \
+                "devpod ssh {MAIN} --log-output json --command bash -lc \
                  'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
                  --dangerously-skip-permissions hi'"
             ),
@@ -361,7 +361,7 @@ fn an_appended_off_switch_is_observed_from_outside_to_turn_it_off() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc \
+            "devpod ssh {MAIN} --log-output json --command bash -lc \
              'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions '\"'\"'fix the bug'\"'\"''"
         )
@@ -401,7 +401,7 @@ fn no_prompt_starts_the_agents_plain_session() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc \
+            "devpod ssh {MAIN} --log-output json --command bash -lc \
              'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions --remote-control={MAIN}'"
         )
@@ -445,15 +445,15 @@ fn each_agent_is_started_the_way_its_own_cli_takes_a_prompt() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc 'gemini --yolo --prompt-interactive '\"'\"'explain this'\"'\"''"
+            "devpod ssh {MAIN} --log-output json --command bash -lc 'gemini --yolo --prompt-interactive '\"'\"'explain this'\"'\"''"
         )
     );
 
     let bare = World::with(&["--warm"]);
     bare.aid(&["--gemini", MAIN]).exited(0);
     assert_eq!(
         bare.devpod_calls().last().expect("a session"),
-        &format!("devpod ssh {MAIN} --command bash -lc 'gemini --yolo'")
+        &format!("devpod ssh {MAIN} --log-output json --command bash -lc 'gemini --yolo'")
     );
 
     // codex is the one agent whose payload carries a prefix, because it is the one
@@ -487,7 +487,7 @@ fn remote_control_reaches_claude_as_one_named_flag_and_dl_never_sees_it() {
     assert_eq!(
         world.devpod_calls().last().expect("a session"),
         &format!(
-            "devpod ssh {MAIN} --command bash -lc \
+            "devpod ssh {MAIN} --log-output json --command bash -lc \
              'CLAUDE_CODE_DISABLE_TERMINAL_TITLE=1 IS_SANDBOX=1 claude \
              --dangerously-skip-permissions --remote-control={MAIN} '\"'\"'fix the bug'\"'\"''"
         )