WASI Module not instantiated error when running example

[jakemaguy]

Running on WSL2 Ubuntu
Docker version 20.10.14, build a224086

The source was cloned and the example build instructions were followed

$ cd example/tac/go
$ make build
make build
mkdir -p functions
## Run TinyGo build via Docker because waPC requires a <0.18.0 version of TinyGo to work right
docker run -v `pwd`/:/build -w /build tinygo/tinygo:0.17.0 tinygo build -o /build/functions/tarmac.wasm -target wasi /build/main.go
go: downloading github.com/wapc/wapc-guest-tinygo v0.3.0

The tarmac wasm file is generated after running the build command:

$ ls -l functions/
total 220
-rwxr-xr-x 1 root root 221650 Jul 18 11:21 tarmac.wasm

Running the tarmac container:

docker run -p 8080:8080  \
    -e "APP_ENABLE_TLS=false" \
    -e "APP_LISTEN_ADDR=0.0.0.0:8080" \
    -v $(pwd)/functions:/functions madflojo/tarmac

time="2022-07-18T15:00:33Z" level=warning msg="No Config file found, loaded config from Environment - Default path ./conf"
time="2022-07-18T15:00:33Z" level=info msg="KV Store not configured, skipping"
time="2022-07-18T15:00:33Z" level=info msg="SQL DB not configured, skipping"
time="2022-07-18T15:00:33Z" level=fatal msg="Service stopped - unable to create module pool for wasm file /functions/tarmac.wasm - module[wasi_unstable] not instantiated"

[madflojo]

Thanks for reporting this, I ran into the same issue with #32 and ended up using a higher version of TinyGo to compile the module. https://github.com/madflojo/tarmac/blob/main/testdata/Makefile#L5

Looks like we need to update the examples to use the latest TinyGo as well.

[jakemaguy]

I have some interesting findings to report. I attempted to bump the tinygo version in the Makefile from 0.17.0 to latest. The example compiled correctly and the server ran:

docker run -p 8080:8080  \
    -e "APP_ENABLE_TLS=false"  \
    -e "APP_LISTEN_ADDR=0.0.0.0:8080" \
    -v $(pwd)/functions:/functions madflojo/tarmac

time="2022-07-18T21:53:12Z" level=warning msg="No Config file found, loaded config from Environment - Default path ./conf"
time="2022-07-18T21:53:12Z" level=info msg="KV Store not configured, skipping"
time="2022-07-18T21:53:12Z" level=info msg="SQL DB not configured, skipping"
time="2022-07-18T21:53:12Z" level=info msg="Starting Listener on 0.0.0.0:8080"

However, when trying to send a request:

server

docker run -p 8080:8080 \
    -e "APP_ENABLE_TLS=false" \
    -e "APP_LISTEN_ADDR=0.0.0.0:8080"  \
    -e "APP_DEBUG=true"  \
    -v $(pwd)/functions:/functions madflojo/tarmac

time="2022-07-18T21:56:44Z" level=warning msg="No Config file found, loaded config from Environment - Default path ./conf"
time="2022-07-18T21:56:44Z" level=debug msg="Enabling Debug Logging"
time="2022-07-18T21:56:44Z" level=info msg="KV Store not configured, skipping"
time="2022-07-18T21:56:44Z" level=info msg="SQL DB not configured, skipping"
time="2022-07-18T21:56:44Z" level=info msg="Starting Listener on 0.0.0.0:8080"
time="2022-07-18T21:56:52Z" level=debug msg="HTTP Request to /" content-length=14 headers="map[Accept:[*/*] Content-Length:[14] Content-Type:[application/x-www-form-urlencoded] User-Agent:[curl/7.68.0]]" http-protocol=HTTP/1.1 method=POST remote-addr="172.17.0.1:38304"
time="2022-07-18T21:56:52Z" level=debug msg="Error executing WASM module - failed to execute wasm module - invocation of WASM module failed - call to \"POST\" was unsuccessful" content-length=14 headers="map[Accept:[*/*] Content-Length:[14] Content-Type:[application/x-www-form-urlencoded] User-Agent:[curl/7.68.0]]" http-protocol=HTTP/1.1 method=POST remote-addr="172.17.0.1:38304"

client

curl --data "Tarmac Example" "http://localhost:8080" -v
*   Trying 127.0.0.1:8080...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8080 (#0)
> POST / HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.68.0
> Accept: */*
> Content-Length: 14
> Content-Type: application/x-www-form-urlencoded
>
* upload completely sent off: 14 out of 14 bytes
* Mark bundle as not supporting multiuse
< HTTP/1.1 500 Internal Server Error
< Server: tarmac
< Date: Mon, 18 Jul 2022 21:57:04 GMT
< Content-Length: 0
<
* Connection #0 to host localhost left intact

bumping tinygo from 0.17.0 to 0.18.0

server

docker run -p 8080:8080 \
    -e "APP_ENABLE_TLS=false" \
    -e "APP_LISTEN_ADDR=0.0.0.0:8080"  \
    -e "APP_DEBUG=true"  \
    -v $(pwd)/functions:/functions madflojo/tarmac

time="2022-07-18T22:04:15Z" level=warning msg="No Config file found, loaded config from Environment - Default path ./conf"
time="2022-07-18T22:04:15Z" level=debug msg="Enabling Debug Logging"
time="2022-07-18T22:04:15Z" level=info msg="KV Store not configured, skipping"
time="2022-07-18T22:04:15Z" level=info msg="SQL DB not configured, skipping"
time="2022-07-18T22:04:15Z" level=info msg="Starting Listener on 0.0.0.0:8080"
time="2022-07-18T22:04:20Z" level=debug msg="HTTP Request to /" content-length=14 headers="map[Accept:[*/*] Content-Length:[14] Content-Type:[application/x-www-form-urlencoded] User-Agent:[curl/7.68.0]]" http-protocol=HTTP/1.1 method=POST remote-addr="172.17.0.1:38314"
time="2022-07-18T22:04:20Z" level=debug msg="CallbackRouter called with payload Reversing Payload: Tarmac Example" function=trace namespace=logger

client

curl --data "Tarmac Example" "http://localhost:8080" -v
*   Trying 127.0.0.1:8080...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8080 (#0)
> POST / HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.68.0
> Accept: */*
> Content-Length: 14
> Content-Type: application/x-www-form-urlencoded
>
* upload completely sent off: 14 out of 14 bytes
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Server: tarmac
< Date: Mon, 18 Jul 2022 22:04:20 GMT
< Content-Length: 14
< Content-Type: text/plain; charset=utf-8
<
* Connection #0 to host localhost left intact
elpmaxE camraT

[madflojo]

now that is interesting. What is super interesting is the CI pipeline is setup with latest and the test example uses posts. I'll have to look into this a bit more.

[madflojo]

Was able to confirm this as well, for now, I updated the Makefiles to use TinyGo v0.18.0. But I'll look at the wapc packages and see if I can identify why it's failing.

FYI @codefromthecrypt

[codefromthecrypt]

oh I see. I think the minimum version of TinyGo is v0.18.0 as it corrected the module import for wasi from wasi_unstable to wasi_snapshot_preview1, which is what everything else uses. tinygo-org/tinygo@303acf5

[madflojo]

After merging #37 this is fixed for versions 0.18 and greater. Turns out we needed to update to the latest wapc-guest package.