From d9f36e389bfb1f947b1a6be35e7b760f8dc6626d Mon Sep 17 00:00:00 2001 From: Caio Casimiro Date: Wed, 20 Sep 2023 11:58:39 +0100 Subject: [PATCH] tests(*) add suites for client/upstream connection aborts Co-Authored-By: Thibault Charbonnier --- .../hfuncs/102-proxy_send_local_response.t | 4 + t/04-openresty/ffi/103-proxy_wasm_attach.t | 4 + t/05-others/010-client_connection_abort.t | 131 ++++++++++++++++++ t/05-others/011-upstream_connection_abort.t | 89 ++++++++++++ .../proxy-wasm-tests/hostcalls/src/filter.rs | 6 + .../proxy-wasm-tests/on-phases/src/filter.rs | 18 ++- 6 files changed, 251 insertions(+), 1 deletion(-) create mode 100644 t/05-others/010-client_connection_abort.t create mode 100644 t/05-others/011-upstream_connection_abort.t 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 index 9782e9345..94a19183c 100644 --- a/t/03-proxy_wasm/hfuncs/102-proxy_send_local_response.t +++ b/t/03-proxy_wasm/hfuncs/102-proxy_send_local_response.t @@ -143,6 +143,7 @@ qr/.*? on_request_headers, 2 headers, .* .*? testing in "RequestHeaders", .* .*? on_response_headers, 5 headers, .* .*? on_response_body, 0 bytes, eof: true, .* +.*? on_done.* .*? on_log.*/ --- no_error_log [error] @@ -248,6 +249,7 @@ qr/.*? on_request_headers, 2 headers, .* .*? testing in "RequestHeaders", .* .*? on_response_headers, 16 headers, .* .*? on_response_body, 0 bytes, eof: true, .* +.*? on_done.* .*? on_log.*/ --- no_error_log [error] @@ -467,7 +469,9 @@ qr/.*? on_request_headers, \d+ headers.* .*? on_response_headers, \d+ headers.* .*? on_response_body, \d+ bytes, eof: true.* .*? on_response_body, \d+ bytes, eof: true.* +.*? on_done.* .*? on_log.* +.*? on_done.* .*? on_log.*/ --- no_error_log [error] diff --git a/t/04-openresty/ffi/103-proxy_wasm_attach.t b/t/04-openresty/ffi/103-proxy_wasm_attach.t index 2c854d10a..0248f4eb1 100644 --- a/t/04-openresty/ffi/103-proxy_wasm_attach.t +++ b/t/04-openresty/ffi/103-proxy_wasm_attach.t @@ -105,6 +105,7 @@ qr/^[^#]*#0 on_vm_start[^#]* #\d+ on_response_headers, 5 headers[^#]* #\d+ on_response_body, 3 bytes, eof: false[^#]* #\d+ on_response_body, 0 bytes, eof: true[^#]* +#\d+ on_done[^#]* #\d+ on_log[^#]*$/ --- error_log eval qr/\[error\] .*? previous plan already attached/ @@ -156,6 +157,7 @@ qr/^[^#]*#0 on_vm_start[^#]* #\d+ on_response_headers, 5 headers[^#]* #\d+ on_response_body, 3 bytes, eof: false[^#]* #\d+ on_response_body, 0 bytes, eof: true[^#]* +#\d+ on_done[^#]* #\d+ on_log[^#]*$/ --- no_error_log [error] @@ -207,6 +209,7 @@ qr/^[^#]*#0 on_vm_start[^#]* #\d+ on_response_headers, 5 headers[^#]* #\d+ on_response_body, 3 bytes, eof: false[^#]* #\d+ on_response_body, 0 bytes, eof: true[^#]* +#\d+ on_done[^#]* #\d+ on_log[^#]*$/ --- no_error_log [error] @@ -258,6 +261,7 @@ qr/^[^#]*#0 on_vm_start[^#]* #\d+ on_response_headers, 5 headers[^#]* #\d+ on_response_body, 3 bytes, eof: false[^#]* #\d+ on_response_body, 0 bytes, eof: true[^#]* +#\d+ on_done[^#]* #\d+ on_log[^#]*$/ --- no_error_log [error] diff --git a/t/05-others/010-client_connection_abort.t b/t/05-others/010-client_connection_abort.t new file mode 100644 index 000000000..d49637f5a --- /dev/null +++ b/t/05-others/010-client_connection_abort.t @@ -0,0 +1,131 @@ +# vim:set ft= ts=4 sts=4 sw=4 et fdm=marker: + +use strict; +use lib '.'; +use t::TestWasm; + +if ($ENV{TEST_NGINX_USE_HUP}) { + plan(skip_all => "unavailable in HUP mode"); + +} else { + plan tests => repeat_each() * (blocks() * 4); +} + +run_tests(); + +__DATA__ + +=== TEST 1: client connection abort - wasm_call +Nginx response filters are not invoked on the produced HTTP 499 response. +--- skip_no_debug: 4 +--- wasm_modules: ngx_rust_tests +--- tcp_listen: $TEST_NGINX_UNIX_SOCKET +--- tcp_reply eval +sub { + return ["HTTP/1.1 200 OK\r\n", + "Connection: close\r\n", + "Content-Length: 0\r\n", + "\r\n"]; +} +--- config + location /t { + wasm_call content ngx_rust_tests log_notice_hello; + wasm_call header_filter ngx_rust_tests log_notice_hello; + wasm_call body_filter ngx_rust_tests log_notice_hello; + proxy_pass http://unix:$TEST_NGINX_UNIX_SOCKET:/; + } +--- shutdown +--- ignore_response +--- grep_error_log eval: qr/(client prematurely closed|(wasm ops calling .*? in .*? phase))/ +--- grep_error_log_out eval +qr/wasm ops calling "ngx_rust_tests\.log_notice_hello" in "content" phase +client prematurely closed\Z/ +--- no_error_log +header_filter +body_filter +[error] + + + +=== TEST 2: client connection abort - chained filters +Filters on aborted client connections do not execute response phases. +--- wasm_modules: on_phases +--- tcp_listen: $TEST_NGINX_UNIX_SOCKET +--- tcp_reply eval +sub { + return ["HTTP/1.1 200 OK\r\n", + "Connection: close\r\n", + "Content-Length: 0\r\n", + "\r\n"]; +} +--- config + location /t { + proxy_wasm on_phases; + proxy_wasm on_phases; + proxy_pass http://unix:$TEST_NGINX_UNIX_SOCKET:/; + } +--- shutdown +--- ignore_response +--- grep_error_log eval: qr/\[info\] .*? ((client prematurely closed)|on_request_headers|on_response_headers|on_log|on_done|on_http_call_response.*)/ +--- grep_error_log_out eval +qr/\A\[info\] .*? on_request_headers +\[info\] .*? on_request_headers +\[info\] .*? reported that client prematurely closed +\[info\] .*? on_done +\[info\] .*? on_log +\[info\] .*? on_done +\[info\] .*? on_log\Z/ +--- no_error_log +on_response +[error] +[crit] + + + +=== TEST 3: client connection abort - chained filters with HTTP dispatch +Filters with pending dispatch calls on aborted client connections await for +response. +--- load_nginx_modules: ngx_http_echo_module +--- wasm_modules: hostcalls +--- http_config eval +qq{ + server { + listen unix:$ENV{TEST_NGINX_UNIX_SOCKET}; + + location / { + return 200; + } + + location /sleep { + echo_sleep 0.3; + echo_status 201; + } + } +} +--- config + location /t { + proxy_wasm hostcalls 'test=/t/dispatch_http_call \ + host=unix:$TEST_NGINX_UNIX_SOCKET \ + path=/'; + proxy_wasm hostcalls 'test=/t/dispatch_http_call \ + host=unix:$TEST_NGINX_UNIX_SOCKET \ + path=/sleep'; + proxy_pass http://unix:$TEST_NGINX_UNIX_SOCKET:/; + } +--- shutdown +--- ignore_response +--- grep_error_log eval: qr/\[info\] .*? ((client prematurely closed)|on_request_headers|on_response_headers|on_log|on_done|on_http_call_response.*)/ +--- grep_error_log_out eval +qr/\A\[info\] .*? on_request_headers +\[info\] .*? on_http_call_response \(id: \d+, status: 200[^*].* +\[info\] .*? on_request_headers +\[info\] .*? on_http_call_response \(id: \d+, status: 201[^*].* +\[info\] .*? reported that client prematurely closed +\[info\] .*? on_done +\[info\] .*? on_log +\[info\] .*? on_done +\[info\] .*? on_log\Z/ +--- no_error_log +[error] +[crit] +[emerg] diff --git a/t/05-others/011-upstream_connection_abort.t b/t/05-others/011-upstream_connection_abort.t new file mode 100644 index 000000000..86703b0c7 --- /dev/null +++ b/t/05-others/011-upstream_connection_abort.t @@ -0,0 +1,89 @@ +# vim:set ft= ts=4 sts=4 sw=4 et fdm=marker: + +use strict; +use lib '.'; +use t::TestWasm; + +skip_valgrind(); + +if ($ENV{TEST_NGINX_USE_HUP}) { + plan(skip_all => "unavailable in HUP mode"); + +} else { + plan tests => repeat_each() * (blocks() * 4); +} + +run_tests(); + +__DATA__ + +=== TEST 1: upstream connection abort - wasm_call +Calls on aborted upstream connections execute response phases on the produced +HTTP 502 response. +--- skip_no_debug: 4 +--- wasm_modules: ngx_rust_tests +--- tcp_listen: $TEST_NGINX_UNIX_SOCKET +--- tcp_shutdown: 2 +--- tcp_reply eval +sub { + return ["HTTP/1.1 100 OK\r\n", + "Connection: close\r\n", + "Content-Length: 0\r\n", + "\r\n"]; +} +--- config + location /t { + wasm_call header_filter ngx_rust_tests log_notice_hello; + wasm_call body_filter ngx_rust_tests log_notice_hello; + proxy_pass http://unix:$TEST_NGINX_UNIX_SOCKET:/; + } +--- error_code: 502 +--- ignore_response +--- grep_error_log eval: qr/(upstream prematurely closed|(wasm ops calling .*? in .*? phase))/ +--- grep_error_log_out eval +qr/\Aupstream prematurely closed +wasm ops calling "ngx_rust_tests\.log_notice_hello" in "header_filter" phase +wasm ops calling "ngx_rust_tests\.log_notice_hello" in "body_filter" phase\Z/ +--- no_error_log +[crit] +[emerg] +[alert] + + + +=== TEST 2: upstream connection abort - chained filters +Filters on aborted upstream connections execute response phases on the produced +HTTP 502 response. +--- wasm_modules: on_phases +--- tcp_listen: $TEST_NGINX_UNIX_SOCKET +--- tcp_shutdown: 2 +--- tcp_reply eval +sub { + return ["HTTP/1.1 100 OK\r\n", + "Connection: close\r\n", + "Content-Length: 0\r\n", + "\r\n"]; +} +--- config + location /t { + proxy_wasm on_phases; + proxy_wasm on_phases; + proxy_pass http://unix:$TEST_NGINX_UNIX_SOCKET:/; + } +--- error_code: 502 +--- ignore_response +--- grep_error_log eval: qr/\[(error|info)\] .*? ((upstream prematurely closed)|on_request_headers|on_response_headers|on_log|on_done|on_http_call_response.*)/ +--- grep_error_log_out eval +qr/\A\[info\] .*? on_request_headers +\[info\] .*? on_request_headers +\[error\] .*? upstream prematurely closed +\[info\] .*? on_response_headers +\[info\] .*? on_response_headers +\[info\] .*? on_done +\[info\] .*? on_log +\[info\] .*? on_done +\[info\] .*? on_log\Z/ +--- no_error_log +[crit] +[emerg] +[alert] diff --git a/t/lib/proxy-wasm-tests/hostcalls/src/filter.rs b/t/lib/proxy-wasm-tests/hostcalls/src/filter.rs index 3c305ee85..3c61dcc14 100644 --- a/t/lib/proxy-wasm-tests/hostcalls/src/filter.rs +++ b/t/lib/proxy-wasm-tests/hostcalls/src/filter.rs @@ -105,6 +105,12 @@ impl Context for TestHttp { self.resume_http_request() } + + fn on_done(&mut self) -> bool { + info!("[hostcalls] on_done"); + + true + } } impl HttpContext for TestHttp { diff --git a/t/lib/proxy-wasm-tests/on-phases/src/filter.rs b/t/lib/proxy-wasm-tests/on-phases/src/filter.rs index 447cc1367..11fc304c3 100644 --- a/t/lib/proxy-wasm-tests/on-phases/src/filter.rs +++ b/t/lib/proxy-wasm-tests/on-phases/src/filter.rs @@ -109,7 +109,23 @@ impl OnPhases { } } -impl Context for OnPhases {} +impl Context for OnPhases { + fn on_done(&mut self) -> bool { + info!("#{} on_done", self.context_id); + + let log_msg = self + .config + .get("log_msg") + .map_or(String::new(), |s| s.to_string()); + + if !log_msg.is_empty() { + info!("#{} log_msg: {}", self.context_id, log_msg); + } + + true + } +} + impl HttpContext for OnPhases { fn on_http_request_headers(&mut self, nheaders: usize, _eof: bool) -> Action { info!(