Add VSL Query/Dispatch structured log messages facility

Move vtree.h from varnishtop to include directory so it's available for anyone.

Simple proof-of-concept single regex against any log line query
implementation.

bin/varnishtop/Makefile.am

@@ -8,8 +8,7 @@ dist_man_MANS = varnishtop.1
 
 varnishtop_SOURCES = varnishtop.c \
 	$(top_builddir)/lib/libvarnish/vas.c \
-	$(top_builddir)/lib/libvarnish/version.c \
-	vtree.h
+	$(top_builddir)/lib/libvarnish/version.c
 
 varnishtop_LDADD = \
 	$(top_builddir)/lib/libvarnishcompat/libvarnishcompat.la \

include/Makefile.am

@@ -57,7 +57,8 @@ nobase_noinst_HEADERS = \
 	vsub.h \
 	vss.h \
 	vtcp.h \
-	vtim.h
+	vtim.h \
+	vtree.h
 
 # Headers for use with vmods
 pkgdataincludedir = $(pkgdatadir)/include

include/vapi/vsl.h

 /*-
  * Copyright (c) 2006 Verdens Gang AS
- * Copyright (c) 2006-2011 Varnish Software AS
+ * Copyright (c) 2006-2013 Varnish Software AS
  * All rights reserved.
  *
  * Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
+ * Author: Martin Blix Grydeland <martin@varnish-software.com>
  *
  * Redistribution and use in source and binary forms, with or without
  * modification, are permitted provided that the following conditions
@@ -48,9 +49,27 @@
 			VSL_x_USAGE
 
 struct VSL_data;
+struct VSLQ;
 
 struct VSL_cursor {
 	const uint32_t		*ptr; /* Record pointer */
+
+	/* If not -1, the vxid of all records in this set */
+	int32_t			vxid;
+
+	/* For set cursors, the depth level of these records */
+	unsigned level;
+
+	/* Nonzero if pointer values from this cursor are still valid
+	   after next call to VSL_Next */
+	unsigned shmptr_ok;
+};
+
+enum VSL_grouping_e {
+	VSL_g_raw,
+	VSL_g_vxid,
+	VSL_g_request,
+	VSL_g_session,
 };
 
 extern const char *VSL_tags[256];
@@ -155,13 +174,138 @@ int VSL_Match(struct VSL_data *vsl, const struct VSL_cursor *c);
 	 *	0:	No match
 	 */
 
-int VSL_Print(struct VSL_data *vsl, const struct VSL_cursor *c, void *file);
+int VSL_PrintVXID(struct VSL_data *vsl, const struct VSL_cursor *c, void *fo);
+	/*
+	 * Print the log record pointed to by cursor to stream.
+	 *
+	 * Format: <vxid> <tag> <type> <data>
+	 *
+	 * Arguments:
+	 *   vsl: The VSL_data context
+	 *     c: A VSL_cursor
+	 *    fo: A FILE* pointer
+	 *
+	 * Return values:
+	 *	0:	OK
+	 *     -5:	I/O write error - see errno
+	 */
+
+int VSL_PrintLevel(struct VSL_data *vsl, const struct VSL_cursor *c, void *fo);
 	/*
 	 * Print the log record pointed to by cursor to stream.
 	 *
+	 * Format: <level> <tag> <type> <data>
+	 *
+	 * Arguments:
+	 *   vsl: The VSL_data context
+	 *     c: A VSL_cursor
+	 *    fo: A FILE* pointer
+	 *
 	 * Return values:
 	 *	0:	OK
 	 *     -5:	I/O write error - see errno
 	 */
 
