diff --git a/bin/varnishd/cache/cache_transport.h b/bin/varnishd/cache/cache_transport.h index 0e5f03c65ef..79f0a7b2d5b 100644 --- a/bin/varnishd/cache/cache_transport.h +++ b/bin/varnishd/cache/cache_transport.h @@ -44,6 +44,7 @@ typedef void vtr_sess_panic_f (struct vsb *, const struct sess *); typedef void vtr_req_panic_f (struct vsb *, const struct req *); typedef void vtr_req_fail_f (struct req *, stream_close_t); typedef void vtr_reembark_f (struct worker *, struct req *); +typedef int vtr_poll_f (struct req *); typedef int vtr_minimal_response_f (struct req *, uint16_t status); struct transport { @@ -64,6 +65,7 @@ struct transport { vtr_sess_panic_f *sess_panic; vtr_req_panic_f *req_panic; vtr_reembark_f *reembark; + vtr_poll_f *poll; vtr_minimal_response_f *minimal_response; VTAILQ_ENTRY(transport) list; diff --git a/bin/varnishd/cache/cache_vrt_vcl.c b/bin/varnishd/cache/cache_vrt_vcl.c index c98274e9d57..85b594b7d86 100644 --- a/bin/varnishd/cache/cache_vrt_vcl.c +++ b/bin/varnishd/cache/cache_vrt_vcl.c @@ -42,6 +42,7 @@ #include "vbm.h" #include "cache_director.h" +#include "cache_transport.h" #include "cache_vcl.h" #include "vcc_interface.h" @@ -521,6 +522,40 @@ VRT_VCL_Allow_Discard(struct vclref **refp) FREE_OBJ(ref); } +/*-------------------------------------------------------------------- + */ + +static int +req_poll(struct worker *wrk, struct req *req) +{ + struct req *top; + + /* NB: Since a fail transition leads to vcl_synth, the request may be + * short-circuited twice. + */ + if (req->req_reset) { + wrk->vpi->handling = VCL_RET_FAIL; + return (-1); + } + + top = req->top->topreq; + CHECK_OBJ_NOTNULL(top, REQ_MAGIC); + CHECK_OBJ_NOTNULL(top->transport, TRANSPORT_MAGIC); + + if (!FEATURE(FEATURE_VCL_REQ_RESET)) + return (0); + if (top->transport->poll == NULL) + return (0); + if (top->transport->poll(top) >= 0) + return (0); + + VSLb_ts_req(req, "Reset", W_TIM_real(wrk)); + wrk->stats->req_reset++; + wrk->vpi->handling = VCL_RET_FAIL; + req->req_reset = 1; + return (-1); +} + /*-------------------------------------------------------------------- * Method functions to call into VCL programs. * @@ -552,6 +587,8 @@ vcl_call_method(struct worker *wrk, struct req *req, struct busyobj *bo, CHECK_OBJ_NOTNULL(req->sp, SESS_MAGIC); CHECK_OBJ_NOTNULL(req->vcl, VCL_MAGIC); CHECK_OBJ_NOTNULL(req->top, REQTOP_MAGIC); + if (req_poll(wrk, req)) + return; VCL_Req2Ctx(&ctx, req); } assert(ctx.now != 0); diff --git a/bin/varnishd/http2/cache_http2_session.c b/bin/varnishd/http2/cache_http2_session.c index e3e3c116c8b..5775b6da680 100644 --- a/bin/varnishd/http2/cache_http2_session.c +++ b/bin/varnishd/http2/cache_http2_session.c @@ -438,6 +438,16 @@ h2_new_session(struct worker *wrk, void *arg) wrk->vsl = NULL; } +static int v_matchproto_(vtr_poll_f) +h2_poll(struct req *req) +{ + struct h2_req *r2; + + CHECK_OBJ_NOTNULL(req, REQ_MAGIC); + CAST_OBJ_NOTNULL(r2, req->transport_priv, H2_REQ_MAGIC); + return (r2->error ? -1 : 1); +} + struct transport HTTP2_transport = { .name = "HTTP/2", .magic = TRANSPORT_MAGIC, @@ -447,4 +457,5 @@ struct transport HTTP2_transport = { .req_body = h2_req_body, .req_fail = h2_req_fail, .sess_panic = h2_sess_panic, + .poll = h2_poll, }; diff --git a/bin/varnishtest/tests/t02014.vtc b/bin/varnishtest/tests/t02014.vtc index f47eed65767..f4083c89077 100644 --- a/bin/varnishtest/tests/t02014.vtc +++ b/bin/varnishtest/tests/t02014.vtc @@ -1,6 +1,12 @@ varnishtest "Exercise h/2 sender flow control code" -barrier b1 sock 3 -cyclic +barrier b1 sock 3 +barrier b2 sock 3 +barrier b3 sock 3 +barrier b4 sock 3 + +barrier b2_err cond 2 +barrier b3_err cond 2 server s1 { rxreq @@ -23,7 +29,9 @@ varnish v1 -vcl+backend { } sub vcl_deliver { - vtc.barrier_sync("${b1_sock}"); + if (req.http.barrier) { + vtc.barrier_sync(req.http.barrier); + } } } -start @@ -43,7 +51,7 @@ client c1 { } -start stream 1 { - txreq + txreq -hdr barrier ${b1_sock} barrier b1 sync delay .5 txwinup -size 256 @@ -59,26 +67,44 @@ client c1 { stream 0 -wait } -run +varnish v1 -vsl_catchup + +logexpect l2 -v v1 -g raw { + expect * * ReqMethod GET + expect * = VCL_call DELIVER +} -start + client c2 { stream 0 { - barrier b1 sync + barrier b2 sync } -start stream 1 { - txreq + txreq -hdr barrier ${b2_sock} + barrier b2_err sync txdata -data "fail" rxrst expect rst.err == STREAM_CLOSED - barrier b1 sync + barrier b2 sync } -run stream 0 -wait -} -run +} -start + +logexpect l2 -wait +barrier b2_err sync + +client c2 -wait + +logexpect l3 -v v1 -g raw { + expect * * ReqMethod POST + expect * = VCL_call DELIVER +} -start client c3 { stream 0 { - barrier b1 sync - barrier b1 sync + barrier b3 sync + barrier b4 sync delay .5 txwinup -size 256 delay .5 @@ -89,17 +115,18 @@ client c3 { } -start stream 1 { - txreq -req "POST" -nostrend + txreq -req "POST" -hdr barrier ${b3_sock} -nostrend txdata -data "ok" + barrier b3_err sync txdata -data "fail" rxrst expect rst.err == STREAM_CLOSED - barrier b1 sync + barrier b3 sync } -run stream 3 { - txreq - barrier b1 sync + txreq -hdr barrier ${b4_sock} + barrier b4 sync delay .5 txwinup -size 256 delay .5 @@ -112,4 +139,9 @@ client c3 { } -run stream 0 -wait -} -run +} -start + +logexpect l3 -wait +barrier b3_err sync + +client c3 -wait diff --git a/bin/varnishtest/tests/t02025.vtc b/bin/varnishtest/tests/t02025.vtc new file mode 100644 index 00000000000..3b7e90e8aae --- /dev/null +++ b/bin/varnishtest/tests/t02025.vtc @@ -0,0 +1,49 @@ +varnishtest "h2 reset interrupt" + +barrier b1 sock 2 +barrier b2 sock 2 + +varnish v1 -cliok "param.set feature +http2" +varnish v1 -cliok "param.set debug +syncvsl" +varnish v1 -vcl { + import vtc; + + backend be none; + + sub vcl_recv { + vtc.barrier_sync("${b1_sock}"); + vtc.barrier_sync("${b2_sock}"); + } + + sub vcl_miss { + vtc.panic("unreachable"); + } +} -start + +logexpect l1 -v v1 -g raw -i Debug { + expect * * Debug "^H2RXF RST_STREAM" +} -start + +client c1 { + stream 1 { + txreq + barrier b1 sync + txrst + } -run +} -start + +logexpect l1 -wait +barrier b2 sync + +varnish v1 -vsl_catchup +varnish v1 -expect req_reset == 1 + +# NB: The varnishncsa command below shows a minimal pattern to collect +# "rapid reset" suspects per session, with the IP address. Here rapid +# is interpreted as before a second elapsed. Session VXIDs showing up +# numerous times become increasingly more suspicious. The format can of +# course be extended to add anything else useful for data mining. +shell -expect "1000 ${localhost}" { + varnishncsa -n ${v1_name} -d \ + -q 'Timestamp:Reset[2] < 1.0' -F '%{VSL:Begin[2]}x %h' +} diff --git a/doc/sphinx/reference/vsl.rst b/doc/sphinx/reference/vsl.rst index e8ea7a36d89..98c126d2d1d 100644 --- a/doc/sphinx/reference/vsl.rst +++ b/doc/sphinx/reference/vsl.rst @@ -76,6 +76,11 @@ Resp Restart Client request is being restarted. +Reset + The client closed its connection, reset its stream or caused + a stream error that forced Varnish to reset the stream. Request + processing is interrupted and considered failed. + Pipe handling timestamps ~~~~~~~~~~~~~~~~~~~~~~~~ diff --git a/include/tbl/feature_bits.h b/include/tbl/feature_bits.h index 1ff2a361fbc..808efe9174c 100644 --- a/include/tbl/feature_bits.h +++ b/include/tbl/feature_bits.h @@ -91,6 +91,11 @@ FEATURE_BIT(TRACE, trace, "Required for tracing vcl_init / vcl_fini" ) +FEATURE_BIT(VCL_REQ_RESET, vcl_req_reset, + "Stop processing client VCL once the client is gone. " + "When this happens MAIN.req_reset is incremented." +) + #undef FEATURE_BIT /*lint -restore */ diff --git a/include/tbl/params.h b/include/tbl/params.h index 83054eef3de..ebabc45f21c 100644 --- a/include/tbl/params.h +++ b/include/tbl/params.h @@ -1782,7 +1782,9 @@ PARAM_PRE PARAM_BITS( /* name */ feature, /* fld */ feature_bits, - /* def */ "+validate_headers", + /* def */ + "+validate_headers," + "+vcl_req_reset", /* descr */ "Enable/Disable various minor features.\n" "\tdefault\tSet default value\n" diff --git a/include/tbl/req_flags.h b/include/tbl/req_flags.h index 88eaff6391c..6a9e6acbb18 100644 --- a/include/tbl/req_flags.h +++ b/include/tbl/req_flags.h @@ -40,6 +40,7 @@ REQ_FLAG(is_hit, 0, 0, "") REQ_FLAG(waitinglist, 0, 0, "") REQ_FLAG(want100cont, 0, 0, "") REQ_FLAG(late100cont, 0, 0, "") +REQ_FLAG(req_reset, 0, 0, "") #define REQ_BEREQ_FLAG(lower, vcl_r, vcl_w, doc) \ REQ_FLAG(lower, vcl_r, vcl_w, doc) #include "tbl/req_bereq_flags.h" diff --git a/lib/libvsc/VSC_main.vsc b/lib/libvsc/VSC_main.vsc index a4049fccb25..3676e16461e 100644 --- a/lib/libvsc/VSC_main.vsc +++ b/lib/libvsc/VSC_main.vsc @@ -345,6 +345,15 @@ Number of times an HTTP/2 stream was refused because the queue was too long already. See also parameter thread_queue_limit. +.. varnish_vsc:: req_reset + :group: wrk + :oneliner: Requests reset + + Number of times a client left before the VCL processing of its + requests completed. For HTTP/2 sessions, either the stream was + reset by an RST_STREAM frame from the client, or a stream or + connection error occurred. + .. varnish_vsc:: n_object :type: gauge :group: wrk