implement the hosts.explain() method

README.rst

@@ -225,24 +225,6 @@ subroutines, subsequent calls to ``.token()`` and ``.secret()`` in the
 same backend transaction are based on the policy that was determined
 by that call.
 
-Diagnosis and logging
----------------------
-
-To understand the policy that was determined for a host and path by
-the ``.policy()`` method, the ``.explain()`` method can be used to
-generate a string that contains:
-
-* The name of the policy object that was determined
-* The hostname that matched
-* If applicable, the path pattern that matched
-
-The ``.explain()`` method also has task scope, meaning that it refers
-to the most recent invocation of ``.policy()`` in the same client or
-backend transaction. The string that it returns can then, for example,
-be entered into the Varnish log, or assigned to a debugging header.
-
-XXX: ``.explain()`` is not implemented yet.
-
 CONTENTS
 ========
 
@@ -617,6 +599,7 @@ Examples::
       # a query string or cookie contents, as required for
       # authorization at the Akamai server (for example by
       # constructing a redirect response in VCL).
+    }
   }
 
 .. _func_hosts.explain:
@@ -628,7 +611,34 @@ hosts.explain
 
 	STRING hosts.explain(PRIV_TASK)
 
-**XXX NOT IMPLEMENTED YET**
+Returns a string describing the policy that was determined for a host
+and path by the most recent invocation of ``.policy()`` in the current
+task scope (client or backend context), suitable for diagnosis or
+logging. The returned string contains:
+
+* The name of the policy object that was determined
+* The hostname that matched
+* If applicable, the path pattern that matched
+
+If description strings were provided in the declaration of the policy
+and/or in the ``.add()`` method call that assigned the policy, then
+these are included in the string.
+
+The ``.explain()`` method MAY NOT be called in ``vcl_init``; if it is,
+then the VCL load fails. If ``.policy()`` was not called previously in
+the current task scope, then an error message is emitted to the
+Varnish log with the ``VCL_Error`` tag, and the method returns NULL.
+
+Example::
+
+  import std;
+
+  sub vcl_recv {
+    if (config.policy(req.http.Host, req.url) == 2) {
+      # [...]
+    }
+    std.log("Policy determination: " + config.explain());
+  }
 
 .. _func_version:
 

src/tests/explain.vtc

+# looks like -*- vcl -*-
+
+varnishtest "hosts.explain()"
+
+varnish v1 -vcl {
+	import hoailona from "${vmod_topbuild}/src/.libs/libvmod_hoailona.so";
+	backend b { .host = "${bad_ip}"; }
+
+	sub vcl_init {
+		new p1 = hoailona.policy(TOKEN, 1h);
+		new p2 = hoailona.policy(OPEN, 1h, description="open");
+		new h = hoailona.hosts();
+		h.add("example.com", "p1");
+		h.add("example.org", "p2");
+		h.add("*.example.com", "p1", "/foo/...");
+		h.add("*.example.org", "p2", "/bar/...");
+		h.add("example.net", "p1", description="net");
+		h.add("example.edu", "p2", description="edu");
+		h.add("*.example.net", "p1", "/baz/...", description="sub net");
+		h.add("*.example.edu", "p2", "/baz/...", description="sub edu");
+	}
+
+	sub vcl_recv {
+		return(synth(200));
+	}
+
+	sub vcl_synth {
+		set resp.http.p1 = h.policy("example.com", "/foo/bar");
+		set resp.http.e1 = h.explain();
+		set resp.http.p2 = h.policy("example.org", "/foo/bar");
+		set resp.http.e2 = h.explain();
+		set resp.http.p3 = h.policy("foo.example.com", "/foo/bar");
+		set resp.http.e3 = h.explain();
+		set resp.http.p4 = h.policy("foo.example.org", "/bar/baz");
+		set resp.http.e4 = h.explain();
+		set resp.http.p5 = h.policy("example.net", "/foo/bar");
+		set resp.http.e5 = h.explain();
+		set resp.http.p6 = h.policy("example.edu", "/foo/bar");
+		set resp.http.e6 = h.explain();
+		set resp.http.p7 = h.policy("foo.example.net", "/baz/quux");
+		set resp.http.e7 = h.explain();
+		set resp.http.p8 = h.policy("foo.example.edu", "/baz/quux");
+		set resp.http.e8 = h.explain();
+		set resp.http.p9 = h.policy("foo.example.com", "/baz/quux");
+		set resp.http.e9 = h.explain();
+	}
+} -start
+
+client c1 {
+	txreq
+	rxresp
+	expect resp.status == 200
+	expect resp.http.p1 == "2"
+	expect resp.http.e1 == "Matched host example.com for global policy p1"
+	expect resp.http.p2 == "1"
+	expect resp.http.e2 == "Matched host example.org for global policy p2 (open)"
+	expect resp.http.p3 == "2"
+	expect resp.http.e3 == "Matched host *.example.com and pattern /foo/... for policy p1"
+	expect resp.http.p4 == "1"
+	expect resp.http.e4 == "Matched host *.example.org and pattern /bar/... for policy p2 (open)"
+	expect resp.http.p5 == "2"
+	expect resp.http.e5 == "Matched host example.net (net) for global policy p1"
+	expect resp.http.p6 == "1"
+	expect resp.http.e6 == "Matched host example.edu (edu) for global policy p2 (open)"
+	expect resp.http.p7 == "2"
+	expect resp.http.e7 == "Matched host *.example.net and pattern /baz/... (sub net) for policy p1"
+	expect resp.http.p8 == "1"
+	expect resp.http.e8 == "Matched host *.example.edu and pattern /baz/... (sub edu) for policy p2 (open)"
+	expect resp.http.p9 == "-1"
+	expect resp.http.e9 == "No policy was matched"
+} -run
+
+varnish v1 -errvcl {h.explain() may not be called in vcl_init} {
+	import hoailona from "${vmod_topbuild}/src/.libs/libvmod_hoailona.so";
+	backend b { .host = "${bad_ip}"; }
+
+	sub vcl_init {
+		new p = hoailona.policy(TOKEN, 1h);
+		new h = hoailona.hosts();
+		if (h.explain() ~ ".") {
+			return(fail);
+		}
+	}
+}
+
+varnish v1 -vcl {
+	import hoailona from "${vmod_topbuild}/src/.libs/libvmod_hoailona.so";
+	backend b { .host = "${bad_ip}"; }
+
+	sub vcl_init {
+		new p = hoailona.policy(TOKEN, 1h);
+		new h = hoailona.hosts();
+		h.add("example.com", "p");
+	}
+
+	sub vcl_recv {
+		return(synth(200));
+	}
+
+	sub vcl_synth {
+		set resp.http.e1 = h.explain();
+	}
+}
+
+client c1 {
+	txreq
+	rxresp
+	expect resp.status == 200
+	expect resp.http.e1 == ""
+} -run
+
+logexpect l1 -v v1 -d 1 -g vxid -q "VCL_Error" {
+        expect 0 * Begin req
+        expect * = VCL_Error "^vmod hoailona error: h.explain.. called before h.policy..$"
+        expect * = End
+} -run