+int VSL_PrintAll(struct VSL_data *vsl, struct VSL_cursor *c, void *fo);
+	/*
+	 * Calls VSL_Next on c until c is exhausted. In turn calls
+	 * prints all records where VSL_Match returns true.
+	 *
+	 * If c->vxid == -1, calls VSL_PrintVXID on each record. Else
+	 * prints a VXID header and calls VSL_PrintLevel on each record.
+	 *
+	 * Arguments:
+	 *   vsl: The VSL_data context
+	 *     c: A VSL_cursor
+	 *    fo: A FILE* pointer, stdout if NULL
+	 *
+	 * Return values:
+	 *	0:	OK
+	 *    !=0:	Return value from either VSL_Next or VSL_Print
+	 */
+
+int VSL_PrintSet(struct VSL_data *vsl, struct VSL_cursor *cp[], void *fo);
+	/*
+	 * Calls VSL_PrintAll on each cursor in cp[]. If any cursor in cp
+	 * has vxid != -1 it will end with a double line break as a set
+	 * delimeter.
+	 *
+	 * Arguments:
+	 *   vsl: The VSL_data context
+	 *    cp: A NULL-terminated array of VSL_cursor pointers
+	 *    fo: A FILE* pointer, stdout if NULL
+	 *
+	 * Return values:
+	 *	0:	OK
+	 *    !=0:	Return value from either VSL_Next or VSL_PrintAll
+	 */
+
+struct VSLQ *VSLQ_New(struct VSL_data *vsl, struct VSL_cursor **cp,
+    enum VSL_grouping_e grouping, const char *query);
+	/*
+	 * Create a new query context using cp. On success cp is NULLed,
+	 * and will be deleted when deleting the query.
+	 *
+	 * Arguments:
+	 *       vsl: The VSL_data context
+	 *        cp: The cursor to use
+	 *  grouping: VXID grouping to report on
+	 *     query: Query match expression
+	 *
+	 * Return values:
+	 *  non-NULL: OK
+	 *      NULL: Error - see VSL_Error
+	 */
+
+void VSLQ_Delete(struct VSLQ **pvslq);
+	/*
+	 * Delete the query pointed to by pvslq, freeing up the resources
+	 */
+
+typedef int VSLQ_dispatch_f(struct VSL_data *vsl, struct VSL_cursor *cp[],
+    void *priv);
+	/*
+	 * The callback function type for use with VSLQ_Dispatch.
+	 *
+	 * Arguments:
+	 *   vsl: The VSL_data context
+	 *  cp[]: A NULL terminated array of pointer to cursors. Each cursor
+	 *        will iterate over the log records of a single VXID
+	 *  priv: The priv argument from VSL_Dispatch
+	 *
+	 * Return value:
+	 *     0: OK - continue
+	 *   !=0: Makes VSLQ_Dispatch return with this return value immediatly
+	 */
+
+int VSLQ_Dispatch(struct VSLQ *vslq, VSLQ_dispatch_f *func, void *priv);
+	/*
+	 * Process log and call func for each set matching the specified
+	 * query
+	 *
+	 * Arguments:
+	 *  vslq: The VSLQ query
+	 *  func: The callback function to call. Can be NULL to ignore records.
+	 *  priv: An argument passed to func
+	 *
+	 * Return values:
+	 *     0: No more log records available
+	 *   !=0: The return value from either VSL_Next() or func
+	 */
+
+int VSLQ_Flush(struct VSLQ *vslq, VSLQ_dispatch_f *func, void *priv);
+	/*
+	 * Flush any pending record sets from the query.
+	 *
+	 * Arguments:
+	 *  vslq: The VSL context
+	 *  func: The callback function to call. Pass NULL to discard the
+	 *        pending messages
+	 *  priv: An argument passed to func
+	 *
+	 * Return values:
+	 *     0: OK
+	 *   !=0: The return value from func
+	 */
+
 #endif /* VAPI_VSL_H_INCLUDED */

lib/libvarnishapi/Makefile.am

@@ -27,6 +27,8 @@ libvarnishapi_la_SOURCES = \
 	vsm.c \
 	vsl_arg.c \
 	vsl_cursor.c \
+	vsl_dispatch.c \
+	vsl_query.c \
 	vsl.c \
 	vsc.c \
 	libvarnishapi.map

lib/libvarnishapi/libvarnishapi.map

@@ -104,6 +104,13 @@ LIBVARNISHAPI_1.3 {
 	VSL_DeleteCursor;
 	VSL_Next;
 	VSL_Match;
-	VSL_Print;
+	VSL_PrintVXID;
+	VSL_PrintLevel;
+	VSL_PrintAll;
+	VSL_PrintSet;
+	VSLQ_New;
+	VSLQ_Delete;
+	VSLQ_Dispatch;
+	VSLQ_Flush;
 	# Variables:
 } LIBVARNISHAPI_1.0;

lib/libvarnishapi/vsl.c

@@ -155,7 +155,7 @@ VSL_Match(struct VSL_data *vsl, const struct VSL_cursor *c)
 }
 
 int
-VSL_Print(struct VSL_data *vsl, const struct VSL_cursor *c, void *fo)
+VSL_PrintVXID(struct VSL_data *vsl, const struct VSL_cursor *c, void *fo)
 {
 	enum VSL_tag_e tag;
 	uint32_t vxid;
@@ -200,3 +200,101 @@ VSL_Print(struct VSL_data *vsl, const struct VSL_cursor *c, void *fo)
 		return (-5);
 	return (0);
 }
