Extended formatters in varnishncsa

The formatters %{Varnish:vxid}x and %{VSL:key[:field]} are introduced,
with documentation. Also updated copyright in the varnishncsa.c file.

bin/varnishncsa/varnishncsa.c

 /*-
  * Copyright (c) 2006 Verdens Gang AS
- * Copyright (c) 2006-2015 Varnish Software AS
+ * Copyright (c) 2006-2016 Varnish Software AS
  * All rights reserved.
  *
  * Author: Anders Berg <andersb@vgnett.no>
@@ -49,7 +49,7 @@
 #include <string.h>
 #include <errno.h>
 #include <stdarg.h>
-#include <stdint.h>
+#include <inttypes.h>
 #include <limits.h>
 #include <ctype.h>
 #include <time.h>
@@ -110,6 +110,7 @@ struct format {
 	char			*string;
 	const char *const	*strptr;
 	char			*time_fmt;
+	int32_t			*int32;
 };
 
 struct watch {
@@ -123,6 +124,17 @@ struct watch {
 };
 VTAILQ_HEAD(watch_head, watch);
 
+struct vsl_watch {
+	unsigned		magic;
+#define VSL_WATCH_MAGIC		0xE3E27D23
+
+	VTAILQ_ENTRY(vsl_watch)	list;
+	enum VSL_tag_e		tag;
+	int			idx;
+	struct fragment		frag;
+};
+VTAILQ_HEAD(vsl_watch_head, vsl_watch);
+
 struct ctx {
 	/* Options */
 	int			a_opt;
@@ -139,10 +151,12 @@ struct ctx {
 	struct watch_head	watch_vcl_log;
 	struct watch_head	watch_reqhdr; /* also bereqhdr */
 	struct watch_head	watch_resphdr; /* also beresphdr */
+	struct vsl_watch_head	watch_vsl;
 	struct fragment		frag[F__MAX];
 	const char		*hitmiss;
 	const char		*handling;
 	const char		*side;
+	int32_t			vxid;
 } CTX;
 
 static void
@@ -268,6 +282,15 @@ format_strptr(const struct format *format)
 	return (1);
 }
 
+static int __match_proto__(format_f)
+format_int32(const struct format *format)
+{
+
+	CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
+	VSB_printf(CTX.vsb, "%" PRIi32, *format->int32);
+	return (1);
+}
+
 static int __match_proto__(format_f)
 format_fragment(const struct format *format)
 {
@@ -447,6 +470,19 @@ addf_fragment(struct fragment *frag, const char *str)
 	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
 }
 
+static void
+addf_int32(int32_t *i)
+{
+	struct format *f;
+
+	AN(i);
+	ALLOC_OBJ(f, FORMAT_MAGIC);
+	AN(f);
+	f->func = &format_int32;
+	f->int32 = i;
+	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
+}
+
 static void
 addf_time(char type, const char *fmt, const char *str)
 {
@@ -529,6 +565,21 @@ addf_hdr(struct watch_head *head, const char *key, const char *str)
 	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
 }
 
+static void
+addf_vsl(enum VSL_tag_e tag, long i)
+{
+	struct vsl_watch *w;
+
+	ALLOC_OBJ(w, VSL_WATCH_MAGIC);
+	AN(w);
+	w->tag = tag;
+	assert(i <= INT_MAX);
+	w->idx = i;
+	VTAILQ_INSERT_TAIL(&CTX.watch_vsl, w, list);
+
+	addf_fragment(&w->frag, "-");
+}
+
 static void
 addf_auth(const char *str)
 {
@@ -544,6 +595,73 @@ addf_auth(const char *str)
 	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
 }
 
