wazero
wazero copied to clipboard
flaky test: BenchmarkLibsodium/box_seal
~I suspect this was after #2265~, turns out this has existed at least since v1.7.0 https://github.com/tetratelabs/wazero/actions/runs/9684312101/job/26721778588
This will be a blocker for the next release
turns out it's flaky - rerun succeeded
reproduced on my local m1 mac
~/wazero/internal/integration_test/libsodium
$ go test -bench='BenchmarkLibsodium/box_seal' -count=100 -benchtime=10x
goos: darwin
goarch: arm64
pkg: github.com/tetratelabs/wazero/internal/integration_test/libsodium
BenchmarkLibsodium/box_seal-10 10 506911971 ns/op
BenchmarkLibsodium/box_seal-10 10 504660892 ns/op
BenchmarkLibsodium/box_seal-10 10 502820754 ns/op
BenchmarkLibsodium/box_seal-10 10 507620717 ns/op
BenchmarkLibsodium/box_seal-10 10 510368371 ns/op
BenchmarkLibsodium/box_seal-10 10 508002408 ns/op
BenchmarkLibsodium/box_seal-10 10 513437050 ns/op
BenchmarkLibsodium/box_seal-10 --- FAIL: BenchmarkLibsodium/box_seal-10
require.go:331: expected no error, but was module[] function[_start] failed: wasm error: unreachable
wasm stack trace:
.$83(i32,i32)
.$9()
/Users/mathetake/wazero/internal/integration_test/libsodium/bench_test.go:133
/usr/local/go/src/testing/benchmark.go:193
/usr/local/go/src/testing/benchmark.go:288
/usr/local/go/src/runtime/asm_arm64.s:1222
BenchmarkLibsodium/box_seal-10 10 508346446 ns/op
BenchmarkLibsodium/box_seal-10 10 505010212 ns/op
BenchmarkLibsodium/box_seal-10 10 506423908 ns/op
turns out this happens with v1.7.0 as well, so the bug might have existed in the first place
maybe next is to see if this will happen with interpreter or amd64, but I have no cycle right now
not sure if this happens with the old compiler in the first place
I was able to reproduce it with amd64:
$ go test -bench='BenchmarkLibsodium/box_seal' -count=100 -benchtime=10x -v
goos: linux
goarch: amd64
pkg: github.com/tetratelabs/wazero/internal/integration_test/libsodium
cpu: AMD EPYC 7B13
BenchmarkLibsodium
BenchmarkLibsodium/box_seal
require.go:331: expected no error, but was module[] function[_start] failed: wasm error: unreachable
wasm stack trace:
.$83(i32,i32)
.$9()
/home/cruces/Documents/Personal/wazero/internal/integration_test/libsodium/bench_test.go:140
/usr/local/go/src/runtime/asm_amd64.s:1695
^Csignal: interrupt
--- FAIL: BenchmarkLibsodium/box_seal-48
FAIL github.com/tetratelabs/wazero/internal/integration_test/libsodium 34.403s
Ignore the line number. I modified the benchmark to run multiple copies over runtime.NumCPU().
I was also able to reproduce it with the interpreter (with a lot more effort):
$ go test -bench='BenchmarkLibsodium/box_seal' -count=100 -benchtime=10x -v
goos: linux
goarch: amd64
pkg: github.com/tetratelabs/wazero/internal/integration_test/libsodium
cpu: AMD EPYC 7B13
BenchmarkLibsodium
BenchmarkLibsodium/box_seal
require.go:331: expected no error, but was module[] function[_start] failed: wasm error: unreachable
wasm stack trace:
.$83(i32,i32)
.$9()
/home/cruces/Documents/Personal/wazero/internal/integration_test/libsodium/bench_test.go:140
/usr/local/go/src/runtime/asm_amd64.s:1695
^Csignal: interrupt
FAIL github.com/tetratelabs/wazero/internal/integration_test/libsodium 617.368s
It also seems to happen with the old, 1.6.0, compliler:
$ go test -bench='BenchmarkLibsodium/box_seal' -count=100 -benchtime=10x -v
goos: linux
goarch: amd64
pkg: github.com/tetratelabs/wazero/internal/integration_test/libsodium
cpu: AMD EPYC 7B13
BenchmarkLibsodium
BenchmarkLibsodium/box_seal
require.go:331: expected no error, but was module[] function[_start] failed: wasm error: unreachable
wasm stack trace:
.$83(i32,i32)
.$9()
/home/cruces/Documents/Personal/wazero/internal/integration_test/libsodium/bench_test.go:140
/usr/local/go/src/runtime/asm_amd64.s:1695
--- FAIL: BenchmarkLibsodium/box_seal
--- FAIL: BenchmarkLibsodium
FAIL
exit status 1
FAIL github.com/tetratelabs/wazero/internal/integration_test/libsodium 9.488s
thank you for your research @ncruces. I think we can conclude that this is some flake in the binary in the first place, I still wonder where does it come from though given that the binary is not compiled with threads
Well, it imports (and calls) random_get, so there's plenty of room for non-determinism in there.
$ wasm-dis box_seal.wasm | grep '(import'
(import "wasi_snapshot_preview1" "clock_time_get" (func $fimport$0 (param i32 i64 i32) (result i32)))
(import "wasi_snapshot_preview1" "fd_close" (func $fimport$1 (param i32) (result i32)))
(import "wasi_snapshot_preview1" "fd_fdstat_get" (func $fimport$2 (param i32 i32) (result i32)))
(import "wasi_snapshot_preview1" "fd_seek" (func $fimport$3 (param i32 i64 i32 i32) (result i32)))
(import "wasi_snapshot_preview1" "fd_write" (func $fimport$4 (param i32 i32 i32 i32) (result i32)))
(import "wasi_snapshot_preview1" "poll_oneoff" (func $fimport$5 (param i32 i32 i32 i32) (result i32)))
(import "wasi_snapshot_preview1" "proc_exit" (func $fimport$6 (param i32)))
(import "wasi_snapshot_preview1" "random_get" (func $fimport$7 (param i32 i32) (result i32)))