Stream: git-wasmtime

Topic: wasmtime / issue #7612 Wasmtime serve gives an Error but ...

view this post on Zulip Wasmtime GitHub notifications bot (Nov 30 2023 at 00:34):

Mossaka added the bug label to Issue #7612.

view this post on Zulip Wasmtime GitHub notifications bot (Nov 30 2023 at 00:34):

Mossaka opened issue #7612:

I am using wasmtime 15 the serve command for a Go WASI HTTP component. The component WIT looks like

package root:component

world root {
  import wasi:clocks/wall-clock@0.2.0-rc-2023-11-10
  import wasi:clocks/monotonic-clock@0.2.0-rc-2023-11-10
  import wasi:io/error@0.2.0-rc-2023-11-10
  import wasi:io/streams@0.2.0-rc-2023-11-10
  import wasi:cli/stdout@0.2.0-rc-2023-11-10
  import wasi:cli/stderr@0.2.0-rc-2023-11-10
  import wasi:cli/stdin@0.2.0-rc-2023-11-10
  import wasi:http/types@0.2.0-rc-2023-11-10
  import wasi:filesystem/types@0.2.0-rc-2023-11-10
  import wasi:filesystem/preopens@0.2.0-rc-2023-11-10
  import wasi:sockets/tcp@0.2.0-rc-2023-11-10
  import wasi:cli/environment@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-input@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-output@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-stdin@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-stdout@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-stderr@0.2.0-rc-2023-11-10

  export wasi:http/incoming-handler@0.2.0-rc-2023-11-10
}

As you can tell, it is using the same version of the WASI HTTP as the wasmtime v15's using. Now when I serve the HTTP request and curl the 8080 endpoint, I got the following error message:

2023-11-30T00:31:14.242114Z ERROR wasmtime_cli::commands::serve: [3] :: Error {
    context: "error while executing at wasm backtrace:\n    0: 0x55d34 - wit-component:shim!indirect-wasi:http/types@0.2.0-rc-2023-11-10-[static]outgoing-body.finish\n    1: 0xb11b - <unknown>!wasi_http_0_2_0_rc_2023_11_10_types_static_outgoing_body_finish\n    2: 0x8e1a - <unknown>!exports_wasi_http_0_2_0_rc_2023_11_10_incoming_handler_handle\n    3: 0xb5be - <unknown>!__wasm_export_exports_wasi_http_0_2_0_rc_2023_11_10_incoming_handler_handle\nnote: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable may show more debugging information",
    source: HasChildren,
}

But my curl returns status code 200 and expected response body:

 curl http://localhost:8080 -vvv