+
+int
+VSL_PrintLevel(struct VSL_data *vsl, const struct VSL_cursor *c, void *fo)
+{
+	enum VSL_tag_e tag;
+	unsigned len, lvl;
+	const char *data;
+	int type;
+	int i;
+
+	CHECK_OBJ_NOTNULL(vsl, VSL_MAGIC);
+	if (c == NULL || c->ptr == NULL)
+		return (0);
+	if (fo == NULL)
+		fo = stdout;
+
+	tag = VSL_TAG(c->ptr);
+	len = VSL_LEN(c->ptr);
+	type = VSL_CLIENT(c->ptr) ? 'c' : VSL_BACKEND(c->ptr) ? 'b' : '-';
+	data = VSL_CDATA(c->ptr);
+	lvl = c->level;
+	if (tag == SLT_Debug) {
+		i = fprintf(fo, "%2u %-15s %c \"", lvl, VSL_tags[tag],
+		    type);
+		if (i < 0)
+			return (-5);
+		while (len-- > 0) {
+			if (*data >= ' ' && *data <= '~')
+				i = fprintf(fo, "%c", *data);
+			else
+				i = fprintf(fo, "%%%02x",
+				    (unsigned char)*data);
+			if (i < 0)
+				return (-5);
+			data++;
+		}
+		i = fprintf(fo, "\"\n");
+		if (i < 0)
+			return (-5);
+		return (0);
+	}
+	i = fprintf(fo, "%2u %-15s %c %.*s\n",
+	    lvl, VSL_tags[tag], type, (int)len, data);
+	if (i < 0)
+		return (-5);
+	return (0);
+}
+
+int
+VSL_PrintAll(struct VSL_data *vsl, struct VSL_cursor *c, void *fo)
+{
+	int i;
+
+	if (c == NULL)
+		return (0);
+	if (c->vxid >= 0) {
+		i = fprintf(fo, "vv VXID: %11u vv\n", c->vxid);
+		if (i < 0)
+			return (-5);
+	}
+	while (1) {
+		i = VSL_Next(c);
+		if (i <= 0)
+			return (i);
+		if (!VSL_Match(vsl, c))
+			continue;
+		if (c->vxid < 0)
+			i = VSL_PrintVXID(vsl, c, fo);
+		else
+			i = VSL_PrintLevel(vsl, c, fo);
+		if (i != 0)
+			return (i);
+	}
+}
+
+int
+VSL_PrintSet(struct VSL_data *vsl, struct VSL_cursor *cp[], void *fo)
+{
+	int i;
+	int delim = 0;
+	struct VSL_cursor *c;
+
+	c = cp[0];
+	while (c) {
+		if (c->vxid >= 0)
+			delim = 1;
+		i = VSL_PrintAll(vsl, c, fo);
+		if (i)
+			return (i);
+		c = *++cp;
+	}
+	if (delim) {
+		i = fprintf(fo, "\n");
+		if (i < 0)
+			return (-5);
+	}
+	return (0);
+}

lib/libvarnishapi/vsl_api.h

@@ -37,10 +37,12 @@
 
 int vsl_diag(struct VSL_data *vsl, const char *fmt, ...)
     __printflike(2, 3);
+int vsl_skip(struct VSL_cursor *c, ssize_t words);
 
 typedef void vslc_delete_f(void *);
 typedef int vslc_next_f(void *);
 typedef int vslc_reset_f(void *);
+typedef int vslc_skip_f(void *, ssize_t words);
 
 struct vslc {
 	struct VSL_cursor		c;
@@ -50,6 +52,7 @@ struct vslc {
 	vslc_delete_f			*delete;
 	vslc_next_f			*next;
 	vslc_reset_f			*reset;
+	vslc_skip_f			*skip;
 };
 
 struct VSL_data {
@@ -66,3 +69,10 @@ struct VSL_data {
 	struct vbitmap			*vbm_select;
 	struct vbitmap			*vbm_supress;
 };
+
+/* vsl_query.c */
+struct vslq_query;
+struct vslq_query *vslq_newquery(struct VSL_data *vsl,
+    enum VSL_grouping_e grouping, const char *query);
+void vslq_deletequery(struct vslq_query **pquery);
+int vslq_runquery(struct vslq_query *query, struct VSL_cursor *cp[]);

lib/libvarnishapi/vsl_cursor.c

@@ -169,6 +169,23 @@ vslc_vsm_reset(void *cursor)
 	return (0);
 }
 
+static int
+vslc_vsm_skip(void *cursor, ssize_t words)
+{
+	struct vslc_vsm *c;
+
+	CAST_OBJ_NOTNULL(c, cursor, VSLC_VSM_MAGIC);
+	if (words < 0)
+		return (-1);
+
+	c->next += words;
+	assert(c->next >= c->head->log);
+	assert(c->next < c->end);
+	c->c.c.ptr = NULL;
+
+	return (0);
+}
+
 struct VSL_cursor *
 VSL_CursorVSM(struct VSL_data *vsl, struct VSM_data *vsm, int tail)
 {
@@ -199,10 +216,13 @@ VSL_CursorVSM(struct VSL_data *vsl, struct VSM_data *vsm, int tail)
 		vsl_diag(vsl, "Out of memory\n");
 		return (NULL);
 	}
+	c->c.c.vxid = -1;	/* N/A to this cursor type */
+	c->c.c.shmptr_ok = 1;
 	c->c.magic = VSLC_MAGIC;
 	c->c.delete = vslc_vsm_delete;
 	c->c.next = vslc_vsm_next;
 	c->c.reset = vslc_vsm_reset;
+	c->c.skip = vslc_vsm_skip;
 
 	c->vsm = vsm;
 	c->vf = vf;
@@ -347,6 +367,7 @@ VSL_CursorFile(struct VSL_data *vsl, const char *name)
 		vsl_diag(vsl, "Out of memory\n");
 		return (NULL);
 	}
