spin icon indicating copy to clipboard operation
spin copied to clipboard

Published 20 hours ago • verified publisher icon fermyon

Http-go template fails

Open mikkelhegn opened this issue 2 years ago • 4 comments

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

mikkelhegn avatar Oct 14 '22 17:10 mikkelhegn

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

radu-matei avatar Oct 16 '22 02:10 radu-matei

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'

etehtsea avatar Oct 16 '22 05:10 etehtsea

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)

mikkelhegn avatar Oct 16 '22 09:10 mikkelhegn

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 - https://github.com/tinygo-org/tinygo/commit/03d1c44265e1f628b2730b9c214db2390a745ee6 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

etehtsea avatar Oct 17 '22 11:10 etehtsea

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!

radu-matei avatar Oct 18 '22 22:10 radu-matei

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 avatar Oct 25 '22 13:10 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 avatar Oct 25 '22 21:10 lann

This makes sense with the patch identified in https://github.com/fermyon/spin/issues/820#issuecomment-1280726355, which changed the underlying realloc implementation. I'm testing a patch to tinygo.

lann avatar Oct 25 '22 21:10 lann

Almost certainly fixed by https://github.com/tinygo-org/tinygo/pull/3303

lann avatar Nov 22 '22 14:11 lann

When I patch tinygo with #3303 I get a different error

    0: 0x2a9ec - abort
                    at /Users/areese/p/src/github.com/tinygo-org/tinygo/lib/wasi-libc/libc-bottom-half/sources/abort.c:5:5
    1: 0x29b8f - canonical_abi_realloc
                    at /Users/areese/p/src/github.com/fermyon/spin/sdk/go/http/wasi-outbound-http.c:13:3

Looks like the bindings expect a pointer returned from realloc but the patch returns nil. https://github.com/fermyon/spin/blob/722107325f01a58e5e04b09df3e70f73409c58bf/sdk/go/http/wasi-outbound-http.c#L11-L13 https://github.com/tinygo-org/tinygo/pull/3303/files#diff-5134aa362b4882a502f819967129e9d01184206daf02f989e50aa03999632ae6R45-R49

adamreese avatar Jan 20 '23 21:01 adamreese

realloc(ptr, 0) is "allowed" to return null by POSIX, but glibc returns a unique pointer and it looks like wit-bindgen depends on that behavior.

lann avatar Jan 23 '23 15:01 lann

Hi, any idea of whats is happening?

2023-01-24T11:16:24.608075Z ERROR spin_http: Error processing request: error while executing at wasm backtrace:
    0: 0x3a4a - <unknown>!runtime.runtimePanic
    1:  0x830 - <unknown>!runtime.lookupPanic
    2: 0xac0f - <unknown>!realloc
    3: 0x27ce0 - <unknown>!canonical_abi_realloc

Caused by:
    wasm trap: wasm `unreachable` instruction executed

OS: Fedora 37 TinyGo: 0.26.0 Spin: 0.7.1 (6cf7447 2022-12-19)

tomaswarynyca avatar Jan 24 '23 11:01 tomaswarynyca

Can you try TinyGo 0.25.0? 0.26.0 has an issue, but haven't been fully investigated yet.

mikkelhegn avatar Jan 24 '23 11:01 mikkelhegn

Same problem with TinyGo 0.25.0!

tomaswarynyca avatar Jan 24 '23 11:01 tomaswarynyca

I cannot replicate, can you share the code? I was using the http-go template. I'm on MacOS.

Screenshot 2023-01-24 at 13 06 57

mikkelhegn avatar Jan 24 '23 12:01 mikkelhegn 

➜ tinygo version
tinygo version 0.25.0 linux/amd64 (using go version go1.19.5 and LLVM version 14.0.5)
➜ spin -V       
spin 0.7.1 (6cf7447 2022-12-19)
➜ spin new http-go go-0.25
Project description: 
HTTP base: /
HTTP path: /...
➜ cd go-0.25
➜ spin build              
Executing the build command for component go-0-25: tinygo build -wasm-abi=generic -target=wasi -gc=leaking -no-debug -o main.wasm main.go
# github.com/fermyon/spin/sdk/go/http
../../../../usr/lib64/tinygo/lib/wasi-libc/sysroot/include/__struct_iovec.h:5:10: fatal: 'stddef.h' file not found
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/internals.go:4:12: note: in file included from internals.go!cgo.c:3:
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:8:12: note: in file included from /home/fedora/go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:8:
../../../../usr/lib64/tinygo/lib/wasi-libc/sysroot/include/stdint.h:20:10: note: in file included from /usr/lib64/tinygo/lib/wasi-libc/sysroot/include/stdint.h:20:
../../../../usr/lib64/tinygo/lib/wasi-libc/sysroot/include/bits/alltypes.h:402:10: note: in file included from /usr/lib64/tinygo/lib/wasi-libc/sysroot/include/bits/alltypes.h:402:
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:62:24: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:12:11: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:13:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:63:21: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:25:24: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:26:24: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:30:39: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:31:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:64:25: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:50:39: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:51:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:65:24: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:57:10: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:20:14: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:21:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:58:22: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:66:29: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:75:29: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:70:10: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:71:25: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:76:32: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/spin-http.h:77:29: expected a bitfield
../../../../usr/lib64/tinygo/lib/wasi-libc/sysroot/include/__struct_iovec.h:5:10: fatal: 'stddef.h' file not found
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/outbound_internals.go:10:13: note: in file included from outbound_internals.go!cgo.c:3:
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:8:12: note: in file included from /home/fedora/go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:8:
../../../../usr/lib64/tinygo/lib/wasi-libc/sysroot/include/stdint.h:20:10: note: in file included from /usr/lib64/tinygo/lib/wasi-libc/sysroot/include/stdint.h:20:
../../../../usr/lib64/tinygo/lib/wasi-libc/sysroot/include/bits/alltypes.h:402:10: note: in file included from /usr/lib64/tinygo/lib/wasi-libc/sysroot/include/bits/alltypes.h:402:
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:62:33: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:12:11: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:13:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:63:30: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:25:33: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:26:33: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:30:48: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:31:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:64:34: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:50:48: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:51:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:65:33: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:57:10: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:20:14: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:21:12: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:58:31: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:66:38: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:75:38: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:70:10: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:71:34: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:76:41: expected a bitfield
../../go/pkg/mod/github.com/fermyon/spin/sdk/[email protected]/http/wasi-outbound-http.h:77:38: expected a bitfield
Error: Build command for component go-0-25 failed with status Exited(1).

