[master] 4f2852623 Add VCL source information to panics

Nils Goroll nils.goroll at uplex.de
Mon Aug 15 13:38:06 UTC 2022


commit 4f2852623d62b1d7a5f712cb2b8695fb22f6e93f
Author: Nils Goroll <nils.goroll at uplex.de>
Date:   Tue Feb 9 13:51:03 2021 +0100

    Add VCL source information to panics
    
    Now that we have the vpi ref as set by VPI_Count() available via struct
    wrk_vpi, we can dump our position in VCL at the time of the panic.
    
    Additional changes:
    
    * move handling info from pan_wrk() to the new VPI_Panic()
    * output the source index of vcl sources with the name in
      VCL_Panic()
    
    The additional panic section looks like this:
    
    vpi = 0x7f5478be93b0 {
      handling (VCL::return) = 0x0 (none),
      ref = 6,
      vpi_ref = 0x7f54753fb530 {
        source = 0 (\"<vcl.inline>\"),
        offset = 365,
        line = 20,
        pos = 25,
        src = \"vtc.panic(\\\"Had Panic header: \\\" + resp.ht[...]\"
      },
    },
    
    The source line is truncated (and truncation denoted by [...]) if longer
    than 40 characters.
    
    If the in-memory vcl data source string looks truncated, tok = "..." may
    be output instead of src "...".

diff --git a/bin/varnishd/cache/cache_panic.c b/bin/varnishd/cache/cache_panic.c
index 8b5e33a75..779079f8d 100644
--- a/bin/varnishd/cache/cache_panic.c
+++ b/bin/varnishd/cache/cache_panic.c
@@ -297,11 +297,6 @@ pan_wrk(struct vsb *vsb, const struct worker *wrk)
 	else
 		VSB_printf(vsb, "0x%x,\n", m);
 
-	hand = VCL_Return_Name(wrk->vpi->handling);
-	if (hand != NULL)
-		VSB_printf(vsb, "VCL::return = %s,\n", hand);
-	else
-		VSB_printf(vsb, "VCL::return = 0x%x,\n", wrk->vpi->handling);
 	VSB_cat(vsb, "VCL::methods = {");
 	m = wrk->seen_methods;
 	p = "";
@@ -355,6 +350,7 @@ static void
 pan_busyobj(struct vsb *vsb, const struct busyobj *bo)
 {
 	const char *p;
+	const struct worker *wrk;
 
 	if (PAN_dump_struct(vsb, bo, BUSYOBJ_MAGIC, "busyobj"))
 		return;
@@ -365,8 +361,9 @@ pan_busyobj(struct vsb *vsb, const struct busyobj *bo)
 		pan_req(vsb, bo->req);
 	if (bo->sp != NULL)
 		pan_sess(vsb, bo->sp);
-	if (bo->wrk != NULL)
-		pan_wrk(vsb, bo->wrk);
+	wrk = bo->wrk;
+	if (wrk != NULL)
+		pan_wrk(vsb, wrk);
 
 	if (bo->vfc != NULL)
 		pan_vfp(vsb, bo->vfc);
@@ -408,6 +405,9 @@ pan_busyobj(struct vsb *vsb, const struct busyobj *bo)
 	else
 		VDI_Panic(bo->director_resp, vsb, "director_resp");
 	VCL_Panic(vsb, "vcl", bo->vcl);
+	if (wrk != NULL)
+		VPI_Panic(vsb, wrk->vpi, bo->vcl);
+
 	VSB_indent(vsb, -2);
 	VSB_cat(vsb, "},\n");
 }
@@ -432,6 +432,7 @@ static void
 pan_req(struct vsb *vsb, const struct req *req)
 {
 	const struct transport *xp;
+	const struct worker *wrk;
 
 	if (PAN_dump_struct(vsb, req, REQ_MAGIC, "req"))
 		return;
@@ -466,8 +467,9 @@ pan_req(struct vsb *vsb, const struct req *req)
 	if (req->sp != NULL)
 		pan_sess(vsb, req->sp);
 
-	if (req->wrk != NULL)
-		pan_wrk(vsb, req->wrk);
+	wrk = req->wrk;
+	if (wrk != NULL)
+		pan_wrk(vsb, wrk);
 
 	WS_Panic(vsb, req->ws);
 	if (VALID_OBJ(req->htc, HTTP_CONN_MAGIC))
@@ -479,6 +481,8 @@ pan_req(struct vsb *vsb, const struct req *req)
 		VDP_Panic(vsb, req->vdc);
 
 	VCL_Panic(vsb, "vcl", req->vcl);
+	if (wrk != NULL)
+		VPI_Panic(vsb, wrk->vpi, req->vcl);
 
 	if (req->body_oc != NULL)
 		pan_objcore(vsb, "BODY", req->body_oc);
diff --git a/bin/varnishd/cache/cache_varnishd.h b/bin/varnishd/cache/cache_varnishd.h
index eb3981da0..6d5adea5d 100644
--- a/bin/varnishd/cache/cache_varnishd.h
+++ b/bin/varnishd/cache/cache_varnishd.h
@@ -527,6 +527,7 @@ void WRK_Log(enum VSL_tag_e, const char *, ...);
 /* cache_vpi.c */
 extern const size_t vpi_wrk_len;
 void VPI_wrk_init(struct worker *, void *, size_t);
+void VPI_Panic(struct vsb *, const struct wrk_vpi *, const struct vcl *);
 
 /* cache_ws.c */
 void WS_Panic(struct vsb *, const struct ws *);
diff --git a/bin/varnishd/cache/cache_vcl.c b/bin/varnishd/cache/cache_vcl.c
index 8251e149a..d7a58a5d9 100644
--- a/bin/varnishd/cache/cache_vcl.c
+++ b/bin/varnishd/cache/cache_vcl.c
@@ -291,7 +291,7 @@ vcl_panic_conf(struct vsb *vsb, const struct VCL_conf *conf)
 	VSB_cat(vsb, "srcname = {\n");
 	VSB_indent(vsb, 2);
 	for (i = 0; i < conf->nsrc; ++i)
-		VSB_printf(vsb, "\"%s\",\n", conf->srcname[i]);
+		VSB_printf(vsb, "[%d] = \"%s\",\n", i, conf->srcname[i]);
 	VSB_indent(vsb, -2);
 	VSB_cat(vsb, "},\n");
 	VSB_cat(vsb, "instances = {\n");
diff --git a/bin/varnishd/cache/cache_vpi.c b/bin/varnishd/cache/cache_vpi.c
index e22cc6377..375b4ea4d 100644
--- a/bin/varnishd/cache/cache_vpi.c
+++ b/bin/varnishd/cache/cache_vpi.c
@@ -32,6 +32,8 @@
 
 #include "config.h"
 
+#include <stdio.h>
+
 #include "cache_varnishd.h"
 
 #include "vcl.h"
@@ -78,6 +80,105 @@ VPI_count(VRT_CTX, unsigned u)
 		    ctx->vcl->conf->ref[u].line, ctx->vcl->conf->ref[u].pos);
 }
 
