wazero icon indicating copy to clipboard operation
wazero copied to clipboard

flaky test: BenchmarkLibsodium/box_seal

Open mathetake opened this issue 1 year ago • 5 comments

~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

mathetake avatar Jun 26 '24 17:06 mathetake

turns out it's flaky - rerun succeeded

mathetake avatar Jun 26 '24 18:06 mathetake

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

mathetake avatar Jun 26 '24 21:06 mathetake

turns out this happens with v1.7.0 as well, so the bug might have existed in the first place

mathetake avatar Jun 26 '24 22:06 mathetake

maybe next is to see if this will happen with interpreter or amd64, but I have no cycle right now

mathetake avatar Jun 26 '24 22:06 mathetake

not sure if this happens with the old compiler in the first place

mathetake avatar Jun 27 '24 15:06 mathetake

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

ncruces avatar Jul 01 '24 13:07 ncruces

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

ncruces avatar Jul 01 '24 13:07 ncruces

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

mathetake avatar Jul 01 '24 14:07 mathetake

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)))

ncruces avatar Jul 01 '24 14:07 ncruces