jco hangs on 12_05 wasi:http component from tinygo that wasmtime/spin run no problem

[squillace]

a wasi:http component built to 12_05 WIT screams with wasmtime and spin, but runs only once with JCO; connection doesn't get released somehow.

Set up:

• Ubuntu 22.05 LTS (in WSL, but that should not affect this)
• Jco installed from release: 0.14.2
• • repro to build the component: https://github.com/squillace/hello-wasi-http-go/tree/jco-wasi-hang.

example: the first iteration is using Dan's https://github.com/sunfishcode/hello-wasi-http Rust component. JCO serves that one fine. The second, when we shift to Joe's Golang version of same, wasmtime and spin are fine, but jco somehow can't close the connection from the client.

wasmtime.jco.spin.rust.golang.wasi-http.mp4

[guybedford]

Thanks for sharing! In the multi-state poll refactor I'm exactly blocked on a HTTP stream end case as well, so this will be a great data point to add into that debugging work going on too.

[guybedford]

@squillace I spent a about 20 minutes working through the build process and did a build against 2023-12-05, but still get:

Error: import `wasi:cli/environment@0.2.0-rc-2023-12-05` has the wrong type

Caused by:
    0: instance export `get-arguments` has the wrong type
    1: expected func found nothing

against the current Wasmtime-cli.

Could you perhaps just share the binary directly? That would be a huge help to look into this further.

The bugs we fixed today in #334 are very likely to have resolved this issue, but I definitely want to verify that is the case.

[pchickey]

for now you need to use add -Scommon to the invocation of the wasmtime-cli (in 16.0 and up), unless you built the proxy world program with the (new, not documented) special wasi_snapshot_preview1.proxy.wasm adapter which is more strict about sticking to just the proxy world imports.

[guybedford]

Thanks @pchickey can confirm that works.

[guybedford]

Running a trace of the program, I'm seeing the following calls:

185 OUTPUT_STREAM_CREATE HTTP null undefined
185 -> 4
185 OUTPUT_STREAM_BLOCKING_WRITE_AND_FLUSH HTTP 4 Uint8Array(15) [
  72, 101, 108, 108, 111,
  32, 102, 114, 111, 109,
  32,  71, 111,  33,  10
]
185 -> 15n
185 HTTP_SERVER_SET_OUTGOING_RESPONSE undefined 1 { statusCode: 200, headers: [], streamId: 4 }
185 -> undefined

That is, I'm not actually seeing a call to OUTPUT_STREAM_DROP or to HTTP_OUTPUT_STREAM_FINISH to indicate the output is finished and the response is ended.

Will look into it more next week, but I think that's the issue here.

[squillace]

somehow I didn't add that we're spin 2.2 (canary to capture 12_05 or release now) and wasmtime 16. sorry, @guybedford, that I didn't upload the ocmponent, but it looks like you have it now. Thanks for having a look!

[squillace]

╭─ralph at ralph-HP-EliteBook-850-G1 in ~/hello-wasi-http-go on main✘✘✘
╰─± jco serve --jco-trace main_2023_12_05.component.wasm
Server listening on 8000...
[module="wasi:http/incoming-handler@0.2.0-rc-2023-12-05", function="handle"] call request=[object Object], response-out=[object Object]
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[constructor]fields"] call
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[constructor]fields"] return result={"_id":2}
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[constructor]outgoing-response"] call headers=0
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[constructor]outgoing-response"] return result={"_id":1}
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[method]outgoing-response.set-status-code"] call self=0, status-code=200
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[method]outgoing-response.set-status-code"] return result={"tag":"ok"}
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[method]outgoing-response.body"] call self=0
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[method]outgoing-response.body"] return result={"tag":"ok","val":{}}
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[method]outgoing-body.write"] call self=0
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[method]outgoing-body.write"] return result={"tag":"ok","val":{}}
[module="wasi:io/streams@0.2.0-rc-2023-11-10", function="[method]output-stream.blocking-write-and-flush"] call self=0, contents=67920
[module="wasi:io/streams@0.2.0-rc-2023-11-10", function="[method]output-stream.blocking-write-and-flush"] return result={"tag":"ok","val":"15"}
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[static]response-outparam.set"] call param=0, response=0
[module="wasi:http/types@0.2.0-rc-2023-12-05", function="[static]response-outparam.set"] return
[module="wasi:http/incoming-handler@0.2.0-rc-2023-12-05", function="handle"] return

look at those odd middle parts... should they be 11-10?

[squillace]

it must be something to do with the tinygo build and composition.... both Dan's rust and Joel's python wasi:http components work. Only @Mossaka 's tinygo one doesn't....

[Mossaka]

I'm not actually seeing a call to OUTPUT_STREAM_DROP or to HTTP_OUTPUT_STREAM_FINISH to indicate the output is finished and the response is ended.

I don't think the Go code called drop. I will take a look at it today.

[guybedford]

It's good to debug components that don't dispose resources on the JCO side though. The fix is exactly creating a cleanup phase to dispose anything undisposed by a component at the end of its lifecycle, but yes strictly speaking I think the component might be invalid if it isn't dropping its resources.

[Mossaka]

We can close this now since I've made the TinyGo component working with jco.

[squillace]

OK, Joe's added a Drop() call and gotten that to work, so this bug should be renamed to be sample case for gracefully handling failures to drop the connection. I note that wasmtime handles this cleanly, and jco probably should as well. My repo will remain the same for building that test.....

@Mossaka btw I cannot compile your solution for 12_05 still because the import at the top of the .go file points at a package that does not have Drop in it. I think you changed that locally but didn't push that to the import package..... my guess.

[squillace]

@guybedford do you want me to open a new issue with that repo branch as the non-closing example? OR we can just make one that doesn't have Drop() in it.