*   Trying 127.0.0.1:8080...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET / HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/8.1.2
> Accept: */*
>
< HTTP/1.1 200 OK
< transfer-encoding: chunked
< date: Thu, 30 Nov 2023 00:31:13 GMT
<
Hello world from Go!!!

Expectation

If the response is 200 and the body is expected, then wasmtime shouldn't output Error.

view this post on Zulip Wasmtime GitHub notifications bot (Nov 30 2023 at 01:25):

pchickey commented on issue #7612:

We'll need to dig in a little deeper to debug here - can you add WASMTIME_LOG=wasmtime_wasi_http=trace and examine what is going on a bit more?

view this post on Zulip Wasmtime GitHub notifications bot (Nov 30 2023 at 01:48):

Mossaka commented on issue #7612:

This is what WASMTIME_LOG=trace shows

2023-11-30T01:47:47.658704Z  INFO wasmtime_cli::commands::serve: Listening on 0.0.0.0:8080
2023-11-30T01:47:49.748585Z TRACE hyper::proto::h1::conn: Conn::read_head
2023-11-30T01:47:49.748617Z TRACE hyper::proto::h1::io: received 77 bytes
2023-11-30T01:47:49.748635Z TRACE parse_headers: hyper::proto::h1::role: Request.parse bytes=77
2023-11-30T01:47:49.748644Z TRACE parse_headers: hyper::proto::h1::role: Request.parse Complete(77)
2023-11-30T01:47:49.748659Z DEBUG hyper::proto::h1::io: parsed 3 headers
2023-11-30T01:47:49.748661Z DEBUG hyper::proto::h1::conn: incoming body is empty
2023-11-30T01:47:49.748675Z TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: KeepAlive, writing: Init, keep_alive: Busy }
2023-11-30T01:47:49.748686Z  INFO wasmtime_cli::commands::serve: Request 0 handling GET to http://127.0.0.1:8080/
2023-11-30T01:47:49.748926Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]fields"}: wasmtime_wasi_http::bindings::wasi::http::types: call
2023-11-30T01:47:49.748936Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]fields"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Resource { rep: 5, state: "own (not in table)" })
2023-11-30T01:47:49.748952Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]outgoing-response"}: wasmtime_wasi_http::bindings::wasi::http::types: call headers=Resource { rep: 5, state: "own (not in table)" }
2023-11-30T01:47:49.748962Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]outgoing-response"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Resource { rep: 6, state: "own (not in table)" })
2023-11-30T01:47:49.748973Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.set-status-code"}: wasmtime_wasi_http::bindings::wasi::http::types: call self_=Resource { rep: 6, state: "borrow" } status_code=200
2023-11-30T01:47:49.748980Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.set-status-code"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Ok(()))
2023-11-30T01:47:49.748991Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.body"}: wasmtime_wasi_http::bindings::wasi::http::types: call self_=Resource { rep: 6, state: "borrow" }
2023-11-30T01:47:49.748998Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.body"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Ok(Resource { rep: 7, state: "own (not in table)" }))
2023-11-30T01:47:49.749013Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]response-outparam.set"}: wasmtime_wasi_http::bindings::wasi::http::types: call param=Resource { rep: 4, state: "own (not in table)" } response=Ok(Resource { rep: 6, state: "own (not in table)" })
2023-11-30T01:47:49.749023Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]response-outparam.set"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(())
2023-11-30T01:47:49.749032Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-body.write"}: wasmtime_wasi_http::bindings::wasi::http::types: call self_=Resource { rep: 7, state: "borrow" }
2023-11-30T01:47:49.749038Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-body.write"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Ok(Resource { rep: 8, state: "own (not in table)" }))
2023-11-30T01:47:49.749084Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="streams" function="[method]output-stream.blocking-write-and-flush"}: wasmtime_wasi::preview2::bindings::wasi::io::streams: call self_=Resource { rep: 8, state: "borrow" } contents=[72, 101, 108, 108, 111, 32, 119, 111, 114, 108, 100, 32, 102, 114, 111, 109, 32, 71, 111, 33, 33, 33, 10]
2023-11-30T01:47:49.749099Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="streams" function="[method]output-stream.blocking-write-and-flush"}: wasmtime_wasi::preview2::bindings::wasi::io::streams: return result=Ok(())
2023-11-30T01:47:49.749136Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]outgoing-body.finish"}: wasmtime_wasi_http::bindings::wasi::http::types: call this=Resource { rep: 7, state: "own (not in table)" } trailers=None
2023-11-30T01:47:49.749142Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]outgoing-body.finish"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Err(entry still has children)
2023-11-30T01:47:49.749153Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: ====== Capturing Backtrace ======
2023-11-30T01:47:49.749156Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: === Tracing through contiguous sequence of Wasm frames ===
2023-11-30T01:47:49.749160Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: trampoline_sp = 0x0000000104aefb50
2023-11-30T01:47:49.749163Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace:    initial pc = 0x00000001048aeb6c
2023-11-30T01:47:49.749190Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace:    initial fp = 0x0000000104aef990
2023-11-30T01:47:49.749198Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749202Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048aeb6c
2023-11-30T01:47:49.749220Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aef990
2023-11-30T01:47:49.749225Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749228Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048a8ecc
2023-11-30T01:47:49.749231Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aefa00
2023-11-30T01:47:49.749234Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749236Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048a53a8
2023-11-30T01:47:49.749239Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aefb10
2023-11-30T01:47:49.749258Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749263Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048a9710
2023-11-30T01:47:49.749266Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aefb40
2023-11-30T01:47:49.749273Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: === Done tracing contiguous sequence of Wasm frames ===
2023-11-30T01:47:49.749276Z TRACE wit-bi
[message truncated]

view this post on Zulip Wasmtime GitHub notifications bot (Nov 30 2023 at 01:50):

Mossaka edited a comment on issue #7612:

This is what WASMTIME_LOG=trace shows

2023-11-30T01:47:47.658704Z  INFO wasmtime_cli::commands::serve: Listening on 0.0.0.0:8080
2023-11-30T01:47:49.748585Z TRACE hyper::proto::h1::conn: Conn::read_head
2023-11-30T01:47:49.748617Z TRACE hyper::proto::h1::io: received 77 bytes
2023-11-30T01:47:49.748635Z TRACE parse_headers: hyper::proto::h1::role: Request.parse bytes=77
2023-11-30T01:47:49.748644Z TRACE parse_headers: hyper::proto::h1::role: Request.parse Complete(77)
2023-11-30T01:47:49.748659Z DEBUG hyper::proto::h1::io: parsed 3 headers
2023-11-30T01:47:49.748661Z DEBUG hyper::proto::h1::conn: incoming body is empty
2023-11-30T01:47:49.748675Z TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: KeepAlive, writing: Init, keep_alive: Busy }
2023-11-30T01:47:49.748686Z  INFO wasmtime_cli::commands::serve: Request 0 handling GET to http://127.0.0.1:8080/
2023-11-30T01:47:49.748926Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]fields"}: wasmtime_wasi_http::bindings::wasi::http::types: call
2023-11-30T01:47:49.748936Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]fields"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Resource { rep: 5, state: "own (not in table)" })
2023-11-30T01:47:49.748952Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]outgoing-response"}: wasmtime_wasi_http::bindings::wasi::http::types: call headers=Resource { rep: 5, state: "own (not in table)" }
2023-11-30T01:47:49.748962Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[constructor]outgoing-response"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Resource { rep: 6, state: "own (not in table)" })
2023-11-30T01:47:49.748973Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.set-status-code"}: wasmtime_wasi_http::bindings::wasi::http::types: call self_=Resource { rep: 6, state: "borrow" } status_code=200
2023-11-30T01:47:49.748980Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.set-status-code"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Ok(()))
2023-11-30T01:47:49.748991Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.body"}: wasmtime_wasi_http::bindings::wasi::http::types: call self_=Resource { rep: 6, state: "borrow" }
2023-11-30T01:47:49.748998Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-response.body"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Ok(Resource { rep: 7, state: "own (not in table)" }))
2023-11-30T01:47:49.749013Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]response-outparam.set"}: wasmtime_wasi_http::bindings::wasi::http::types: call param=Resource { rep: 4, state: "own (not in table)" } response=Ok(Resource { rep: 6, state: "own (not in table)" })
2023-11-30T01:47:49.749023Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]response-outparam.set"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(())
2023-11-30T01:47:49.749032Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-body.write"}: wasmtime_wasi_http::bindings::wasi::http::types: call self_=Resource { rep: 7, state: "borrow" }
2023-11-30T01:47:49.749038Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[method]outgoing-body.write"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Ok(Ok(Resource { rep: 8, state: "own (not in table)" }))
2023-11-30T01:47:49.749084Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="streams" function="[method]output-stream.blocking-write-and-flush"}: wasmtime_wasi::preview2::bindings::wasi::io::streams: call self_=Resource { rep: 8, state: "borrow" } contents=[72, 101, 108, 108, 111, 32, 119, 111, 114, 108, 100, 32, 102, 114, 111, 109, 32, 71, 111, 33, 33, 33, 10]
2023-11-30T01:47:49.749099Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="streams" function="[method]output-stream.blocking-write-and-flush"}: wasmtime_wasi::preview2::bindings::wasi::io::streams: return result=Ok(())
2023-11-30T01:47:49.749136Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]outgoing-body.finish"}: wasmtime_wasi_http::bindings::wasi::http::types: call this=Resource { rep: 7, state: "own (not in table)" } trailers=None
2023-11-30T01:47:49.749142Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}:wit-bindgen import{module="types" function="[static]outgoing-body.finish"}: wasmtime_wasi_http::bindings::wasi::http::types: return result=Err(entry still has children)
2023-11-30T01:47:49.749153Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: ====== Capturing Backtrace ======
2023-11-30T01:47:49.749156Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: === Tracing through contiguous sequence of Wasm frames ===
2023-11-30T01:47:49.749160Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: trampoline_sp = 0x0000000104aefb50
2023-11-30T01:47:49.749163Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace:    initial pc = 0x00000001048aeb6c
2023-11-30T01:47:49.749190Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace:    initial fp = 0x0000000104aef990
2023-11-30T01:47:49.749198Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749202Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048aeb6c
2023-11-30T01:47:49.749220Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aef990
2023-11-30T01:47:49.749225Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749228Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048a8ecc
2023-11-30T01:47:49.749231Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aefa00
2023-11-30T01:47:49.749234Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749236Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048a53a8
2023-11-30T01:47:49.749239Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aefb10
2023-11-30T01:47:49.749258Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: --- Tracing through one Wasm frame ---
2023-11-30T01:47:49.749263Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: pc = 0x1048a9710
2023-11-30T01:47:49.749266Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: fp = 0x104aefb40
2023-11-30T01:47:49.749273Z TRACE wit-bindgen export{module="wasi:http/incoming-handler@0.2.0-rc-2023-11-10" function="handle"}: wasmtime_runtime::traphandlers::backtrace: === Done tracing contiguous sequence of Wasm frames ===
2023-11-30T01:47:49.749276Z TRACE
[message truncated]

view this post on Zulip Wasmtime GitHub notifications bot (Nov 30 2023 at 06:51):

bjorn3 commented on issue #7612:

Why is doesn't return a 500 internal server error is I think because by the time it crashes the http headers and the response body have already been written. Http doesn't allow changing the status code in the middle of a response, only at the start.

As for the crash, I'm not really familiar with how wasi preview 2 works, but is it possible that you need to drop the output-stream before calling outgoing-body.finish?

view this post on Zulip Wasmtime GitHub notifications bot (Nov 30 2023 at 16:33):

pchickey commented on issue #7612:

Yes, you need to drop the output-stream derived from outgoing-body before calling outgoing-body.finish. The wit docs explain this restriction: https://github.com/WebAssembly/wasi-http/blob/main/wit/types.wit#L493-L528

re Err(entry still has children): some resources are so-called "child resources" of others, e.g. https://github.com/WebAssembly/wasi-io/blob/main/wit/streams.wit#L85-L87. This introduces a rule that, before the parent resource can be dropped, all child resources must be dropped. This also comes up in a bunch of places in the http interfaces as well.

The child/parent wording admittedly isn't perfect, but one way to think about it is that a child resource is an "interior pointer" of the parent - it cant becomes invalid after the parent is freed. This interiority is literally true in the implementation of these resources in the host, but more importantly it is required to give a correct implementation of the interfaces. The parent-child relationship of the output-stream of an outgoing-body ensures that no further writes to the body contents are possible when finish sends the trailers. This is even more important for incoming-body's input-stream, where the child stream being dropped before incoming-body.finish means that the http connection can implement backpressure at all.

view this post on Zulip Wasmtime GitHub notifications bot (Jan 17 2024 at 01:26):

Mossaka closed issue #7612:

I am using wasmtime 15 the serve command for a Go WASI HTTP component. The component WIT looks like

package root:component

world root {
  import wasi:clocks/wall-clock@0.2.0-rc-2023-11-10
  import wasi:clocks/monotonic-clock@0.2.0-rc-2023-11-10
  import wasi:io/error@0.2.0-rc-2023-11-10
  import wasi:io/streams@0.2.0-rc-2023-11-10
  import wasi:cli/stdout@0.2.0-rc-2023-11-10
  import wasi:cli/stderr@0.2.0-rc-2023-11-10
  import wasi:cli/stdin@0.2.0-rc-2023-11-10
  import wasi:http/types@0.2.0-rc-2023-11-10
  import wasi:filesystem/types@0.2.0-rc-2023-11-10
  import wasi:filesystem/preopens@0.2.0-rc-2023-11-10
  import wasi:sockets/tcp@0.2.0-rc-2023-11-10
  import wasi:cli/environment@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-input@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-output@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-stdin@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-stdout@0.2.0-rc-2023-11-10
  import wasi:cli/terminal-stderr@0.2.0-rc-2023-11-10

  export wasi:http/incoming-handler@0.2.0-rc-2023-11-10
}

As you can tell, it is using the same version of the WASI HTTP as the wasmtime v15's using. Now when I serve the HTTP request and curl the 8080 endpoint, I got the following error message:

2023-11-30T00:31:14.242114Z ERROR wasmtime_cli::commands::serve: [3] :: Error {
    context: "error while executing at wasm backtrace:\n    0: 0x55d34 - wit-component:shim!indirect-wasi:http/types@0.2.0-rc-2023-11-10-[static]outgoing-body.finish\n    1: 0xb11b - <unknown>!wasi_http_0_2_0_rc_2023_11_10_types_static_outgoing_body_finish\n    2: 0x8e1a - <unknown>!exports_wasi_http_0_2_0_rc_2023_11_10_incoming_handler_handle\n    3: 0xb5be - <unknown>!__wasm_export_exports_wasi_http_0_2_0_rc_2023_11_10_incoming_handler_handle\nnote: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable may show more debugging information",
    source: HasChildren,
}

But my curl returns status code 200 and expected response body:

 curl http://localhost:8080 -vvv
*   Trying 127.0.0.1:8080...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET / HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/8.1.2
> Accept: */*
>
< HTTP/1.1 200 OK
< transfer-encoding: chunked
< date: Thu, 30 Nov 2023 00:31:13 GMT
<
Hello world from Go!!!

Expectation

If the response is 200 and the body is expected, then wasmtime shouldn't output Error.

view this post on Zulip Wasmtime GitHub notifications bot (Jan 17 2024 at 01:26):

Mossaka commented on issue #7612:

Can close this issue now as it's been resolved.

Last updated: Nov 22 2024 at 16:03 UTC