Mailing List Archive

[master] e6f531bc0 Add missing bits of VRT_fail() handling during vcl_init {} / vcl_fini{}
commit e6f531bc0a82d0f143b050687fd08dbfd50b6575
Author: Nils Goroll <nils.goroll@uplex.de>
Date: Wed Jan 20 12:15:21 2021 +0100

Add missing bits of VRT_fail() handling during vcl_init {} / vcl_fini{}

This change is based on the precondition that VRT_fail() should work
wherever we have a VRT_CTX and DTRT, see also previous.

on vcl_init {}
--------------

We already handled a "direct" VRT_fail() via a vmod function
correctly. This commit adds a test.

Yet we can also VRT_fail() via a PRIV_TASK fini callback and did not
handle that case (triggered an assertion in VRT_fail()). Notice that
this case has worked in client / backend tasks for long and a test
case has been added with 746384b20cbc24ff8afd2df35e1510087404fbf4 . It
has now gained relevance with 43d9e5fb1a10a88ab6a5a98ad4038438025c4999

on vcl_fini {}
--------------

By design, vcl_fini {} must not fail, which is also why the only valid
return() value is "ok" (VCL_RET_OK).

Consequently, we had

if (method && *ctx->handling && *ctx->handling != VCL_RET_OK) {
assert(ev == VCL_EVENT_LOAD);

in vcl_send_event().

And then came VRT_fail().

If we wanted to sustain an assertion similar to the above, we would
need to require vmod authors to never call VRT_fail() from
VCL_MET_FINI - which would complicate code, be likely overlooked and
receive little to no test coverage.

So instead we now ignore errors during vcl_fini {} and emit a
VCL_error log line.

I considered the alternative to check for VCL_MET_FINI in VRT_fail(),
but decided to handle the exception where it applies, which is in
vcl_send_event().

I am aware that this part of the change may trigger some controversy
and I am open to discussing alternatives. If anything, we now avoid
unmotivated assertion failures triggered for the new tests in
v00051.vtc for the time being.

diff --git a/bin/varnishd/cache/cache_vcl.c b/bin/varnishd/cache/cache_vcl.c
index 596a26966..abc41de2c 100644
--- a/bin/varnishd/cache/cache_vcl.c
+++ b/bin/varnishd/cache/cache_vcl.c
@@ -172,6 +172,39 @@ VCL_Rel_CliCtx(struct vrt_ctx **ctx)

/*--------------------------------------------------------------------*/

+/* VRT_fail() can be called
+ * - from the vcl sub via a vmod
+ * - via a PRIV_TASK .fini callback
+ *
+ * if this happens during init, we fail it
+ * if during fini, we ignore, because otherwise VMOD authors would be forced to
+ * handle VCL_MET_FINI specifically everywhere.
+ */
+
+static int
+vcl_event_handling(VRT_CTX)
+{
+ CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
+
+ if (*ctx->handling == 0)
+ return (0);
+
+ assert(*ctx->handling == VCL_RET_FAIL);
+
+ if (ctx->method == VCL_MET_INIT)
+ return (1);
+
+ /*
+ * EVENT_WARM / EVENT_COLD: method == 0
+ * must not set handling
+ */
+ assert(ctx->method == VCL_MET_FINI);
+
+ *ctx->handling = 0;
+ VRT_fail(ctx, "VRT_fail() from vcl_fini{} has no effect");
+ return (0);
+}
+
static int
vcl_send_event(struct vcl *vcl, enum vcl_event_e ev, struct vsb **msg)
{
@@ -216,13 +249,7 @@ vcl_send_event(struct vcl *vcl, enum vcl_event_e ev, struct vsb **msg)
VCL_TaskEnter(cli_task_privs);
r = ctx->vcl->conf->event_vcl(ctx, ev);
VCL_TaskLeave(ctx, cli_task_privs);
-
- /* if the warm event did not get to vcl_init, vcl_fini
- * won't be run, so handling may be zero */
- if (method && *ctx->handling && *ctx->handling != VCL_RET_OK) {
- assert(ev == VCL_EVENT_LOAD);
- r = 1;
- }
+ r |= vcl_event_handling(ctx);

*msg = VCL_Rel_CliCtx(&ctx);

diff --git a/bin/varnishtest/tests/v00051.vtc b/bin/varnishtest/tests/v00051.vtc
index 8948d76d5..913932146 100644
--- a/bin/varnishtest/tests/v00051.vtc
+++ b/bin/varnishtest/tests/v00051.vtc
@@ -488,3 +488,71 @@ varnish v1 -expect vcl_fail == 14
varnish v1 -expect sc_vcl_failure == 11

logexpect l1 -wait
+
+#######################################################################
+# Fail in vcl_init with direct VRT_fail()
+
+varnish v1 -errvcl {Forced failure} {
+ import debug;
+ backend proforma none;
+ sub vcl_init {
+ debug.fail();
+ }
+}
+
+#######################################################################
+# Fail in vcl_init via fini callback
+
+varnish v1 -errvcl {thou shalt not fini} {
+ import debug;
+ backend proforma none;
+ sub vcl_init {
+ debug.fail_task_fini();
+ }
+}
+
+#######################################################################
+# Fail in vcl_fini with direct VRT_fail()
+
+varnish v1 -vcl {
+ import debug;
+ backend proforma none;
+ sub vcl_fini {
+ debug.fail();
+ }
+}
+
+varnish v1 -vcl+backend {
+}
+
+logexpect l1 -v v1 -g raw {
+ expect * 0 CLI "^Rd vcl.state vcl16 0cold"
+ expect 3 0 VCL_Error "^Forced failure"
+ expect 0 0 VCL_Error {^\QVRT_fail() from vcl_fini{} has no effect\E$}
+} -start
+
+varnish v1 -cliok "vcl.discard vcl16"
+logexpect l1 -wait
+
+#######################################################################
+# Fail in vcl_fini via fini callback - ignored but logged as VMOD BUG
+
+varnish v1 -vcl {
+ import debug;
+ backend proforma none;
+ sub vcl_fini {
+ debug.fail_task_fini();
+ }
+}
+
+varnish v1 -vcl+backend {
+}
+
+logexpect l1 -v v1 -g raw {
+ expect * 0 CLI "^Rd vcl.state vcl18 0cold"
+ expect 3 0 VCL_Error "^thou shalt not fini"
+ expect 0 0 VCL_Error {^\QVRT_fail() from vcl_fini{} has no effect\E$}
+} -start
+
+varnish v1 -cliok "vcl.discard vcl18"
+logexpect l1 -wait
_______________________________________________
varnish-commit mailing list
varnish-commit@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-commit