Skip to content

internal/vm: $stdout and $stderr are duck-typed — dispatch #write instead of asserting *IOObj - #697

Merged
tannevaled merged 6 commits into
mainfrom
wave40-duck-typed-stderr
Sep 26, 2026
Merged

tannevaled merged 6 commits into
mainfrom
wave40-duck-typed-stderr

Conversation

@tannevaled

@tannevaled tannevaled commented Sep 26, 2026 •

Copy link
Copy Markdown
Contributor

The defect

internal/vm/io.go's curIO type-asserted $stdout / $stderr to *IOObj and fell
back to the raw file descriptor for anything else. MRI's standard streams are
duck-typed at the language level, so every interpreter-generated warning and every
Kernel#p aimed at a stream that merely answers #write went to the terminal instead
of to the object the program had installed.

Reproduced against MRI 4.0.5 (ruby 4.0.5 (2026-05-20 revision 64336ffd0e) +PRISM [arm64-darwin25]), before this change:

class Duck; def initialize; @b = +""; end; def write(*a); a.each { |x| @b << x.to_s }; 1; end; def collected; @b; end; end
$VERBOSE = true
s = Duck.new
$stderr = s
[1, 2].fetch(5, 1) { |i| i }
$stderr = STDERR
print s.collected
# MRI  : "prog.rb:5: warning: block supersedes default value argument\n"
# rbgo : ""     -- and the warning went to the terminal

Why it survived

