aykevl added the bug label to Issue #7833.
aykevl opened issue #7833:
wasmtime
has a different output depending on whether it is run normally or through a pipe (for example,tail
).Test Case
See the wasm.test file here:
wasm-test.zipSteps to Reproduce
Normal case:
$ wasmtime run test.wasm line written using C puts hello world!
Output is redirected to a pipe:
$ wasmtime run test.wasm | tail line written using C puts
For comparison, I tested the same thing in
wasmer
and it has the correct (first) output in both cases.Expected Results
Output should be the same, regardless of where stdout is redirected.
Actual Results
The last line is somehow lost when stdout is redirected to a pipe (in this case, passing it to
tail
but I've also seen this issue when running from inside Go os/exec).Versions and Environment
Wasmtime version or commit: wasmtime-cli 17.0.0
Operating system: Linux (Fedora Asahi)
Architecture: aarch64
Extra Info
This is a relatively big test case, I can try to make it smaller if needed.
aykevl edited issue #7833:
wasmtime
has a different output depending on whether it is run normally or through a pipe (for example,tail
).Test Case
See the wasm.test file here:
wasm-test.zipSteps to Reproduce
Normal case:
$ wasmtime run test.wasm line written using C puts hello world!
Output is redirected to a pipe:
$ wasmtime run test.wasm | tail line written using C puts
For comparison, I tested the same thing in
wasmer
and it has the correct (first) output in both cases.Expected Results
Output should be the same, regardless of where stdout is redirected.
Actual Results
The last line is somehow lost when stdout is redirected to a pipe (in this case, passing it to
tail
but I've also seen this issue when running from inside Go os/exec).Versions and Environment
Wasmtime version or commit: wasmtime-cli 17.0.0
Operating system: Linux (Fedora Asahi)
Architecture: aarch64
Extra Info
This is a relatively big test case, I can try to make it smaller if needed.
For example, I've found it reproducible usingfwrite("test\n", 5, 1, stdout);
.
alexcrichton commented on issue #7833:
Thanks for the report! I can reproduce this behavior as well with the uploaded wasm. That being said though I'm not certian that this is a bug in Wasmtime. Through
WASMTIME_LOG=trace
in the non-piped case (tty stdout) the module is callingfd_write
more times than in the piped case. In other words, in the piped case, the module itself isn't even requesting a print. The main difference here is that the module callsfd_fdstat_get
and the tty version returnsfs_filetype: CharacterDevice
while the piped version returnsfs_filetype: Unknown
meaning that the module may use this to act differently.Would you be able to share the source code of this module? The bug may be in TinyGo's standard library, but it might also be in wasi-libc. This may also be a bug that's since been fixed in wasi-libc and may require a newer build than you might be using. Hard to tell! If you're able to share the original source we can try to help dig in further.
Furthermore you mention
fwrite("test\n", 5, 1, stdout);
reproduces this behavior for you. Locally however I do not see a reproduction with a simple program doing that. This may indicate that this was a bug in wasi-libc that's since been fixed. Could you share the full source of the program (perhaps the module too) withfwrite
and the version of wasi-sdk that you're using?
aykevl closed issue #7833:
wasmtime
has a different output depending on whether it is run normally or through a pipe (for example,tail
).Test Case
See the wasm.test file here:
wasm-test.zipSteps to Reproduce
Normal case:
$ wasmtime run test.wasm line written using C puts hello world!
Output is redirected to a pipe:
$ wasmtime run test.wasm | tail line written using C puts
For comparison, I tested the same thing in
wasmer
and it has the correct (first) output in both cases.Expected Results
Output should be the same, regardless of where stdout is redirected.
Actual Results
The last line is somehow lost when stdout is redirected to a pipe (in this case, passing it to
tail
but I've also seen this issue when running from inside Go os/exec).Versions and Environment
Wasmtime version or commit: wasmtime-cli 17.0.0
Operating system: Linux (Fedora Asahi)
Architecture: aarch64
Extra Info
This is a relatively big test case, I can try to make it smaller if needed.
For example, I've found it reproducible usingfwrite("test\n", 5, 1, stdout);
.
aykevl commented on issue #7833:
That being said though I'm not certian that this is a bug in Wasmtime.
Yeah, since reporting this bug I started to realize it's more likely to be a bug in wasm-libc.
The main difference here is that the module calls
fd_fdstat_get
and the tty version returnsfs_filetype: CharacterDevice
while the piped version returnsfs_filetype: Unknown
meaning that the module may use this to act differently.Thanks! I wasn't aware that WASI allowed inspecting the output file type.
Would you be able to share the source code of this module?
It's essentially just testdata/cgo in https://github.com/tinygo-org/tinygo/pull/4101/files but without the
fflush
workaround.
Unfortunately, when I tried to reproduce it today I couldn't get it to fail. I don't remember updating anything (like wasmtime) so not sure why this is the case. Closing, I'll reopen the issue once I manage to reproduce it again.
aykevl commented on issue #7833:
Nevermind, that was a silly mistake on my side.
I can reproduce it using the following steps (this assumes you already have a working TinyGo build):
- Check out the cgo-printf branch of TinyGo.
- run
go install
,tinygo clean
- Comment out the
fflush
call at the bottom of testdata/cgo/main.c. (You can also uncomment most of the main function in testdata/cgo/main.go if you'd like).- Build a binary using
tinygo build -o test.wasm -target=wasi ./testdata/cgo
- Run it using
wasmtime run test.wasm | tail
.That's rather involved just to reproduce this issue, I can try to make a reproducer that doesn't use TinyGo.
aykevl reopened issue #7833:
wasmtime
has a different output depending on whether it is run normally or through a pipe (for example,tail
).Test Case
See the wasm.test file here:
wasm-test.zipSteps to Reproduce
Normal case:
$ wasmtime run test.wasm line written using C puts hello world!
Output is redirected to a pipe:
$ wasmtime run test.wasm | tail line written using C puts
For comparison, I tested the same thing in
wasmer
and it has the correct (first) output in both cases.Expected Results
Output should be the same, regardless of where stdout is redirected.
Actual Results
The last line is somehow lost when stdout is redirected to a pipe (in this case, passing it to
tail
but I've also seen this issue when running from inside Go os/exec).Versions and Environment
Wasmtime version or commit: wasmtime-cli 17.0.0
Operating system: Linux (Fedora Asahi)
Architecture: aarch64
Extra Info
This is a relatively big test case, I can try to make it smaller if needed.
For example, I've found it reproducible usingfwrite("test\n", 5, 1, stdout);
.
aykevl commented on issue #7833:
This may also be a bug that's since been fixed in wasi-libc and may require a newer build than you might be using.
Tried again with the main branch of wasi-libc, same issue. So whatever it is, it doesn't look like it's fixed there.
aykevl commented on issue #7833:
Update: I can't seem to reproduce this with a simple 'hello world', this needs a bit more investigation.
aykevl edited a comment on issue #7833:
Update: I can't seem to reproduce this with a simple 'hello world' in C, this needs a bit more investigation.
aykevl closed issue #7833:
wasmtime
has a different output depending on whether it is run normally or through a pipe (for example,tail
).Test Case
See the wasm.test file here:
wasm-test.zipSteps to Reproduce
Normal case:
$ wasmtime run test.wasm line written using C puts hello world!
Output is redirected to a pipe:
$ wasmtime run test.wasm | tail line written using C puts
For comparison, I tested the same thing in
wasmer
and it has the correct (first) output in both cases.Expected Results
Output should be the same, regardless of where stdout is redirected.
Actual Results
The last line is somehow lost when stdout is redirected to a pipe (in this case, passing it to
tail
but I've also seen this issue when running from inside Go os/exec).Versions and Environment
Wasmtime version or commit: wasmtime-cli 17.0.0
Operating system: Linux (Fedora Asahi)
Architecture: aarch64
Extra Info
This is a relatively big test case, I can try to make it smaller if needed.
For example, I've found it reproducible usingfwrite("test\n", 5, 1, stdout);
.
aykevl commented on issue #7833:
Ok, figured it out. I need to call
__wasm_call_dtors
before exiting. Apparently it flushes the stdout buffer.See:
https://github.com/WebAssembly/wasi-libc/blob/main/libc-bottom-half/crt/crt1-command.c#L46
Last updated: Dec 23 2024 at 12:05 UTC