fix(proxy-wasm) always execute the whole filter chain on responses

Co-Authored-By: Caio Ramos Casimiro <[email protected]>
Kong · Oct 6, 2023 · 67c8214 · 67c8214
1 parent 89170ed
commit 67c8214
Show file tree

Hide file tree

Showing 6 changed files with 73 additions and 10 deletions.
diff --git a/src/common/proxy_wasm/ngx_proxy_wasm.c b/src/common/proxy_wasm/ngx_proxy_wasm.c
@@ -616,6 +616,7 @@ ngx_proxy_wasm_run_step(ngx_proxy_wasm_exec_t *pwexec,
 
     ictx->pwexec = pwexec;  /* set instance current pwexec */
     pwexec->ictx = ictx;    /* link pwexec to instance */
+    pwctx->step = step;
 
     /*
      * update instance log
@@ -732,8 +733,14 @@ ngx_proxy_wasm_resume(ngx_proxy_wasm_ctx_t *pwctx,
     case NGX_PROXY_WASM_STEP_TICK:
     case NGX_PROXY_WASM_STEP_DONE:
     case NGX_PROXY_WASM_STEP_RESP_BODY:
-    case NGX_PROXY_WASM_STEP_RESP_HEADERS:
     case NGX_PROXY_WASM_STEP_DISPATCH_RESPONSE:
+        break;
+    case NGX_PROXY_WASM_STEP_RESP_HEADERS:
+        if (pwctx->last_step < NGX_PROXY_WASM_STEP_RESP_HEADERS) {
+            /* first execution of response phases, ensure the chain is reset */
+            ngx_proxy_wasm_ctx_reset_chain(pwctx);
+        }
+
         break;
     default:
         if (step <= pwctx->last_step) {

diff --git a/src/common/proxy_wasm/ngx_proxy_wasm.h b/src/common/proxy_wasm/ngx_proxy_wasm.h
@@ -434,6 +434,18 @@ ngx_proxy_wasm_ctx_set_next_action(ngx_proxy_wasm_ctx_t *pwctx,
 }
 
 
+static ngx_inline void
+ngx_proxy_wasm_ctx_reset_chain(ngx_proxy_wasm_ctx_t *pwctx)
+{
+    ngx_proxy_wasm_log_error(NGX_LOG_DEBUG, pwctx->log, 0,
+                             "resetting filter chain: pwctx->exec_index "
+                             "%l to 0 (pwctx: %p)",
+                             pwctx->exec_index, pwctx);
+
+    pwctx->exec_index = 0;
+}
+
+
 static ngx_inline ngx_proxy_wasm_exec_t *
 ngx_proxy_wasm_instance2pwexec(ngx_wavm_instance_t *instance)
 {

diff --git a/src/common/proxy_wasm/ngx_proxy_wasm_host.c b/src/common/proxy_wasm/ngx_proxy_wasm_host.c
@@ -929,8 +929,11 @@ ngx_proxy_wasm_hfuncs_send_local_response(ngx_wavm_instance_t *instance,
     switch (rc) {
 
     case NGX_OK:
-        ngx_proxy_wasm_ctx_set_next_action(pwexec->parent,
-                                           NGX_PROXY_WASM_ACTION_DONE);
+        if (pwexec->parent->step != NGX_PROXY_WASM_STEP_DISPATCH_RESPONSE) {
+            ngx_proxy_wasm_ctx_set_next_action(pwexec->parent,
+                                               NGX_PROXY_WASM_ACTION_DONE);
+        }
+
         break;
 
     case NGX_ERROR:

diff --git a/t/03-proxy_wasm/hfuncs/102-proxy_send_local_response.t b/t/03-proxy_wasm/hfuncs/102-proxy_send_local_response.t
@@ -417,7 +417,38 @@ Hello world
 
 
 
-=== TEST 18: proxy_wasm - send_local_response() in chained filters
+=== TEST 18: proxy_wasm - send_local_response() executes all chained filters response steps
+should run all response steps of all chained filters
+--- wasm_modules: hostcalls
+--- config
+    location /t {
+        proxy_wasm hostcalls;
+        proxy_wasm hostcalls 'test=/t/send_local_response/body';
+        proxy_wasm hostcalls;
+    }
+--- response_body
+Hello world
+--- grep_error_log eval: qr/\[info\] .*? on_(request|response|log).*/
+--- grep_error_log_out eval
+qr/\A.*? on_request_headers, \d+ headers.*
+.*? on_request_headers, \d+ headers.*
+.*? on_response_headers, \d+ headers.*
+.*? on_response_headers, \d+ headers.*
+.*? on_response_headers, \d+ headers.*
+.*? on_response_body, \d+ bytes, eof: true.*
+.*? on_response_body, \d+ bytes, eof: true.*
+.*? on_response_body, \d+ bytes, eof: true.*
+.*? on_log.*
+.*? on_log.*
+.*? on_log/
+--- no_error_log
+[error]
+[crit]
+[alert]
+
+
+
+=== TEST 19: proxy_wasm - send_local_response() invoked twice in chained filters
 should interrupt the current phase, preventing "response already stashed"
 should still run all response phases
 --- wasm_modules: hostcalls
@@ -445,7 +476,7 @@ qr/.*? on_request_headers, \d+ headers.*
 
 
 
-=== TEST 19: proxy_wasm - send_local_response() in chained filters as a subrequest
+=== TEST 20: proxy_wasm - send_local_response() in chained filters as a subrequest
 should interrupt the current phase, preventing "response already stashed"
 should still run all response phases
 should not have a log phase (subrequest)

diff --git a/t/04-openresty/ffi/103-proxy_wasm_attach.t b/t/04-openresty/ffi/103-proxy_wasm_attach.t
@@ -451,7 +451,7 @@ bad opts.isolation value: -1
 --- error_code eval
 [200, 200]
 --- ignore_response_body
---- grep_error_log eval: qr/\*\d+.*?(resuming|new instance|reusing instance|finalizing|freeing|now|trap in|filter chain).*/
+--- grep_error_log eval: qr/\*\d+.*?(resuming|new instance|reusing instance|finalizing|freeing|now|trap in|initializing filter chain).*/
 --- grep_error_log_out eval
 [
 qr/\A\*\d+ proxy_wasm initializing filter chain \(nfilters: 1, isolation: 1\)[^#*]*
@@ -508,7 +508,7 @@ qr/\A\*\d+ proxy_wasm initializing filter chain \(nfilters: 1, isolation: 1\)[^#
 --- error_code eval
 [200, 200]
 --- ignore_response_body
---- grep_error_log eval: qr/(\*\d+.*?(resuming|new instance|reusing instance|finalizing|freeing|now|trap in|filter chain)|#\d+ on_(configure|vm_start)).*/
+--- grep_error_log eval: qr/(\*\d+.*?(resuming|new instance|reusing instance|finalizing|freeing|now|trap in|initializing filter chain)|#\d+ on_(configure|vm_start)).*/
 --- grep_error_log_out eval
 [
 qr/\A[^#]*#0 on_vm_start[^#*]*
@@ -573,7 +573,7 @@ qr/\A\*\d+ proxy_wasm initializing filter chain \(nfilters: 1, isolation: 2\)[^#
 --- error_code eval
 [200, 200]
 --- ignore_response_body
---- grep_error_log eval: qr/(\*\d+.*?(resuming|new instance|reusing instance|finalizing|freeing|now|trap in|filter chain)|#\d+ (on_configure|on_vm_start)).*/
+--- grep_error_log eval: qr/(\*\d+.*?(resuming|new instance|reusing instance|finalizing|freeing|now|trap in|initializing filter chain)|#\d+ (on_configure|on_vm_start)).*/
 --- grep_error_log_out eval
 [
 qr/\A[^#]*#0 on_vm_start[^#*]*

diff --git a/t/04-openresty/ffi/200-proxy_wasm_and_lua_sanity.t b/t/04-openresty/ffi/200-proxy_wasm_and_lua_sanity.t
@@ -240,11 +240,20 @@ GET \/headers HTTP\/.*
 Host: localhost:\d+.*
 Connection: close.*
 Content-Length: 0.*
+--- error_log eval
+qr/on_http_call_response \(id: \d+, status: 200, headers: 5, body_bytes: \d+, trailers: 0/
+--- grep_error_log eval: qr/\*\d+.*?\[proxy-wasm\].*?(resuming|freeing).*/
+--- grep_error_log_out eval
+qr/\A\*\d+ .*? filter 1\/1 resuming "on_request_headers" step in "rewrite" phase[^#*]*
+\*\d+ .*? filter 1\/1 resuming "on_dispatch_response" step in "access" phase[^#*]*
+\*\d+ .*? filter 1\/1 resuming "on_response_headers" step in "header_filter" phase[^#*]*
+\*\d+ .*? filter 1\/1 resuming "on_response_body" step in "body_filter" phase[^#*]*
+\*\d+ .*? filter 1\/1 resuming "on_log" step in "log" phase[^#*]*
+\*\d+ .*? filter 1\/1 resuming "on_done" step in "done" phase[^#*]*
+\*\d+ .*? filter freeing context #\d+ \(1\/1\)[^#*]*\Z/
 --- no_error_log
 [error]
 [crit]
-[emerg]
-[alert]
 
 
 
@@ -300,6 +309,7 @@ qr/on_http_call_response \(id: \d+, status: 200, headers: 5, body_bytes: \d+, tr
 --- grep_error_log_out eval
 qr/\A\*\d+ .*? filter 1\/1 resuming "on_request_headers" step in "rewrite" phase[^#*]*
 \*\d+ .*? filter 1\/1 resuming "on_dispatch_response" step in "access" phase[^#*]*
+\*\d+ .*? filter 1\/1 resuming "on_response_headers" step in "header_filter" phase[^#*]*
 \*\d+ .*? filter 1\/1 resuming "on_response_body" step in "body_filter" phase[^#*]*
 \*\d+ .*? filter 1\/1 resuming "on_response_body" step in "body_filter" phase[^#*]*
 \*\d+ .*? filter 1\/1 resuming "on_log" step in "log" phase[^#*]*