src/vmod_hoailona.c

@@ -694,13 +694,121 @@ vmod_hosts_secret(VRT_CTX, struct vmod_hoailona_hosts *hosts,
 
 VCL_STRING
 vmod_hosts_explain(VRT_CTX, struct vmod_hoailona_hosts *hosts,
-		   struct vmod_priv *task)
+		   struct vmod_priv *priv_task)
 {
-	(void) ctx;
-	(void) hosts;
-	(void) task;
+	struct policy_task *task;
+	struct host *host;
+	struct vmod_hoailona_policy *policy;
+	char *ret = NULL;
+
+	CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
+	CHECK_OBJ_NOTNULL(ctx->ws, WS_MAGIC);
+	CHECK_OBJ_NOTNULL(hosts, VMOD_HOAILONA_HOSTS_MAGIC);
+	AN(priv_task);
+	if (INIT(ctx)) {
+		VERR(ctx, "%s.explain() may not be called in vcl_init",
+		     hosts->vcl_name);
+		return NULL;
+	}
+	if (priv_task->priv == NULL) {
+		VERR(ctx, "%s.explain() called before %s.policy()",
+		     hosts->vcl_name, hosts->vcl_name);
+		return NULL;
+	}
+	WS_Contains(ctx->ws, priv_task->priv, sizeof(struct policy_task));
+	CAST_OBJ(task, priv_task->priv, VMOD_HOAILONA_POLICY_TASK_MAGIC);
+	host = task->host;
+
+	if (task->policy != NULL) {
+		CHECK_OBJ_NOTNULL(host, VMOD_HOAILONA_HOST_MAGIC);
+		AN(host->name);
+		CHECK_OBJ(task->policy, VMOD_HOAILONA_POLICY_MAGIC);
+		AN(task->policy->vcl_name);
+		policy = task->policy;
+		if (policy->description != NULL) {
+			if (host->description != NULL)
+				ret = WS_Printf(ctx->ws, "Matched host %s (%s) "
+						"for global policy %s (%s)",
+						host->name, host->description,
+						policy->vcl_name,
+						policy->description);
+			else
+				ret = WS_Printf(ctx->ws, "Matched host %s "
+						"for global policy %s (%s)",
+						host->name, policy->vcl_name,
+						policy->description);
+		}
+		else {
+			if (host->description != NULL)
+				ret = WS_Printf(ctx->ws, "Matched host %s (%s) "
+						"for global policy %s",
+						host->name, host->description,
+						policy->vcl_name);
+			else
+				ret = WS_Printf(ctx->ws, "Matched host %s "
+						"for global policy %s",
+						host->name, policy->vcl_name);
+		}
+	}
+	else if (task->assignment != NULL) {
+		struct assignment *a;
+
+		CHECK_OBJ_NOTNULL(host, VMOD_HOAILONA_HOST_MAGIC);
+		AN(host->name);
+		CHECK_OBJ_NOTNULL(task->assignment,
+				  VMOD_HOAILONA_ASSIGNMENT_MAGIC);
+		CHECK_OBJ_NOTNULL(task->assignment->policy,
+				  VMOD_HOAILONA_POLICY_MAGIC);
+		CHECK_OBJ_NOTNULL(task->assignment->pattern,
+				  VMOD_HOAILONA_PATTERN_MAGIC);
+		AN(task->assignment->policy->vcl_name);
+		AN(task->assignment->pattern->path);
+		AZ(host->description);
+		a = task->assignment;
+		policy = a->policy;
+		if (policy->description != NULL) {
+			if (a->description != NULL)
+				ret = WS_Printf(ctx->ws,
+						"Matched host %s "
+						"and pattern %s (%s) "
+						"for policy %s (%s)",
+						host->name, a->pattern->path,
+						a->description,
+						policy->vcl_name,
+						policy->description);
+			else
+				ret = WS_Printf(ctx->ws,
+						"Matched host %s "
+						"and pattern %s "
+						"for policy %s (%s)",
+						host->name, a->pattern->path,
+						policy->vcl_name,
+						policy->description);
+		}
+		else {
+			if (a->description != NULL)
+				ret = WS_Printf(ctx->ws,
+						"Matched host %s "
+						"and pattern %s (%s) "
+						"for policy %s",
+						host->name, a->pattern->path,
+						a->description,
+						policy->vcl_name);
+			else
+				ret = WS_Printf(ctx->ws,
+						"Matched host %s "
+						"and pattern %s "
+						"for policy %s",
+						host->name, a->pattern->path,
+						policy->vcl_name);
+		}
+	}
+	else
+		ret = WS_Printf(ctx->ws, "%s", "No policy was matched");
 
-	return NULL;
+	if (ret == NULL)
+		VERRNOMEM(ctx, "in %s.explain()", hosts->vcl_name);
+	return ret;
 }
 
 /* Functions */

