ffi issue-0047: file #run-on-stderr-vs-runtime-on-stdout split
Surfaced while adding the `--- build done ---` delimiter
(commit 2993072). `#run print()` output is buffered by the
interp and flushed via std.debug.print → stderr at
core.zig:187/190; JIT runtime `print()` writes via libc
write(1, ...) → stdout. Same `print` call from the user's
viewpoint, different streams in practice.
Not blocking step 3 — tests capture both streams via 2>&1 so
snapshots are unaffected. Issue file documents the fix path
(move the two `std.debug.print` flushes in core.zig to
stdout-writes) for a future session.
This commit is contained in:
108
issues/0047-run-output-on-stderr-runtime-on-stdout.md
Normal file
108
issues/0047-run-output-on-stderr-runtime-on-stdout.md
Normal file
@@ -0,0 +1,108 @@
|
||||
# Symptom
|
||||
|
||||
`#run print(...)` output lands on **stderr**; runtime `print(...)`
|
||||
output lands on **stdout**. The test runner captures both via
|
||||
`2>&1` so they appear interleaved in snapshots, but for a human
|
||||
running `sx run foo.sx` and piping stdout somewhere — or in any
|
||||
context that separates the streams — the compile-time output
|
||||
silently goes to a different place than the runtime output.
|
||||
|
||||
The recently-landed `--- build done ---` delimiter (commit
|
||||
`2993072`) makes the boundary visible in test logs but doesn't
|
||||
fix the underlying split.
|
||||
|
||||
# Reproduction
|
||||
|
||||
```sx
|
||||
#import "modules/std.sx";
|
||||
|
||||
configure :: () {
|
||||
print("hello from #run\n");
|
||||
}
|
||||
#run configure();
|
||||
|
||||
main :: () -> s32 {
|
||||
print("hello from runtime\n");
|
||||
return 0;
|
||||
}
|
||||
```
|
||||
|
||||
```
|
||||
$ ./zig-out/bin/sx run repro.sx > /tmp/stdout.txt 2> /tmp/stderr.txt
|
||||
$ cat /tmp/stdout.txt
|
||||
hello from runtime
|
||||
$ cat /tmp/stderr.txt
|
||||
hello from #run
|
||||
```
|
||||
|
||||
Expected (most consistent): both on stdout — both are `print`
|
||||
calls in user code; the user doesn't distinguish "build-time
|
||||
print" from "runtime print" at the call site.
|
||||
|
||||
# Root cause
|
||||
|
||||
The interp accumulates `print` output into an internal buffer
|
||||
(`Interpreter.output: []u8`) via the `out` builtin
|
||||
(`src/ir/interp.zig:1678-1683`). After the interp returns, the
|
||||
buffer is flushed to **stderr** via `std.debug.print` from
|
||||
`src/core.zig:187` and `src/core.zig:190`.
|
||||
|
||||
The JIT-executed runtime `print` lowers through `BuiltinId.out`
|
||||
in `emit_llvm.zig:2936-2954` which emits `write(1, ptr, len)` —
|
||||
directly to fd 1 (stdout).
|
||||
|
||||
So the split is at the flush call in `core.zig`, not at the
|
||||
print mechanism itself.
|
||||
|
||||
# Investigation prompt
|
||||
|
||||
For a fresh session picking this up:
|
||||
|
||||
The fix is small in code but touches a few callers. The two
|
||||
`std.debug.print("{s}", .{interp.output.items})` sites at
|
||||
`src/core.zig:187` and `:190` should write to stdout instead.
|
||||
|
||||
Options for the stdout write:
|
||||
1. **libc write(1, ...)** via `std.c.write(1, ptr, len)`. Direct,
|
||||
no Zig std buffering, interleaves correctly with `--- build
|
||||
done ---` (also direct to stderr).
|
||||
2. **std.posix.write(std.posix.STDOUT_FILENO, ...)** — Zig'\''s
|
||||
typed wrapper. Same effect.
|
||||
3. **std.fs.File.stdout() + writeAll** — more idiomatic but
|
||||
may bring buffering complexity.
|
||||
|
||||
Whichever route, the order of writes vs the `--- build done ---`
|
||||
delimiter (which currently goes to stderr) matters:
|
||||
- If both #run output AND delimiter both go to stdout: ordering
|
||||
preserved within stdout's buffer.
|
||||
- If delimiter stays on stderr and #run goes to stdout: the
|
||||
delimiter might appear out-of-order in mixed-stream captures.
|
||||
|
||||
Cleanest: move BOTH to stdout. The compile-error path (in
|
||||
`renderErrors`) stays on stderr — only successful #run output
|
||||
moves.
|
||||
|
||||
Other call sites that might leak `#run` output to stderr:
|
||||
- `core.zig:187` — `invokeByFuncId` error path.
|
||||
- `core.zig:190` — `invokeByFuncId` success path.
|
||||
- Grep for `interp.output` to find others.
|
||||
|
||||
# Verification
|
||||
|
||||
After the fix, the repro above should produce:
|
||||
|
||||
```
|
||||
$ ./zig-out/bin/sx run repro.sx > /tmp/stdout.txt 2> /tmp/stderr.txt
|
||||
$ cat /tmp/stdout.txt
|
||||
hello from #run
|
||||
--- build done ---
|
||||
hello from runtime
|
||||
$ cat /tmp/stderr.txt
|
||||
(empty)
|
||||
```
|
||||
|
||||
Test snapshots for the 7 tests with top-level `#run` will need
|
||||
to be re-`--update`d, but the visible content is the same —
|
||||
just on the right stream now.
|
||||
|
||||
Full suite + `zig build test` must still pass.
|
||||
Reference in New Issue
Block a user