+	c->c.c.vxid = -1;	/* N/A to this cursor type */
 	c->c.magic = VSLC_MAGIC;
 	c->c.delete = vslc_file_delete;
 	c->c.next = vslc_file_next;
@@ -391,3 +412,14 @@ VSL_Next(struct VSL_cursor *cursor)
 	AN(c->next);
 	return ((c->next)(c));
 }
+
+int
+vsl_skip(struct VSL_cursor *cursor, ssize_t words)
+{
+	struct vslc *c;
+
+	CAST_OBJ_NOTNULL(c, (void *)cursor, VSLC_MAGIC);
+	if (c->skip == NULL)
+		return (-1);
+	return ((c->skip)(c, words));
+}

lib/libvarnishapi/vsl_query.c

+/*-
+ * Copyright (c) 2006 Verdens Gang AS
+ * Copyright (c) 2006-2013 Varnish Software AS
+ * All rights reserved.
+ *
+ * Author: Martin Blix Grydeland <martin@varnish-software.com>
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions
+ * are met:
+ * 1. Redistributions of source code must retain the above copyright
+ *    notice, this list of conditions and the following disclaimer.
+ * 2. Redistributions in binary form must reproduce the above copyright
+ *    notice, this list of conditions and the following disclaimer in the
+ *    documentation and/or other materials provided with the distribution.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
+ * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+ * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+ * ARE DISCLAIMED.  IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
+ * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
+ * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
+ * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
+ * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
+ * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
+ * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+ * SUCH DAMAGE.
+ *
+ */
+
+#include <errno.h>
+#include <unistd.h>
+#include <stdlib.h>
+#include <stdint.h>
+
+#include "vas.h"
+#include "miniobj.h"
+#include "vre.h"
+
+#include "vapi/vsl.h"
+#include "vsl_api.h"
+
+struct vslq_query {
+	unsigned		magic;
+#define VSLQ_QUERY_MAGIC	0x122322A5
+
+	vre_t			*regex;
+};
+
+struct vslq_query *
+vslq_newquery(struct VSL_data *vsl, enum VSL_grouping_e grouping,
+    const char *querystring)
+{
+	struct vslq_query *query;
+	const char *error;
+	int pos;
+	vre_t *regex;
+
+	(void)grouping;
+	AN(querystring);
+	regex = VRE_compile(querystring, 0, &error, &pos);
+	if (regex == NULL) {
+		vsl_diag(vsl, "failed to compile regex at pos %d: %s",
+		    pos, error);
+		return (NULL);
+	}
+
+	ALLOC_OBJ(query, VSLQ_QUERY_MAGIC);
+	query->regex = regex;
+	return (query);
+}
+
+void
+vslq_deletequery(struct vslq_query **pquery)
+{
+	struct vslq_query *query;
+
+	AN(pquery);
+	query = *pquery;
+	*pquery = NULL;
+	CHECK_OBJ_NOTNULL(query, VSLQ_QUERY_MAGIC);
+
+	AN(query->regex);
+	VRE_free(&query->regex);
+	AZ(query->regex);
+
+	FREE_OBJ(query);
+}
+
+int
+vslq_runquery(struct vslq_query *query, struct VSL_cursor *cp[])
+{
+	struct VSL_cursor *c;
+	int i, len;
+	const char *data;
+
+	CHECK_OBJ_NOTNULL(query, VSLQ_QUERY_MAGIC);
+	AN(query->regex);
+
+	c = cp[0];
+	while (c) {
+		while (1) {
+			i = VSL_Next(c);
+			if (i == 0)
+				break;
+			assert(i == 1);
+			AN(c->ptr);
+			len = VSL_LEN(c->ptr);
+			data = VSL_CDATA(c->ptr);
+			i = VRE_exec(query->regex, data, len, 0, 0, NULL, 0,
+			    NULL);
+			if (i != VRE_ERROR_NOMATCH) {
+				AZ(VSL_ResetCursor(c));
+				return (1);
+			}
+		}
+		AZ(VSL_ResetCursor(c));
+		c = *++cp;
+	}
+
+	return (0);
+}