Http-go template fails

[mikkelhegn]

Creating a new Spin application using the http-go template fails without any modifications to the code:

Serving http://127.0.0.1:3000
Available Routes:
  go-temp2: http://127.0.0.1:3000 (wildcard)
2022-10-14T17:31:26.421024Z ERROR spin_http_engine: Error processing request: wasm trap: wasm `unreachable` instruction executed
wasm backtrace:
    0: 0x3a8f - <unknown>!runtime.runtimePanic

[radu-matei]

Could you please share which versions for Spin and TinyGo this is?

Just validated this with Spin from canary, TinyGo 0.26, and the latest template version and it fails for me as well.

For reference, I also tested our C# template, which is built on top of the same C interop, and that one works well.

cc @adamreese

[etehtsea]

As it passes on CI, it looks like there are some breaking changes between 0.22 and 0.26 - https://github.com/fermyon/spin/actions/runs/3245485308/jobs/5323079898

This is from the log on CI (0.22):

make -C sdk/go test
make[1]: Entering directory '/home/runner/work/spin/spin/sdk/go'
tinygo build -wasm-abi=generic -target=wasi -gc=leaking -no-debug -o http/testdata/http-tinygo/main.wasm http/testdata/http-tinygo/main.go
go test -v .
=== RUN   TestHTTPTriger
    integration_test.go:76: building example:  http/testdata/http-tinygo
    integration_test.go:80: Get "http://127.0.0.1:35811/hello": dial tcp 127.0.0.1:35811: connect: connection refused
    integration_test.go:80: Get "http://127.0.0.1:35811/hello": dial tcp 127.0.0.1:35811: connect: connection refused
    integration_test.go:80: Get "http://127.0.0.1:35811/hello": dial tcp 127.0.0.1:35811: connect: connection refused
    integration_test.go:80: Get "http://127.0.0.1:35811/hello": dial tcp 127.0.0.1:35811: connect: connection refused
    integration_test.go:85: 200 OK
--- PASS: TestHTTPTriger (21.91s)
=== RUN   TestBuildExamples
    integration_test.go:114: building example:  ../../examples/config-tinygo
    integration_test.go:114: building example:  ../../examples/http-tinygo
    integration_test.go:114: building example:  ../../examples/http-tinygo-outbound-http
    integration_test.go:114: building example:  ../../examples/tinygo-outbound-redis
    integration_test.go:114: building example:  ../../examples/tinygo-redis
--- PASS: TestBuildExamples (43.40s)
PASS
ok  	github.com/fermyon/spin/sdk/go	65.313s
tinygo test -wasm-abi=generic -target=wasi -gc=leaking -v ./http
?   	github.com/fermyon/spin/sdk/go/http	[no test files]
tinygo test -wasm-abi=generic -target=wasi -gc=leaking -v ./redis
?   	github.com/fermyon/spin/sdk/go/redis	[no test files]
make[1]: Leaving directory '/home/runner/work/spin/spin/sdk/go'

[mikkelhegn]

I've been testing the 0.5.0 release and the canary release (from October 14th) and both fail, with both SDK, Spin runtime, and template being from the same version.

TinyGo: tinygo version 0.26.0 darwin/amd64 (using go version go1.19.2 and LLVM version 14.0.0)

[etehtsea]

I did a little research about it - it works fine up to 0.25.0 (incl).
Also, I've figured out the commit that is causing the issue - tinygo-org/tinygo@03d1c44
Reverting it from the tinygo's dev branch make tests (make test-sdk-go) to pass again (so as http-tinygo example).

Unfortunately, I'm unfamiliar with the internals and can't tell if it's the upstream bug or not without further debugging.

UPD: This in-progress PR seems to fix the issue so now it looks more like an upstream bug

[radu-matei]

Validated that TinyGo v0.25 works.
I think we should update the documentation to point out the version we know works.

Thanks for investigating this!

[lann]

Removing -no-debug from the tinygo build command and running spin with WASMTIME_BACKTRACE_DETAILS=1 gives more detail:

    2: 0x141d9 - realloc
                    at /usr/lib/tinygo/src/runtime/arch_tinygowasm.go:136:28

[lann]

Finally getting back to this... The backtrace appears to point at the indexing operation here:

ptr := unsafe.Pointer(&buf[0])

Suggesting that the panic could be caused by buf having size zero, which could possibly happen if realloc was called with size 0.

[lann]

This makes sense with the patch identified in #820 (comment), which changed the underlying realloc implementation. I'm testing a patch to tinygo.