src/vmod_hoailona.vcc

@@ -208,24 +208,6 @@ subroutines, subsequent calls to ``.token()`` and ``.secret()`` in the
 same backend transaction are based on the policy that was determined
 by that call.
 
-Diagnosis and logging
----------------------
-
-To understand the policy that was determined for a host and path by
-the ``.policy()`` method, the ``.explain()`` method can be used to
-generate a string that contains:
-
-* The name of the policy object that was determined
-* The hostname that matched
-* If applicable, the path pattern that matched
-
-The ``.explain()`` method also has task scope, meaning that it refers
-to the most recent invocation of ``.policy()`` in the same client or
-backend transaction. The string that it returns can then, for example,
-be entered into the Varnish log, or assigned to a debugging header.
-
-XXX: ``.explain()`` is not implemented yet.
-
 $Object policy(PRIV_TASK, ENUM {OPEN, DENY, TOKEN} type, DURATION ttl,
                STRING description=0, BLOB secret=0, INT start_offset=0)
 
@@ -553,11 +535,39 @@ Examples::
       # a query string or cookie contents, as required for
       # authorization at the Akamai server (for example by
       # constructing a redirect response in VCL).
+    }
   }
 
 $Method STRING .explain(PRIV_TASK)
 
-**XXX NOT IMPLEMENTED YET**
+Returns a string describing the policy that was determined for a host
+and path by the most recent invocation of ``.policy()`` in the current
+task scope (client or backend context), suitable for diagnosis or
+logging. The returned string contains:
+
+* The name of the policy object that was determined
+* The hostname that matched
+* If applicable, the path pattern that matched
+
+If description strings were provided in the declaration of the policy
+and/or in the ``.add()`` method call that assigned the policy, then
+these are included in the string.
+
+The ``.explain()`` method MAY NOT be called in ``vcl_init``; if it is,
+then the VCL load fails. If ``.policy()`` was not called previously in
+the current task scope, then an error message is emitted to the
+Varnish log with the ``VCL_Error`` tag, and the method returns NULL.
+
+Example::
+
+  import std;
+
+  sub vcl_recv {
+    if (config.policy(req.http.Host, req.url) == 2) {
+      # [...]
+    }
+    std.log("Policy determination: " + config.explain());
+  }
 
 $Function STRING version()