From 578f2d157eabe7c82b5ae4d6770ce52d75159cd9 Mon Sep 17 00:00:00 2001 From: Dridi Boukelmoune Date: Thu, 25 Jan 2024 16:54:20 +0100 Subject: [PATCH] vrt_var: Expose bereq.task_deadline in vcl_pipe The [be]req.task_deadline should eventually be generalized to all subroutines with read-write access to [be]req. When that happens, bereq.task_deadline will inherit req.task_deadline during the pipe transition. Related tasks should otherwise have independent deadlines, except sub-request tasks like ESI where there is a hierarchical dependency. --- bin/varnishd/cache/cache.h | 1 + bin/varnishd/cache/cache_backend.c | 12 +++++++-- bin/varnishd/cache/cache_req_fsm.c | 1 + bin/varnishd/cache/cache_vrt_var.c | 2 ++ bin/varnishd/http1/cache_http1.h | 3 ++- bin/varnishd/http1/cache_http1_pipe.c | 8 ++---- bin/varnishtest/tests/s00013.vtc | 37 ++++++++++++++++++--------- doc/sphinx/reference/vcl_var.rst | 14 ++++++++++ 8 files changed, 57 insertions(+), 21 deletions(-) diff --git a/bin/varnishd/cache/cache.h b/bin/varnishd/cache/cache.h index a7fcac6bf44..7d6b684571c 100644 --- a/bin/varnishd/cache/cache.h +++ b/bin/varnishd/cache/cache.h @@ -419,6 +419,7 @@ struct busyobj { vtim_dur connect_timeout; vtim_dur first_byte_timeout; vtim_dur between_bytes_timeout; + vtim_dur task_deadline; /* Timers */ vtim_real t_first; /* First timestamp logged */ diff --git a/bin/varnishd/cache/cache_backend.c b/bin/varnishd/cache/cache_backend.c index 6b378aedeea..c24ae96a2f3 100644 --- a/bin/varnishd/cache/cache_backend.c +++ b/bin/varnishd/cache/cache_backend.c @@ -366,6 +366,7 @@ vbe_dir_http1pipe(VRT_CTX, VCL_BACKEND d) struct backend *bp; struct v1p_acct v1a; struct pfd *pfd; + vtim_real deadline; CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC); CHECK_OBJ_NOTNULL(d, DIRECTOR_MAGIC); @@ -390,8 +391,15 @@ vbe_dir_http1pipe(VRT_CTX, VCL_BACKEND d) i = V1F_SendReq(ctx->req->wrk, ctx->bo, &v1a.bereq, &v1a.out); VSLb_ts_req(ctx->req, "Pipe", W_TIM_real(ctx->req->wrk)); - if (i == 0) - retval = V1P_Process(ctx->req, *PFD_Fd(pfd), &v1a); + if (i == 0) { + deadline = ctx->bo->task_deadline; + if (isnan(deadline)) + deadline = cache_param->pipe_task_deadline; + if (deadline > 0.) + deadline += ctx->req->sp->t_idle; + retval = V1P_Process(ctx->req, *PFD_Fd(pfd), &v1a, + deadline); + } VSLb_ts_req(ctx->req, "PipeSess", W_TIM_real(ctx->req->wrk)); ctx->bo->htc->doclose = retval; vbe_dir_finish(ctx, d); diff --git a/bin/varnishd/cache/cache_req_fsm.c b/bin/varnishd/cache/cache_req_fsm.c index c7469f5eb4a..3f92d91aaf2 100644 --- a/bin/varnishd/cache/cache_req_fsm.c +++ b/bin/varnishd/cache/cache_req_fsm.c @@ -795,6 +795,7 @@ cnt_pipe(struct worker *wrk, struct req *req) } bo->wrk = wrk; + bo->task_deadline = NAN; /* XXX: copy req->task_deadline */ if (WS_Overflowed(req->ws)) wrk->vpi->handling = VCL_RET_FAIL; else diff --git a/bin/varnishd/cache/cache_vrt_var.c b/bin/varnishd/cache/cache_vrt_var.c index c1282c1495f..b69005cd010 100644 --- a/bin/varnishd/cache/cache_vrt_var.c +++ b/bin/varnishd/cache/cache_vrt_var.c @@ -409,6 +409,8 @@ VRT_r_bereq_##which(VRT_CTX) \ BEREQ_TIMEOUT(connect_timeout) BEREQ_TIMEOUT(first_byte_timeout) BEREQ_TIMEOUT(between_bytes_timeout) +BEREQ_TIMEOUT(task_deadline) + /*--------------------------------------------------------------------*/ diff --git a/bin/varnishd/http1/cache_http1.h b/bin/varnishd/http1/cache_http1.h index b5ab024460e..f758a74c981 100644 --- a/bin/varnishd/http1/cache_http1.h +++ b/bin/varnishd/http1/cache_http1.h @@ -54,7 +54,8 @@ struct v1p_acct { int V1P_Enter(void); void V1P_Leave(void); -stream_close_t V1P_Process(const struct req *, int fd, struct v1p_acct *); +stream_close_t V1P_Process(const struct req *, int fd, struct v1p_acct *, + vtim_real deadline); void V1P_Charge(struct req *, const struct v1p_acct *, struct VSC_vbe *); /* cache_http1_line.c */ diff --git a/bin/varnishd/http1/cache_http1_pipe.c b/bin/varnishd/http1/cache_http1_pipe.c index d0b513c7cf1..7ffe4b68cbc 100644 --- a/bin/varnishd/http1/cache_http1_pipe.c +++ b/bin/varnishd/http1/cache_http1_pipe.c @@ -115,11 +115,11 @@ V1P_Charge(struct req *req, const struct v1p_acct *a, struct VSC_vbe *b) } stream_close_t -V1P_Process(const struct req *req, int fd, struct v1p_acct *v1a) +V1P_Process(const struct req *req, int fd, struct v1p_acct *v1a, + vtim_real deadline) { struct pollfd fds[2]; vtim_dur tmo, tmo_task; - vtim_real deadline; stream_close_t sc; int i, j; @@ -143,10 +143,6 @@ V1P_Process(const struct req *req, int fd, struct v1p_acct *v1a) fds[1].fd = req->sp->fd; fds[1].events = POLLIN; - deadline = cache_param->pipe_task_deadline; - if (deadline > 0.) - deadline += req->sp->t_idle; - sc = SC_TX_PIPE; while (fds[0].fd > -1 || fds[1].fd > -1) { fds[0].revents = 0; diff --git a/bin/varnishtest/tests/s00013.vtc b/bin/varnishtest/tests/s00013.vtc index e27838df506..2898ec87f95 100644 --- a/bin/varnishtest/tests/s00013.vtc +++ b/bin/varnishtest/tests/s00013.vtc @@ -6,15 +6,12 @@ server s1 { delay 1.1 close - accept - rxreq - txresp -hdr "transfer-encoding: chunked" - expect_close - - accept - rxreq - txresp -hdr "transfer-encoding: chunked" - expect_close + loop 3 { + accept + rxreq + txresp -hdr "transfer-encoding: chunked" + expect_close + } accept non_fatal @@ -28,13 +25,20 @@ server s1 { varnish v1 -cliok "param.set pipe_timeout 0s" varnish v1 -cliok "param.set pipe_task_deadline 0s" -varnish v1 -vcl+backend "" -start +varnish v1 -vcl+backend { + sub vcl_pipe { + if (req.method == "TMO") { + set bereq.task_deadline = 1.1s; + } + } +} -start logexpect l1 -v v1 -g raw -q SessClose { expect 1000 * SessClose {^TX_PIPE 1\.} expect 1003 * SessClose {^RX_TIMEOUT 0\.} expect 1006 * SessClose {^RX_TIMEOUT 1\.} expect 1009 * SessClose {^RX_TIMEOUT 1\.} + expect 1012 * SessClose {^RX_TIMEOUT 1\.} } -start client c1 { @@ -51,12 +55,21 @@ varnish v1 -cliok "param.set pipe_timeout 0s" varnish v1 -cliok "param.set pipe_task_deadline 1.1s" client c1 -run +varnish v1 -cliok "param.set pipe_timeout 0s" +varnish v1 -cliok "param.set pipe_task_deadline 0s" + +client c2 { + non_fatal + txreq -method TMO + rxresp +} -run + varnish v1 -cliok "param.set pipe_timeout 500ms" varnish v1 -cliok "param.set pipe_task_deadline 1.1s" client c1 -run logexpect l1 -wait -varnish v1 -expect MAIN.s_pipe == 4 +varnish v1 -expect MAIN.s_pipe == 5 varnish v1 -expect MAIN.sc_tx_pipe == 1 -varnish v1 -expect MAIN.sc_rx_timeout == 3 +varnish v1 -expect MAIN.sc_rx_timeout == 4 diff --git a/doc/sphinx/reference/vcl_var.rst b/doc/sphinx/reference/vcl_var.rst index 23c16901940..510d13950c9 100644 --- a/doc/sphinx/reference/vcl_var.rst +++ b/doc/sphinx/reference/vcl_var.rst @@ -840,6 +840,20 @@ bereq.retries A count of how many times this request has been retried. +.. _bereq.task_deadline: + +bereq.task_deadline + + Type: DURATION + + Readable from: vcl_pipe + + Writable from: vcl_pipe + + Deadline for pipe sessions, defaults ``0s``, which falls back to the + ``pipe_task_deadline`` parameter, see :ref:`varnishd(1)` + + .. _bereq.time: bereq.time