+static void
+parse_x_format(char *buf)
+{
+	char *r, *s, c;
+	int slt;
+	long i;
+
+	if (!strcmp(buf, "Varnish:time_firstbyte")) {
+		addf_fragment(&CTX.frag[F_ttfb], "");
+		return;
+	}
+	if (!strcmp(buf, "Varnish:hitmiss")) {
+		addf_strptr(&CTX.hitmiss);
+		return;
+	}
+	if (!strcmp(buf, "Varnish:handling")) {
+		addf_strptr(&CTX.handling);
+		return;
+	}
+	if (!strcmp(buf, "Varnish:side")) {
+		addf_strptr(&CTX.side);
+		return;
+	}
+	if (!strcmp(buf, "Varnish:vxid")) {
+		addf_int32(&CTX.vxid);
+		return;
+	}
+	if (!strncmp(buf, "VCL_Log:", 8)) {
+		addf_vcl_log(buf + 8, "");
+		return;
+	}
+	if (!strncmp(buf, "VSL:", 4)) {
+		buf += 4;
+		r = buf;
+		while(*r != ':' && *r != '\0')
+			r++;
+		c = *r;
+		*r = '\0';
+		slt = VSL_Name2Tag(buf, -1);
+		if (slt == -2)
+			VUT_Error(1, "Tag not unique: %s", buf);
+		if (slt == -1)
+			VUT_Error(1, "Unknown log tag: %s", buf);
+		assert(slt >= 0);
+		if (c) {
+			i = strtol(r + 1, &s, 10);
+			if (*s)
+				VUT_Error(1,
+				    "Not a number: %s (see VSL:%s)",
+				    r + 1, buf);
+			if (i < 0)
+				VUT_Error(1,
+				    "Illegal '-' in field specifier for VSL:%s",
+				    buf);
+		} else
+			i = 0;
+		if (i > INT_MAX) {
+			VUT_Error(1, "Field specifier %ld for the tag VSL:%s"
+			    " is probably too high",
+			    i, buf);
+		}
+		addf_vsl(slt, i);
+		return;
+	}
+	VUT_Error(1, "Unknown formatting extension: %s", buf);
+}
+
 static void
 parse_format(const char *format)
 {
@@ -650,27 +768,8 @@ parse_format(const char *format)
 				addf_time(*q, buf, NULL);
 				break;
 			case 'x':
-				if (!strcmp(buf, "Varnish:time_firstbyte")) {
-					addf_fragment(&CTX.frag[F_ttfb], "");
-					break;
-				}
-				if (!strcmp(buf, "Varnish:hitmiss")) {
-					addf_strptr(&CTX.hitmiss);
-					break;
-				}
-				if (!strcmp(buf, "Varnish:handling")) {
-					addf_strptr(&CTX.handling);
-					break;
-				}
-				if (!strcmp(buf, "Varnish:side")) {
-					addf_strptr(&CTX.side);
-					break;
-				}
-				if (!strncmp(buf, "VCL_Log:", 8)) {
-					addf_vcl_log(buf + 8, "");
-					break;
-				}
-				/* FALLTHROUGH */
+				parse_x_format(buf);
+				break;
 			default:
 				VUT_Error(1, "Unknown format specifier at: %s",
 				    p - 2);
@@ -795,6 +894,7 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
 	unsigned tag;
 	const char *b, *e, *p;
 	struct watch *w;
+	struct vsl_watch *vslw;
 	int i, skip, be_mark;
 	(void)vsl;
 	(void)priv;
@@ -820,6 +920,7 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
 			continue;
 		CTX.hitmiss = "-";
 		CTX.handling = "-";
+		CTX.vxid = t->vxid;
 		skip = 0;
 		while (skip == 0 && 1 == VSL_Next(t->c)) {
 			tag = VSL_TAG(t->c->rec.ptr);
@@ -960,6 +1061,18 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
 			if ((tag == SLT_RespHeader && CTX.c_opt)
 			    || (tag == SLT_BerespHeader && CTX.b_opt))
 				process_hdr(&CTX.watch_resphdr, b, e);
+
+			VTAILQ_FOREACH(vslw, &CTX.watch_vsl, list) {
+				CHECK_OBJ_NOTNULL(vslw, VSL_WATCH_MAGIC);
+				if (tag == vslw->tag) {
+					if (vslw->idx == 0)
+						frag_line(0, b, e, &vslw->frag);
+					else
+						frag_fields(0, b, e,
+						    vslw->idx, &vslw->frag,
+						    0, NULL);
+				}
+			}
 		}
 		if (skip)
 			continue;
@@ -1010,6 +1123,7 @@ main(int argc, char * const *argv)
 	VTAILQ_INIT(&CTX.watch_vcl_log);
 	VTAILQ_INIT(&CTX.watch_reqhdr);
 	VTAILQ_INIT(&CTX.watch_resphdr);
+	VTAILQ_INIT(&CTX.watch_vsl);
 	CTX.vsb = VSB_new_auto();
 	AN(CTX.vsb);
 	VB64_init();

doc/sphinx/reference/varnishncsa.rst

@@ -170,9 +170,20 @@ Supported formatters are:
     quotes), depending on where the request was made. In pure backend
     or client mode, this field will be constant.
 
+  Varnish:vxid
+    The VXID of the varnish transaction.
+
   VCL_Log:key
     Output value set by std.log("key:value") in VCL.
 
+  VSL:key[:field]
+    The value of the varnishlog entry with the given key.  If field is
+    specified, only the selected part is shown.  Specifying ":0" is
+    equivalent to not specifying a field, where the entire field is
+    printed.  Defaults to "-" (without the quotes) when the key is not
+    seen, or when the field is out of bounds.  If a key appears several
+    times in a given transaction, only the first occurrence is used.
+
 SIGNALS
 =======