With a StringIO in place of the duck type, both engines collect it identically --
because StringIO is an *IOObj here and so satisfied the type assertion. The
matchers meant to catch this (mspec's complain / output) used a StringIO, so the
harness's own double could not witness the defect. The comment in io_class.go that
justified writing to curStderr() said so in as many words: "still honouring a
$stderr reassigned to a StringIO (mspec's complain matcher)"
.

Every WITNESS test added here therefore uses a plain object answering only #write.

The C functions read, and what each decided

Read at ruby/ruby tag v3_4_0.

function decided
io.c:2296 rb_io_write Where the dispatch point goes. It is, in full, return rb_funcallv(io, id_write, 1, &str); -- an unconditional dynamic #write send, with no fast path for a real IO.
io.c:2220 io_writev Where the fast path actually lives: inside IO#write's own C body, reached only because method lookup on a real IO lands there, and itself ending in rb_funcallv(io, id_write, argc, argv) once rb_io_check_io reports "port is not IO, call write method for it". So no caller ever chooses between the two arms.
io.c:2302 rb_io_writev The piece count is observable, and MRI splits on the receiver's #write arity, not on the piece count: argc > 1 && rb_obj_method_arity(io, id_write) == 1 gets one call per piece plus a :deprecated notice; anything else gets one multi-argument call.
io.c:9162 rb_write_error_str The only licence for a raw-descriptor write, and its condition is rb_stderr_to_original_p (io.c:9130) = err == orig_stderr -- pointer identity with the original object, not "is it an IO". Testing *IOObj instead is strictly broader, which is the defect.
io.c:9215, io.c:9228 stdout_setter / stderr_setter What the streams promise: both begin must_respond_to(id_write, val, id), so any object answering #write is admitted and the rest are refused with a TypeError at assignment.
io.c:8959 rb_io_puts Builds three argv shapes, not one: an empty line writes rb_default_rs alone; a line already ending in a newline writes itself alone; anything else writes line and separator as two pieces.
io.c:8727 rb_io_print Calls rb_io_write per argument with the raw object -- the #to_s happens inside IO#write (io.c:2026), so a duck's #write receives the unconverted value. rbgo already matched.
io.c:9018 rb_p_write Kernel#p writes the inspected form and rb_default_rs as two pieces. Its T_FILE && rb_method_basic_definition_p arm is not a semantic fork -- both arms produce the same bytes -- so rbgo takes the general one.
error.c:374 rb_write_warning_str The decisive one. It is rb_warning_warn(rb_mWarning, str), and rb_warning_warn (error.c:341) is rb_funcallv(mod, id_warn, 1, &str). So the one place is Warning.warn, one level above $stderr.
error.c:466, :497, :489 rb_warn / rb_warning / rb_enc_warn All three funnel into rb_write_warning_str, and differ only in their gate: !NIL_P(ruby_verbose) for rb_warn, RTEST for rb_warning.
error.c:287 rb_warning_s_warn The default Warning.warn body: rb_write_error_str(str). That is the only route from a warning to $stderr.
error.c:355 rb_warn_category rb_warning_warn_arity(): a one-argument Warning.warn override is called without the category keyword.
error.c:420 rb_category_warning The "outdated interface" notice needs RTEST(ruby_verbose) (true, not merely non-nil) and an enabled category -- and :deprecated is off by default in Ruby 3+.
process.c rb_f_abort Kernel#abort writes its message with rb_io_puts(1, args, rb_ractor_stderr()) -- puts semantics on the duck-typed $stderr. See the defects section: rbgo's is outside this PR's cluster.

The one-place dispatch decision

rb_io_write is already the single dynamic-dispatch point in MRI, and the fast path
is not a branch any caller takes -- it is what method lookup does when the receiver
happens to be a real IO. So the rule belongs in exactly one function per C counterpart,
all in io.go:

stdoutValue / stderrValue   rb_ractor_stdout / rb_ractor_stderr   the object, not an *IOObj
  stdSink                   (the one non-MRI fallback, stated once)
ioWrite                     rb_io_write                           one dynamic #write
ioWritev                    rb_io_writev                          + the #write-arity split
  writeArityIsOne           rb_obj_method_arity(io, id_write)
  warnOutdatedWrite         io.c:2306-2315 and its three gates
writeWarningStr             rb_write_warning_str -> Warning.warn
  warningWarn               rb_warn_category's arity rule

rbWarn1, rbWarning1 and rbWarn now call writeWarningStr; Kernel#warn calls the
same warningWarn they end in; ioPuts and Kernel#p call ioWritev. curStdout /
curStderr stay, for the callers that genuinely need a stream object (rack.errors,
Puma's log sink, ARGF), and carry a comment saying they are not the way to emit output.

Two duplicated tests were removed rather than left to drift: nativePrint and
nativePuts each carried their own "lost its #write" fallback, which stdSink now
owns. This repo has had four repeat defects in a week from a rule restated at several
sites.

Choosing Warning.warn rather than $stderr as the sink is what the C source decided,
and it subsumes the original brief: the default Warning.warn is
$stderr.write(message), an ordinary send, so fixing the higher level fixes the
duck-typed $stderr and makes an overridden Warning.warn intercept rbgo's own
internal warnings, which MRI's does and rbgo's did not.

What happens for a stream that cannot do the job

receiver MRI 4.0.5 rbgo, this PR
answers #write but not #puts works for warn, p, puts, print; $stderr.puts / $stderr.print raise NoMethodError: private method 'puts' called for an instance of Duck identical
answers neither #write nor #puts TypeError: $stderr must have write method, Mute given, raised at the ASSIGNMENT by must_respond_to -- never a NoMethodError identical (already correct before this PR)
#write raises the exception propagates out of the warning site, out of p, out of everything identical (was silently swallowed on the internal paths, which never reached #write at all)
had #write and lost it afterwards NoMethodError writes to the underlying stream instead, so a Go host embedding the VM is not killed by a program mutating its own stream. Documented on stdSink as an implementation choice, not a differential case.

Three receivers x nine paths

Byte-for-byte against MRI 4.0.5. "duck" answers only #write; "Tempfile" is the third
receiver and, unexpectedly, a second witness -- a Tempfile is a delegator, not an
*IOObj, so it was dropped exactly as the duck was. StringIO is the control that
could not witness anything.

path duck StringIO Tempfile before
warn (internal rb_warn) = = = duck and Tempfile were empty
Kernel#warn = = = =
$stderr.puts = = = =
$stderr.write = = = =
$stderr.print = = = =
p = = = duck and Tempfile were empty
puts = = = = bytes, wrong argv shape
print = = = =
deprecation warning = = = =

45 of 45 cells identical after the change; 6 differed before. Plus the argv shapes:

MRI rbgo before rbgo after
p 7, splat #write [["7", "\n"]] [] (leaked) [["7", "\n"]]
p 7, arity-1 #write [["7"], ["\n"]] [] (leaked) [["7"], ["\n"]]
puts "hi", splat [["hi", "\n"]] [["hi\n"]] [["hi", "\n"]]
puts "hi", arity-1 [["hi"], ["\n"]] [["hi\n"]] [["hi"], ["\n"]]
puts "hi\n" [["hi\n"]] [["hi\n"]] [["hi\n"]]
puts "" [["\n"]] [["\n"]] [["\n"]]
print 7, 8 [["7"], ["8"]] [["7"], ["8"]] [["7"], ["8"]]
overridden Warning.warn sees internal rb_warn yes no yes
arity-1 #write + Warning[:deprecated] One#write is outdated interface... nothing identical

Tests

internal/vm/io_duck_stream_test.go: 10 WITNESS cases and 8 GUARD cases. The labels
are measured, by running that exact file against the parent commit -- every WITNESS
fails there, every GUARD passes.

Every case asserts both streams. The old code did not lose the text, it wrote it to
the raw descriptor, so an assertion on one buffer alone passes either way. One case
here did exactly that and passed on the parent commit for the wrong reason until its
verdict was routed through the other stream; that is recorded in its comment.

Corpus

Ratchet scripts/conformance/rubyspec/run.sh, corpus pinned 87b1631, 2206 spec
files, TIMEOUT=25, measured serially at 2-way (a parallel sweep is not
reproducible on this host -- one or two sibling agents were measuring alongside).
Load average was 8.4-8.6 throughout and comparable across the pair.

The per-file table comes from a small Go sweep tool rather than a shell loop, and its
integrity guard asserts no empty key column, distinct filenames == input count
and a floor on the measurement -- not just row count, which a previous sweep here
passed green while reporting 2206 rows with every filename empty and a total of 0. It
also counts a TIMEOUT, a load with no RBGO_RESULT line, and a file that loaded and
genuinely scored 0 as three separate things.

Against origin/main at 41fa005

main moved four times while this was being measured (#685, #692, #694, #684 all landed),
so the pair was rebuilt and re-measured on each new base. The result is unchanged:

base base passing this PR delta files up files down
7269d0a + #692's shim 23097 23135 +38 25 0
4f5581a 23096 23135 +39 26 0
41fa005 (current) 23096 23135 +39 26 0

On the current base: 2193 files loaded either side, 5 vs 6 timeouts, 8 vs 7 no-result.
Zero files moved down in any of the three runs, and the SET of files that moved is
byte-identical between the 4f5581a and 41fa005 pairs -- four independently built
binaries, the same 26 names.

file before -> after
core/kernel/p_spec.rb 4 -> 8 (+4)
core/module/ruby2_keywords_spec.rb 3 -> 6 (+3)
core/array/new_spec.rb 18 -> 20 (+2)
core/io/for_fd_spec.rb 54 -> 56 (+2)
core/io/new_spec.rb 54 -> 56 (+2)
core/io/open_spec.rb 60 -> 62 (+2)
core/regexp/compile_spec.rb 36 -> 38 (+2)
core/regexp/new_spec.rb 36 -> 38 (+2)
language/constants_spec.rb 83 -> 85 (+2)
language/optional_assignments_spec.rb 72 -> 74 (+2)
core/array/fetch_spec.rb 8 -> 9 (+1)
core/array/find_index_spec.rb 7 -> 8 (+1)
core/array/initialize_spec.rb 22 -> 23 (+1)
core/array/rindex_spec.rb 12 -> 13 (+1)
core/env/fetch_spec.rb 12 -> 13 (+1)
core/file/new_spec.rb 25 -> 26 (+1)
core/hash/fetch_spec.rb 17 -> 18 (+1)
core/io/syswrite_spec.rb 17 -> 18 (+1)
core/module/autoload_spec.rb 65 -> 66 (+1)
core/module/const_added_spec.rb 12 -> 13 (+1)
core/module/const_get_spec.rb 44 -> 45 (+1)
core/module/const_source_location_spec.rb 38 -> 39 (+1)
core/refinement/import_methods_spec.rb 13 -> 14 (+1)
language/for_spec.rb 28 -> 29 (+1)
language/regexp/encoding_spec.rb 27 -> 28 (+1)
core/random/bytes_spec.rb 8 -> 9 (+1) -- NOT a win, a known flake

core/random/bytes_spec.rb is not credited: it is flaky. Sampled ten times per binary
rather than concluded from one run, base gives 8 8 8 9 8 9 8 9 8 9 and this PR gives
8 9 8 8 9 8 9 9 9 8 -- the same population. So the honest figure is +38 across 25
files
, and the same 25 files came out of an independent earlier pair run before #692
merged, on a separate build of both sides.

One further row changed STATUS without changing any count, and is load noise rather than
a result: core/mutex/lock_spec.rb (no-result -> timeout, 0 either way).

On the shim that was main's before #692 merged

Measured before #692 landed, so both sides are a different build:

passing
base (7269d0a) 22740
this PR on that base 22739

No net change there, and the single differing file is the same
core/random/bytes_spec.rb flake, in the other direction.
That the pre-#692 shim
shows nothing is expected and is the whole story of this defect: that shim's double for
complain was a StringIO, which cannot witness any of it. #692 is what introduced a
double that could.

Under #692's shim on the pre-#685 build, the same comparison gave 23097 -> 23135,
i.e. +38 across the same 25 files -- so the payoff reproduces across two different
builds of both sides.

FLOOR is not touched by this PR.

Gates

  • CGO_ENABLED=0 GOWORK=off go test -count=1 ./... -- full suite, green.
  • CGO_ENABLED=0 go build ./... green; GOOS=wasip1 GOARCH=wasm green.
  • GOOS=js GOARCH=wasm green. It was red when this branch opened --
    internal/vm/errno.go:101,108,120: undefined: syscall.ENOTRECOVERABLE / EOWNERDEAD / ETXTBSY, verified identical on an unmodified origin/main checkout and therefore not
    touched here. internal/vm, ci: fix the js/wasm build, and make the guard that caught it reachable #684 has since landed and fixed it, and this branch is rebased onto it,
    so the wasm (js, browser) lane now runs for this PR too.
  • gofmt -l internal/ cmd/ empty.
  • -race is unavailable locally (this host needs CGO_ENABLED=0; the Xcode licence is
    broken), so CI's race lane is the first to run it.

100% coverage, by the four-part recipe

-race is unavailable locally, so this is the no-race profile; the rounded total is
99.9% on BOTH sides and is deliberately not the comparison.

  1. Below-100 function LIST, diffed against origin/main on the same
    -coverpkg=./internal/... profile: 16 entries on each side, and the two lists are
    identical.
  2. Each cover -func was resolved in the tree that produced its profile.
  3. The full measured function set was diffed too, keyed by file::name rather than
    by file:line: -- with the line number in the key, a 160-line insertion makes every
    later function look both removed and added, and the diff says nothing. Keyed
    properly, there is exactly one removal: builtins.go::stdoutValue, matched by
    io.go::stdoutValue arriving. Same function, moved. Nine functions added, all at
    100.0%.

The list diff earned its place. It named two functions this PR left below 100% that the
rounded total hid completely -- ioWritev at 90.9% and warnOutdatedWrite at 87.5%.
Locating them needed one more step than expected: a -coverpkg profile carries one
entry per test package, so a block with a single 0 is not an uncovered block; the
counts have to be aggregated per block first. Two genuinely different causes came out:

  • ioWritev's len(strs) == 0 guard was unreachable, and MRI has no such case
    either (rb_io_puts always builds n >= 1; its no-argument case goes through
    rb_io_write). Removed rather than tested.
  • warnOutdatedWrite's :deprecated-disabled arm is reachable, and is the default
    state. Pinned with a case asserting both the silence and Warning[:deprecated] == false, so that gate is now measured rather than asserted in a comment.

Defects found outside this PR's cluster

Each measured against MRI 4.0.5, each left alone because its owning file is not this
wave's.

  1. Kernel#abort ignores $stderr entirely, and adds a newline MRI does not.
    internal/vm/kernel_introspect.go:239 does fmt.Fprintln(vm.errOut, msg), where
    process.c rb_f_abort does rb_io_puts(1, args, rb_ractor_stderr()) -- puts
    semantics on the duck-typed global. Measured with a #write that appends to a file:
    abort "plain message" gives MRI 14 bytes on the duck and 0 on fd 2; rbgo gives 0 on
    the duck and 14 on fd 2. And abort "with newline\n" gives MRI 13 bytes (rb_io_puts
    appends nothing to a line already ending in a newline) against rbgo's 14 -- a doubled
    separator. Fixing it needs ioWritev from this PR, so it is a natural follow-up.
  2. The uncaught-exception report ignores $stderr. cmd/rbgo/main.go:102-113
    writes to os.Stderr directly. With $stderr bound to a duck that appends to a file,
    MRI puts the whole report (message, class, source line, caret) on the duck and nothing
    on fd 2; rbgo puts it on fd 2 and nothing on the duck.
  3. The circular-require warning ignores $stderr. internal/vm/require.go:382
    calls curStderr().writeStr(...) -- the exact pattern this PR removed from its own
    three files. Measured under $VERBOSE = true: MRI writes it to the duck, rbgo to
    fd 2. internal/vm/autoload.go:271 has the same shape.
  4. A toplevel def produces a PUBLIC method on Object; MRI makes it private.
    def myhelper(x); x; end then Object.private_method_defined?(:myhelper) gives MRI
    true and rbgo false; public_method_defined? is the mirror image; and
    1.myhelper(2) succeeds in rbgo where MRI raises
    NoMethodError: private method 'myhelper' called for an instance of Integer. This
    found me rather than the reverse: it broke my first test harness, whose
    respond_to?(:collected) guard answered true for a private helper.
  5. at_exit handlers do not run when the program dies of an uncaught exception.
    MRI runs them (and prints the exception report afterwards, which is why a handler
    cannot see that report); rbgo runs none. at_exit does run on an explicit exit.
  6. Kernel#exit's status is lost: exit 1 exits 0. MRI exits 1. Pre-existing on
    the base, with and without an at_exit handler. Caution for whoever picks this up:
    the obvious probe lies. Running cmd >/dev/null 2>&1; echo $? through a shell
    harness reported 0 for MRI too, including for exit 1 -- it nearly became a
    fabricated defect in the other direction. Capture the status in the SAME shell
    statement that runs the process ("$E" "$f"; st=$?) and print it from the variable.
  7. rbWarn emits no "path:lineno: " prefix, and the constant-redefinition warning
    is missing MRI's second line.
    X = 1; X = 2 under $VERBOSE = true gives MRI
    prog.rb:3: warning: already initialized constant X followed by
    prog.rb:2: warning: previous definition of X was here; rbgo gives
    warning: already initialized constant X and nothing more. rbWarn is in this PR's
    cluster, but its nine callers are not, so adding the prefix is a separate measurement.

🤖 Generated with Claude Code

tannevaled and others added 6 commits September 26, 2026 20:40
…pe assertion

curIO type-asserted $stderr/$stdout to *IOObj and fell back to the raw file
descriptor for anything else, so every interpreter-generated warning and every
Kernel#p aimed at a duck-typed stream went to the terminal instead.

MRI's streams are duck-typed at the language level: stdout_setter and
stderr_setter (io.c:9215, :9228, v3_4_0) admit any object answering #write and
reject the rest with a TypeError, and rb_io_write (io.c:2296) is unconditionally
rb_funcallv(io, id_write, 1, &str) -- there is no fast path for a real IO at
that level.

One dispatch point, in io.go:

  stdoutValue/stderrValue  rb_ractor_stdout / rb_ractor_stderr
  ioWrite                  rb_io_write
  ioWritev                 rb_io_writev, including its #write-arity split
  writeWarningStr          rb_write_warning_str -> Warning.warn

rb_warn reaches $stderr only through the default Warning.warn, so routing
rbWarn1/rbWarning1/rbWarn there also makes an overridden Warning.warn intercept
rbgo's own warnings, as MRI's does.

ioPuts and Kernel#p now hand the line and its separator to ioWritev as two
pieces, the shape rb_io_puts and rb_p_write build -- observable to any stream
that records what it was handed.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…ouble

Ten WITNESS cases and eight GUARD cases, and the labels are measured by running
this exact file against the parent commit, not assumed: every WITNESS fails
there, every GUARD passes.

The double answers ONLY #write. A StringIO cannot witness any of this, because
StringIO IS an *IOObj in rbgo -- it satisfied the type assertion curStderr()
made and collected the output either way, which is why mspec's StringIO-based
complain/output matchers never saw the defect.

Every case asserts BOTH streams. The old code did not lose the text, it wrote it
to the raw descriptor, so an assertion on one buffer alone passes either way --
one case here did exactly that and passed on the parent commit for the wrong
reason until its verdict was routed through the other stream.

Also drops nativePuts's second "lost its #write" test, now that stdSink owns
that rule.

Expected values are byte-for-byte from MRI 4.0.5 running the same scripts.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…to_s

rb_io_writev's outdated-interface notice renders the receiver with `%+"PRIsVALUE"`,
and the '+' flag means rb_inspect. The first version of warnOutdatedWrite used
#to_s, which is observable: an object carrying @marker and its own #to_s is named
`#<Object:0x... @marker=42>` by MRI 4.0.5 and "TO_S_CALLED" by that version.

Adds the witness, which also reaches the singleton arm of the '.' / '#' separator
choice. It asserts the prefix and suffix rather than the whole string, because the
middle is a heap address.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…e :deprecated gate

The below-100% function LIST diffed against origin/main named exactly two new
entries, both mine: ioWritev at 90.9% and warnOutdatedWrite at 87.5%. Resolving
each in the tree that produced its profile and aggregating the -coverpkg blocks
(the profile carries one entry per test package, so a single 0 is not an
uncovered block) located both.

ioWritev's `len(strs) == 0` guard is unreachable: rb_io_writev is never called
with argc 0 in MRI either, since rb_io_puts always builds n >= 1 and its
no-argument case goes through rb_io_write. Removed rather than tested -- a
branch no test can reach honestly does not belong.

warnOutdatedWrite's other arm IS reachable, and is the DEFAULT state: the
:deprecated category is off in Ruby 3+, which is why that notice is almost never
seen. Pinned with a case that asserts silence and asserts Warning[:deprecated]
is false, so the gate is a measurement rather than a comment.

Both functions now read 100%, and the below-100 list is identical to
origin/main's (16 entries either side). The only change to the FULL measured
function set is builtins.go::stdoutValue leaving and io.go::stdoutValue
arriving -- the same function, moved.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
… doc

The doc said eight fail and two pass, from before the singleton-inspect and
:deprecated-gate cases were added. Re-measured against origin/main: 11 WITNESS,
all failing there, and 6 GUARD, all passing. Nothing mislabelled either way.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
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