tomaswarynyca avatar Jan 24 '23 14:01 tomaswarynyca

@dicej / @lann any idea?

mikkelhegn avatar Jan 24 '23 14:01 mikkelhegn

@tomaswarynyca You may need to install clang?

lann avatar Jan 24 '23 15:01 lann

@lann I have it installed

➜ clang --version
clang version 15.0.7 (Fedora 15.0.7-1.fc37)
Target: x86_64-redhat-linux-gnu
Thread model: posix
InstalledDir: /usr/bin

tomaswarynyca avatar Jan 24 '23 15:01 tomaswarynyca

Did you install Tinygo as a package? I am not too familiar with Fedora.

lann avatar Jan 24 '23 15:01 lann

Yeah, as it says on the TinyGo website https://tinygo.org/getting-started/install/linux/#fedora-linux

image

Installing TinyGo 0.25 installs a few more dependencies

image

tomaswarynyca avatar Jan 24 '23 15:01 tomaswarynyca 

../../../../usr/lib64/tinygo/lib/wasi-libc/sysroot/include/__struct_iovec.h:5:10: fatal: 'stddef.h' file not found

The most obvious interpretation of this is a missing package. From a quick search the only other one that makes sense to me for Fedora might be kernel-headers.

lann avatar Jan 24 '23 16:01 lann

https://github.com/tinygo-org/tinygo/pull/3410 should fix the original error, though it revealed another issue with the SDK bindings as well so it isn't a complete fix.

lann avatar Jan 24 '23 20:01 lann

https://github.com/fermyon/spin/pull/1114 might have fixed the issue with tinygo 0.26.

lann avatar Feb 06 '23 23:02 lann

Hurrah!

image

For anyone wanting this upgrade. Spin v0.8.0 works, but you need to update the Go SDK reference using go get github.com/fermyon/spin/sdk/go@main in the folder containing go.mod for your Spin component.

mikkelhegn avatar Feb 07 '23 08:02 mikkelhegn

I'd suggest to keep this issue open until we have a v0.9.0 version shipped, and this fix will be part of the default SDK version being used by the template.

mikkelhegn avatar Feb 07 '23 12:02 mikkelhegn

With tinygo 0.27.0 although the http-go template and http-tinygo example each build/run successfully for me, I seem to get errors for the other tinygo-related templates and example apps. Others able to confirm? (Not sure if user error)

For example, the http-tinygo-outbound-http example (here using spin and sdk from https://github.com/fermyon/spin/pull/1153, which is current with main as of writing):

$ spin -V
spin 0.8.0 (ca0b046 2023-02-15)

$ spin build
Executing the build command for component tinygo-hello: tinygo build -target=wasi -gc=leaking -no-debug -o main.wasm main.go
spin up
Successfully ran the build command for the Spin components.

$ spin up
Serving http://127.0.0.1:3000
Available Routes:
  tinygo-hello: http://127.0.0.1:3000/hello
panic: free: invalid pointer
2023-02-15T22:01:07.166089Z ERROR spin_http: Error processing request: error while executing at wasm backtrace:
    0: 0x196b - <unknown>!runtime._panic.llvm.6707981987192336823
    1: 0x6530 - <unknown>!free
    2: 0x2cc9e - <unknown>!canonical_abi_free
    3: 0x2ce6b - <unknown>!spin_http_headers_free
    4: 0x2d1c3 - <unknown>!spin_http_request_free
    5: 0x2c98a - <unknown>!github.com/fermyon/spin/sdk/go/http.send$1
    6: 0x2c80e - <unknown>!github.com/fermyon/spin/sdk/go/http.send
    7: 0x2a51e - <unknown>!spin_http_handle_http_request
    8: 0x2d338 - <unknown>!__wasm_export_spin_http_handle_http_request

Caused by:
    wasm trap: wasm `unreachable` instruction executed

If someone who is still on tinygo 0.26.0 can compare notes, that'd be handy. If it is indeed particular to 0.27.0, I/we can create a separate issue.

vdice avatar Feb 15 '23 22:02 vdice

That could be a bug in the SDK that managed to stay hidden with earlier tinygo versions. I'm working on updating the Go SDK right now to add key-value support and update outbound-redis. I can take a look at this while I'm at it.

dicej avatar Feb 15 '23 22:02 dicej

This does look vaguely like the kind of bug I (thought I) fixed.

lann avatar Feb 15 '23 22:02 lann

This should be addressed in https://github.com/fermyon/spin/pull/1165

dicej avatar Feb 16 '23 21:02 dicej