[master] 02bc0a683 Add vcl control over timeout_linger, send_timeout, idle_send_timeout
Nils Goroll
nils.goroll at uplex.de
Wed Jan 15 18:08:07 UTC 2020
commit 02bc0a68379cfb6e856b8b37f074bef0313c3dd4
Author: Nils Goroll <nils.goroll at uplex.de>
Date: Wed Apr 24 18:22:48 2019 +0200
Add vcl control over timeout_linger, send_timeout, idle_send_timeout
and test that they work for H1
To @Dridi, I would appreciate if you could have another look at s10.vtc.
I *tried* to keep your good ideas intact, and hope you can live with
these changes.
diff --git a/bin/varnishd/cache/cache.h b/bin/varnishd/cache/cache.h
index 0cf024c9c..14f5338c4 100644
--- a/bin/varnishd/cache/cache.h
+++ b/bin/varnishd/cache/cache.h
@@ -575,6 +575,9 @@ struct sess {
vtim_real t_open; /* fd accepted */
vtim_real t_idle; /* fd accepted or resp sent */
vtim_dur timeout_idle;
+ vtim_dur timeout_linger;
+ vtim_dur send_timeout;
+ vtim_dur idle_send_timeout;
};
#define SESS_TMO(sp, tmo) \
diff --git a/bin/varnishd/cache/cache_session.c b/bin/varnishd/cache/cache_session.c
index 3e131943b..1be9f1fff 100644
--- a/bin/varnishd/cache/cache_session.c
+++ b/bin/varnishd/cache/cache_session.c
@@ -389,6 +389,9 @@ SES_New(struct pool *pp)
sp->t_open = NAN;
sp->t_idle = NAN;
sp->timeout_idle = NAN;
+ sp->timeout_linger = NAN;
+ sp->send_timeout = NAN;
+ sp->idle_send_timeout = NAN;
Lck_New(&sp->mtx, lck_sess);
CHECK_OBJ_NOTNULL(sp, SESS_MAGIC);
return (sp);
diff --git a/bin/varnishd/cache/cache_vrt_var.c b/bin/varnishd/cache/cache_vrt_var.c
index 3a06d16a4..ab650b6ad 100644
--- a/bin/varnishd/cache/cache_vrt_var.c
+++ b/bin/varnishd/cache/cache_vrt_var.c
@@ -36,6 +36,8 @@
#include "common/heritage.h"
#include "vcl.h"
+#include "vtim.h"
+#include "vtcp.h"
#include "vrt_obj.h"
@@ -946,18 +948,41 @@ HTTP_VAR(beresp)
/*--------------------------------------------------------------------*/
-VCL_VOID
-VRT_l_sess_timeout_idle(VRT_CTX, VCL_DURATION d)
-{
- CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
- CHECK_OBJ_NOTNULL(ctx->sp, SESS_MAGIC);
- ctx->sp->timeout_idle = d > 0.0 ? d : 0.0;
-}
-
-VCL_DURATION
-VRT_r_sess_timeout_idle(VRT_CTX)
-{
- CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
- CHECK_OBJ_NOTNULL(ctx->sp, SESS_MAGIC);
- return (SESS_TMO(ctx->sp, timeout_idle));
-}
+#define set_noop(sp, d) (void)0
+
+#ifdef SO_SNDTIMEO_WORKS
+static inline void
+set_idle_send_timeout(struct sess *sp, VCL_DURATION d)
+{
+ struct timeval tv = VTIM_timeval(d);
+ VTCP_Assert(setsockopt(sp->fd, SOL_SOCKET, SO_SNDTIMEO,
+ &tv, sizeof tv));
+}
+#else
+#define set_idle_send_timeout(sp, d) set_noop(sp, d)
+#endif
+
+#define SESS_VAR_DUR(x, setter) \
+VCL_VOID \
+VRT_l_sess_##x(VRT_CTX, VCL_DURATION d) \
+{ \
+ CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC); \
+ CHECK_OBJ_NOTNULL(ctx->sp, SESS_MAGIC); \
+ if (d < 0.0) \
+ d = 0.0; \
+ setter(ctx->sp, d); \
+ ctx->sp->x = d; \
+} \
+ \
+VCL_DURATION \
+VRT_r_sess_##x(VRT_CTX) \
+{ \
+ CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC); \
+ CHECK_OBJ_NOTNULL(ctx->sp, SESS_MAGIC); \
+ return (SESS_TMO(ctx->sp, x)); \
+}
+
+SESS_VAR_DUR(timeout_idle, set_noop)
+SESS_VAR_DUR(timeout_linger, set_noop)
+SESS_VAR_DUR(send_timeout, set_noop)
+SESS_VAR_DUR(idle_send_timeout, set_idle_send_timeout)
diff --git a/bin/varnishd/http1/cache_http1_deliver.c b/bin/varnishd/http1/cache_http1_deliver.c
index f7e7b270d..2714a0410 100644
--- a/bin/varnishd/http1/cache_http1_deliver.c
+++ b/bin/varnishd/http1/cache_http1_deliver.c
@@ -130,8 +130,8 @@ V1D_Deliver(struct req *req, struct boc *boc, int sendbody)
}
AZ(req->wrk->v1l);
- V1L_Open(req->wrk, req->wrk->aws,
- &req->sp->fd, req->vsl, req->t_prev + cache_param->send_timeout,
+ V1L_Open(req->wrk, req->wrk->aws, &req->sp->fd, req->vsl,
+ req->t_prev + SESS_TMO(req->sp, send_timeout),
cache_param->http1_iovs);
if (WS_Overflowed(req->wrk->aws)) {
diff --git a/bin/varnishd/http1/cache_http1_fsm.c b/bin/varnishd/http1/cache_http1_fsm.c
index ebe9133db..63c7833c9 100644
--- a/bin/varnishd/http1/cache_http1_fsm.c
+++ b/bin/varnishd/http1/cache_http1_fsm.c
@@ -329,7 +329,7 @@ HTTP1_Session(struct worker *wrk, struct req *req)
hs = HTC_RxStuff(req->htc, HTTP1_Complete,
&req->t_first, &req->t_req,
- sp->t_idle + cache_param->timeout_linger,
+ sp->t_idle + SESS_TMO(sp, timeout_linger),
sp->t_idle + SESS_TMO(sp, timeout_idle),
NAN,
cache_param->http_req_size);
diff --git a/bin/varnishd/http2/cache_http2_proto.c b/bin/varnishd/http2/cache_http2_proto.c
index 4930a5e0a..9290cc0f8 100644
--- a/bin/varnishd/http2/cache_http2_proto.c
+++ b/bin/varnishd/http2/cache_http2_proto.c
@@ -985,7 +985,7 @@ h2_stream_tmo(struct h2_sess *h2, const struct h2_req *r2, vtim_real now)
return (0);
if (isnan(now) || (r2->t_winupd != 0 &&
- now - r2->t_winupd > cache_param->idle_send_timeout)) {
+ now - r2->t_winupd > SESS_TMO(h2->sess, idle_send_timeout))) {
VSLb(h2->vsl, SLT_Debug,
"H2: stream %u: Hit idle_send_timeout waiting for"
" WINDOW_UPDATE", r2->stream);
@@ -993,7 +993,7 @@ h2_stream_tmo(struct h2_sess *h2, const struct h2_req *r2, vtim_real now)
}
if (r == 0 && r2->t_send != 0 &&
- now - r2->t_send > cache_param->send_timeout) {
+ now - r2->t_send > SESS_TMO(h2->sess, send_timeout)) {
VSLb(h2->vsl, SLT_Debug,
"H2: stream %u: Hit send_timeout", r2->stream);
r = 1;
diff --git a/bin/varnishtest/tests/b00068.vtc b/bin/varnishtest/tests/b00068.vtc
index d5f6910b1..2251b5290 100644
--- a/bin/varnishtest/tests/b00068.vtc
+++ b/bin/varnishtest/tests/b00068.vtc
@@ -20,6 +20,9 @@ varnish v1 -arg "-p timeout_linger=1" \
sub vcl_recv {
std.log(blob.encode(encoding=HEX,
blob=vtc.workspace_dump(session, f)));
+ if (req.url == "/longer") {
+ set sess.timeout_linger = 2s;
+ }
}
sub vcl_backend_error {
set beresp.status = 200;
@@ -27,7 +30,7 @@ varnish v1 -arg "-p timeout_linger=1" \
}
} -start
-logexpect l1 -v v1 -g session -q "SessOpen ~ a0" {
+logexpect l1 -v v1 -g session -q "SessOpen ~ a0 and ReqURL ~ \"^/$\"" {
expect * * VCL_call {^RECV}
expect 0 = VCL_Log "^0{128}$"
expect * * VCL_call {^RECV}
@@ -36,7 +39,25 @@ logexpect l1 -v v1 -g session -q "SessOpen ~ a0" {
expect 0 = VCL_Log "[1-9a-f]"
} -start
-logexpect l2 -v v1 -g session -q "SessOpen ~ a1" {
+logexpect l2 -v v1 -g session -q "SessOpen ~ a1 and ReqURL ~ \"^/$\"" {
+ expect * * VCL_call {^RECV}
+ expect 0 = VCL_Log "^0{128}$"
+ expect * * VCL_call {^RECV}
+ expect 0 = VCL_Log "^0{128}$"
+ expect * * VCL_call {^RECV}
+ expect 0 = VCL_Log "[1-9a-f]"
+} -start
+
+logexpect l3 -v v1 -g session -q "SessOpen ~ a0 and ReqURL ~ \"^/longer\"" {
+ expect * * VCL_call {^RECV}
+ expect 0 = VCL_Log "^0{128}$"
+ expect * * VCL_call {^RECV}
+ expect 0 = VCL_Log "^0{128}$"
+ expect * * VCL_call {^RECV}
+ expect 0 = VCL_Log "[1-9a-f]"
+} -start
+
+logexpect l4 -v v1 -g session -q "SessOpen ~ a1 and ReqURL ~ \"^/longer\"" {
expect * * VCL_call {^RECV}
expect 0 = VCL_Log "^0{128}$"
expect * * VCL_call {^RECV}
@@ -67,8 +88,34 @@ client c1u -connect "${tmpdir}/v1.sock" {
rxresp
} -start
+client c2 {
+ txreq -url /longer
+ rxresp
+ delay 1.2
+ txreq -url /longer
+ rxresp
+ delay 2.2
+ txreq -url /longer
+ rxresp
+} -start
+
+client c2u -connect "${tmpdir}/v1.sock" {
+ txreq -url /longer
+ rxresp
+ delay 1.2
+ txreq -url /longer
+ rxresp
+ delay 2.2
+ txreq -url /longer
+ rxresp
+} -start
+
client c1 -wait
client c1u -wait
+client c2 -wait
+client c2u -wait
logexpect l1 -wait
logexpect l2 -wait
+logexpect l3 -wait
+logexpect l4 -wait
diff --git a/bin/varnishtest/tests/c00070.vtc b/bin/varnishtest/tests/c00070.vtc
index 9042fc554..7b1ec34fb 100644
--- a/bin/varnishtest/tests/c00070.vtc
+++ b/bin/varnishtest/tests/c00070.vtc
@@ -44,7 +44,7 @@ client c1 {
expect resp.http.overflowed == "false"
expect resp.http.free_backend > 9000
- expect resp.http.free_session >= 232
+ expect resp.http.free_session >= 200
expect resp.http.free_thread > 2000
} -run
diff --git a/bin/varnishtest/tests/s00010.vtc b/bin/varnishtest/tests/s00010.vtc
index 391761967..116b6b440 100644
--- a/bin/varnishtest/tests/s00010.vtc
+++ b/bin/varnishtest/tests/s00010.vtc
@@ -28,13 +28,38 @@ varnish v1 -cliok "param.set send_timeout .1"
varnish v1 -vcl+backend {
import debug;
- sub vcl_recv { return (pass); }
- sub vcl_deliver { debug.sndbuf(256b); }
+ sub vcl_recv {
+ if (req.url == "/longsend") {
+ # client -rcvbuf 256 is super inefficient, so
+ # we need a very long timeout
+ set sess.send_timeout = 20s;
+ } else
+ if (req.url == "/longidlesend") {
+ set sess.idle_send_timeout = 20s;
+ }
+ }
+
+ sub vcl_hash {
+ hash_data("/");
+ return (lookup);
+ }
+
+ sub vcl_deliver {
+ debug.sndbuf(256b);
+ }
+} -start
+
+# l0 signals when to raise the barrier
+# l1 checks for the TX_ERROR in the same session
+
+logexpect l0 -v v1 -g raw {
+ expect * * ReqURL "^/$"
+ expect * = Debug "^Hit total send timeout"
} -start
-logexpect l1 -v v1 -g raw {
- expect * 1001 Debug "Hit total send timeout"
- expect * 1000 SessClose TX_ERROR
+logexpect l1 -v v1 -g session -q "ReqURL ~ \"^/$\"" {
+ expect * * SessClose "^TX_ERROR"
+ expect * * Debug "^Hit total send timeout"
} -start
client c1 -rcvbuf 256 {
@@ -46,17 +71,60 @@ client c1 -rcvbuf 256 {
barrier b2 sync
} -start
-logexpect l1 -wait
+client c2 -rcvbuf 256 {
+ txreq -url /longsend
+ rxresphdrs
+ delay 0.8
+ rxrespbody
+ expect resp.bodylen == 100000
+} -start
+
+logexpect l0 -wait
barrier b2 sync
+logexpect l1 -wait
client c1 -wait
+client c2 -wait
varnish v1 -cliok "param.reset send_timeout"
+varnish v1 -cliok "ban obj.status != 0"
+
+# l2 signals when to raise the barrier
+# l3 checks the idle send timeout in the right transaction
+# l4 checks for no idle send timeout with the prolonged timeout
+
logexpect l2 -v v1 -g raw {
- expect * 1004 Debug "Hit idle send timeout"
+ expect * * ReqURL "^/$"
+ expect * = Debug "^Hit idle send timeout"
+} -start
+
+
+logexpect l3 -v v1 -q "ReqURL ~ \"^/$\"" {
+ expect * * ReqURL "^/$"
+ expect * = RespHeader "^Transfer-Encoding"
+ expect 0 = Debug "^Hit idle send timeout"
+} -start
+
+logexpect l4 -v v1 -q "ReqURL ~ \"^/longidlesend$\"" {
+ expect * * ReqURL "^/longidlesend$"
+ expect * = RespHeader "^Transfer-Encoding"
+ # no Hit idle send ...
+ expect 0 = Timestamp "^Resp"
} -start
client c1 -start
+
+client c3 -rcvbuf 256 {
+ txreq -url /longidlesend
+ rxresphdrs
+ delay 1.8
+ rxrespbody
+ expect resp.bodylen == 100000
+} -start
+
logexpect l2 -wait
barrier b2 sync
client c1 -wait
+client c3 -wait
+logexpect l3 -wait
+logexpect l4 -wait
diff --git a/bin/varnishtest/tests/s00012.vtc b/bin/varnishtest/tests/s00012.vtc
index 2ea5bdf16..9726f050f 100644
--- a/bin/varnishtest/tests/s00012.vtc
+++ b/bin/varnishtest/tests/s00012.vtc
@@ -17,12 +17,28 @@ varnish v1 \
-vcl+backend {
import debug;
+ sub vcl_recv {
+ if (req.url == "/longsend") {
+ # client -rcvbuf 128 is super inefficient, so
+ # we need a very long timeout
+ set sess.send_timeout = 20s;
+ } else
+ if (req.url == "/longidlesend") {
+ set sess.idle_send_timeout = 2s;
+ }
+ }
+
+ sub vcl_hash {
+ hash_data("/");
+ return (lookup);
+ }
+
sub vcl_deliver {
debug.sndbuf(128b);
}
} -start
-logexpect l1 -v v1 {
+logexpect l1 -v v1 -q "ReqURL ~ \"^/$\"" {
expect * * Debug "Hit total send timeout"
} -start
@@ -34,22 +50,41 @@ client c1 -connect "${tmpdir}/v1.sock" -rcvbuf 128 {
delay 2
} -start
+client c2 -connect "${tmpdir}/v1.sock" -rcvbuf 128 {
+ txreq -url /longsend
+ rxresphdrs
+ delay 0.8
+ rxrespbody
+ expect resp.bodylen == 100000
+} -start
+
+
client c1 -wait
-logexpect l1 -wait
+client c2 -wait
varnish v1 -cliok "param.set idle_send_timeout 1"
varnish v1 -cliok "param.reset send_timeout"
-logexpect l2 -v v1 {
+logexpect l2 -v v1 -q "ReqURL ~ \"^/$\"" {
expect * * Debug "Hit idle send timeout"
} -start
-client c2 -connect "${tmpdir}/v1.sock" -rcvbuf 128 {
+client c3 -connect "${tmpdir}/v1.sock" -rcvbuf 128 {
txreq
rxresphdrs
# keep the session open for 2 seconds
delay 2
} -start
-client c2 -wait
+client c4 -connect "${tmpdir}/v1.sock" -rcvbuf 128 {
+ txreq -url /longidlesend
+ rxresphdrs
+ delay 1.8
+ rxrespbody
+ expect resp.bodylen == 100000
+} -start
+
+client c3 -wait
+client c4 -wait
+logexpect l1 -wait
logexpect l2 -wait
diff --git a/doc/sphinx/reference/vcl_var.rst b/doc/sphinx/reference/vcl_var.rst
index a4c2469bd..dd9f34975 100644
--- a/doc/sphinx/reference/vcl_var.rst
+++ b/doc/sphinx/reference/vcl_var.rst
@@ -1272,6 +1272,40 @@ sess.timeout_idle
Idle timeout for this session, defaults to the
``timeout_idle`` parameter, see :ref:`varnishd(1)`
+sess.timeout_linger
+
+ Type: DURATION
+
+ Readable from: client
+
+ Writable from: client
+
+ Linger timeout for this session, defaults to the
+ ``timeout_linger`` parameter, see :ref:`varnishd(1)`
+
+sess.send_timeout
+
+ Type: DURATION
+
+ Readable from: client
+
+ Writable from: client
+
+ Total timeout for ordinary HTTP1 responses, defaults to the
+ ``send_timeout`` parameter, see :ref:`varnishd(1)`
+
+sess.idle_send_timeout
+
+ Type: DURATION
+
+ Readable from: client
+
+ Writable from: client
+
+ Send timeout for individual pieces of data on client
+ connections, defaults to the ``idle_send_timeout`` parameter,
+ see :ref:`varnishd(1)`
+
storage
~~~~~~~
More information about the varnish-commit
mailing list