+static void
+vpi_ref_panic(struct vsb *vsb, unsigned n, const struct vcl *vcl)
+{
+	const struct VCL_conf *conf = NULL;
+	const struct vpi_ref *ref;
+	const char *p, *src = NULL;
+	const int lim = 40;
+	const char *abbstr = "[...]";
+	char buf[lim + sizeof(abbstr)];
+	int w = 0;
+
+	AN(vsb);
+
+	if (vcl != NULL)
+		conf = vcl->conf;
+	if (conf != NULL && conf->magic != VCL_CONF_MAGIC)
+		conf = NULL;
+
+	if (conf == NULL) {
+		VSB_printf(vsb, "ref = %u, nref = ?,\n", n);
+		return;
+	}
+	if (n >= conf->nref) {
+		VSB_printf(vsb, "ref = %u *invalid*, nref = %u\n",
+		    n, conf->nref);
+		return;
+	}
+
+	VSB_printf(vsb, "ref = %u,\n", n);
+
+	ref = &conf->ref[n];
+	if (PAN_dump_struct(vsb, ref, VPI_REF_MAGIC, "vpi_ref"))
+		return;
+
+	if (ref->source < conf->nsrc) {
+		VSB_printf(vsb, "source = %u (\"%s\"),\n", ref->source,
+		    conf->srcname[ref->source]);
+		src = conf->srcbody[ref->source];
+	} else {
+		VSB_printf(vsb, "source = %u *invalid*,\n", ref->source);
+	}
+
+	if (src != NULL) {
+		w = strlen(src);
+		if (ref->offset >= w)
+			src = NULL;
+	}
+	if (src != NULL) {
+		src += ref->offset;
+		p = strchr(src, '\n');
+		if (p != NULL)
+			w = p - src;
+		else
+			w -= ref->offset;
+		if (w > lim) {
+			w = snprintf(buf, sizeof buf, "%.*s%s",
+			    lim, src, abbstr);
+			src = buf;
+		}
+	}
+
+	VSB_printf(vsb, "offset = %u,\n", ref->offset);
+	VSB_printf(vsb, "line = %u,\n", ref->line);
+	VSB_printf(vsb, "pos = %u,\n", ref->pos);
+	if (src != NULL) {
+		VSB_cat(vsb, "src = ");
+		VSB_quote(vsb, src, w, VSB_QUOTE_CSTR);
+		VSB_putc(vsb, '\n');
+	} else {
+		VSB_printf(vsb, "token = \"%s\"\n", ref->token);
+	}
+	VSB_indent(vsb, -2);
+	VSB_cat(vsb, "},\n");
+
+}
+void
+VPI_Panic(struct vsb *vsb, const struct wrk_vpi *vpi, const struct vcl *vcl)
+{
+	const char *hand;
+
+	AN(vsb);
+	if (PAN_dump_struct(vsb, vpi, WRK_VPI_MAGIC, "vpi"))
+		return;
+
+	hand = VCL_Return_Name(vpi->handling);
+	if (vpi->handling == 0)
+		hand = "none";
+	else if (hand == NULL)
+		hand = "*invalid*";
+
+	VSB_printf(vsb, "handling (VCL::return) = 0x%x (%s),\n",
+	    vpi->handling, hand);
+
+	vpi_ref_panic(vsb, vpi->ref, vcl);
+
+	VSB_indent(vsb, -2);
+	VSB_cat(vsb, "},\n");
+}
+
 /*
  * After vcl_fini {} == VGC_function_vcl_fini() is called from VGC_Discard(),
  * handling must either be OK from VCL "return (ok)" or FAIL from VRT_fail().


More information about the varnish-commit mailing list