chore(wasm): testing Kong/ngx_wasm_module#546

[flrgh]

Created to track testing of Kong/ngx_wasm_module#546

Do not merge me.

KAG-4671

[flrgh]

Testing locally, my initial findings are there appears to be something going wrong with sending a response from a filter. This test and others like it are failing with a timeout as the client never receive a response.

In master I have the following error.log output for the test:

2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm] "tests" filter reusing instance (ictx: 000000000185D948, store: 000000000123BD28)
2024/05/28 11:34:47 [info] 3286943#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm root] create_http_context (id: #1), client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "b395de695a18a75825b491613c682167"
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm]["tests" #1] filter 1/1 resuming "on_request_headers" step in "rewrite" phase
2024/05/28 11:34:47 [info] 3286943#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm http] on_request_headers (5 headers, eof: false), client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "b395de695a18a75825b491613c682167"
2024/05/28 11:34:47 [info] 3286943#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm] testing in "RequestHeaders", client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "b395de695a18a75825b491613c682167"
2024/05/28 11:34:47 [info] 3286943#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm] kong.client.protocol: ""http"", client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "b395de695a18a75825b491613c682167"
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm] setting next action: pwctx->action = "DONE" (pwctx: 0000000005AED380)
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm] setting next action: pwctx->action = "CONTINUE" (pwctx: 0000000005AED380)
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm] resetting filter chain: pwctx->exec_index 0 to 0 (pwctx: 0000000005AED380)
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm]["tests" #1] filter 1/1 resuming "on_response_headers" step in "header_filter" phase
2024/05/28 11:34:47 [info] 3286943#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm http] on_response_headers (8 headers, eof: false), client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "b395de695a18a75825b491613c682167"
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm]["tests" #1] filter 1/1 resuming "on_response_body" step in "body_filter" phase
2024/05/28 11:34:47 [info] 3286943#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm http] on_response_body (5 bytes, eof true), client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "b395de695a18a75825b491613c682167"
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm]["tests" #1] filter 1/1 resuming "on_log" step in "log" phase
2024/05/28 11:34:47 [info] 3286943#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm http] on_log while logging request, client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "b395de695a18a75825b491613c682167"
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm]["tests" #1] filter 1/1 resuming "on_done" step in "done" phase
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm]["tests" #1] filter 1/1 finalizing context
2024/05/28 11:34:47 [debug] 3286943#0: *2 [proxy-wasm] "tests" filter freeing context #1 (1/1)

Whereas in chore/wasm-test-lua-bridge-refactor we never seem to make it to the other phase handlers:

2024/05/28 11:37:07 [debug] 3317361#0: *2 [proxy-wasm] "tests" filter reusing instance (ictx: 000000000573C440, store: 0000000001038918)
2024/05/28 11:37:07 [info] 3317361#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm root] create_http_context (id: #1), client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "fdf27806b2ce595919ad0177a46c7c12"
2024/05/28 11:37:07 [debug] 3317361#0: *2 [proxy-wasm]["tests" #1] filter 1/1 resuming "on_request_headers" step in "access" phase
2024/05/28 11:37:07 [info] 3317361#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm http] on_request_headers (5 headers, eof: false), client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "fdf27806b2ce595919ad0177a46c7c12"
2024/05/28 11:37:07 [info] 3317361#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm] testing in "RequestHeaders", client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "fdf27806b2ce595919ad0177a46c7c12"
2024/05/28 11:37:07 [info] 3317361#0: *2 [proxy-wasm]["tests" #1] [proxy-wasm] kong.client.protocol: ""http"", client: 127.0.0.1, server: kong, request: "GET /single/status/200 HTTP/1.1", host: "0.0.0.0:9000", request_id: "fdf27806b2ce595919ad0177a46c7c12"
2024/05/28 11:37:07 [debug] 3317361#0: *2 [proxy-wasm] setting next action: pwctx->action = "DONE" (pwctx: 00000000049F0C20)
2024/05/28 11:37:07 [debug] 3317361#0: *2 [proxy-wasm] setting next action: pwctx->action = "CONTINUE" (pwctx: 00000000049F0C20)

[no more output after this]

Edit: this has been fixed

[flrgh]

Closing in favor of #13222