[master] 0c96fc659 vmod_vtc: Add generation of arbitrary log lines
Nils Goroll
nils.goroll at uplex.de
Mon Jan 31 14:55:06 UTC 2022
commit 0c96fc6597c3ba6da057bb43acb7f677e6b776f8
Author: Nils Goroll <nils.goroll at uplex.de>
Date: Fri Jan 28 11:52:57 2022 +0100
vmod_vtc: Add generation of arbitrary log lines
diff --git a/vmod/tests/vtc_b00000.vtc b/vmod/tests/vtc_b00000.vtc
new file mode 100644
index 000000000..bb2f87a8b
--- /dev/null
+++ b/vmod/tests/vtc_b00000.vtc
@@ -0,0 +1,74 @@
+varnishtest "Test vtc.vsl()"
+
+varnish v1 -vcl {
+ import vtc;
+
+ backend proforma none;
+
+ sub vcl_init {
+ # Fake a minimal session log
+ vtc.vsl(9000, "Begin", c, "sess 0 HTTP/1");
+ vtc.vsl(9000, "SessOpen", c, "127.0.0.1 123 a0 127.0.0.1 124 1643281288.313845 22");
+ vtc.vsl(9000, "Link", c, "req 9001 rxreq");
+ vtc.vsl(9001, "Begin", c, "req 9000 rxreq");
+ vtc.vsl(9001, "End", c, "");
+ vtc.vsl(9000, "End", c, "");
+
+ vtc.vsl_replay("""
+**** v1 vsl| 1000 Begin c sess 0 HTTP/1
+**** v1 vsl| 1000 SessOpen c 127.0.0.1 53112 a0 127.0.0.1 37263 1643285160.270383 22
+**** v1 vsl| 1000 Link c req 1001 rxreq
+**** v1 vsl| 1001 Begin c req 1000 rxreq
+**** v1 vsl| 1001 Timestamp c Start: 1643285160.271226 0.000000 0.000000
+**** v1 vsl| 1001 Timestamp c Req: 1643285160.271226 0.000000 0.000000
+**** v1 vsl| 1001 VCL_use c vcl1
+**** v1 vsl| 1001 ReqStart c 127.0.0.1 53112 a0
+**** v1 vsl| 1001 ReqMethod c GET
+**** v1 vsl| 1001 ReqURL c /
+**** v1 vsl| 1001 ReqProtocol c HTTP/1.1
+**** v1 vsl| 1001 ReqHeader c Pattern: /foo/
+**** v1 vsl| 1001 ReqHeader c Subject: /foo/
+**** v1 vsl| 1001 ReqHeader c Host: 127.0.0.1
+**** v1 vsl| 1001 ReqHeader c X-Forwarded-For: 127.0.0.1
+**** v1 vsl| 1001 VCL_call c RECV
+**** v1 vsl| 1001 VCL_return c synth
+**** v1 vsl| 1001 VCL_call c HASH
+**** v1 vsl| 1001 VCL_return c lookup
+**** v1 vsl| 1001 RespProtocol c HTTP/1.1
+**** v1 vsl| 1001 RespStatus c 200
+**** v1 vsl| 1001 RespReason c OK
+**** v1 vsl| 1001 RespHeader c Date: Thu, 27 Jan 2022 12:06:00 GMT
+**** v1 vsl| 1001 RespHeader c Server: Varnish
+**** v1 vsl| 1001 RespHeader c X-Varnish: 1001
+**** v1 vsl| 1001 VCL_call c SYNTH
+**** v1 vsl| 1001 RespHeader c Match: true
+**** v1 vsl| 1001 RespHeader c Match-Nopathname: true
+**** v1 vsl| 1001 RespHeader c Match-Noescape: true
+**** v1 vsl| 1001 RespHeader c Match-Period: true
+**** v1 vsl| 1001 RespHeader c Content-Type: text/html; charset=utf-8
+**** v1 vsl| 1001 RespHeader c Retry-After: 5
+**** v1 vsl| 1001 VCL_return c deliver
+**** v1 vsl| 1001 Timestamp c Process: 1643285160.271421 0.000195 0.000195
+**** v1 vsl| 1001 RespHeader c Content-Length: 227
+**** v1 vsl| 1001 Storage c malloc Transient
+**** v1 vsl| 1001 Filters c
+**** v1 vsl| 1001 RespHeader c Connection: keep-alive
+**** v1 vsl| 1001 Timestamp c Resp: 1643285160.271493 0.000267 0.000072
+**** v1 vsl| 1001 ReqAcct c 67 0 67 270 227 497
+**** v1 vsl| 1001 End c
+**** v1 vsl| 1000 SessClose c REM_CLOSE 0.009
+**** v1 vsl| 1000 End c
+""");
+ }
+} -start
+
+logexpect l1 -v v1 -d 1 -g vxid {
+ expect * 9000 Begin sess
+ expect 5 9000 End
+} -run
+
+logexpect l2 -v v1 -d 1 -g session -q "SessOpen ~ 53112" {
+ expect * 1000 Begin sess
+ expect * 1001 Begin req
+ expect * = RespHeader Connection:
+} -run
diff --git a/vmod/vmod_vtc.c b/vmod/vmod_vtc.c
index 31412c06c..53387c7ee 100644
--- a/vmod/vmod_vtc.c
+++ b/vmod/vmod_vtc.c
@@ -31,6 +31,7 @@
#include "config.h"
+#include <stdlib.h>
#include <stdio.h>
#include <string.h>
#include <unistd.h>
@@ -362,3 +363,161 @@ vmod_proxy_header(VRT_CTX, VCL_ENUM venum, VCL_IP client, VCL_IP server,
return (VRT_blob(ctx, "proxy_header", h, l,
BLOB_VMOD_PROXY_HEADER_TYPE));
}
+
+// ref vsl.c
+struct vsl_tag2enum {
+ const char *string;
+ enum VSL_tag_e tag;
+};
+
+static struct vsl_tag2enum vsl_tag2enum[SLT__MAX] = {
+#define SLTM(name,flags,sdesc,ldesc) [SLT_ ## name] = { \
+ .string = #name, \
+ .tag = SLT_ ## name \
+ },
+#include "tbl/vsl_tags.h"
+};
+
+static int
+vsl_tagcmp(const void *aa, const void *bb)
+{
+ const struct vsl_tag2enum *a = aa, *b = bb;
+
+ // ref vsl2rst.c ptag_cmp
+ if (a->string == NULL && b->string != NULL)
+ return (1);
+ else if (a->string != NULL && b->string == NULL)
+ return (-1);
+ else if (a->string == NULL && b->string == NULL)
+ return (0);
+ return (strcmp(a->string, b->string));
+}
+
+/*lint -esym(528, init_vsl_tag2enum) */
+static void __attribute__((constructor))
+init_vsl_tag2enum(void)
+{
+ qsort(vsl_tag2enum, SLT__MAX, sizeof *vsl_tag2enum, vsl_tagcmp);
+}
+
+
+VCL_VOID
+vmod_vsl(VRT_CTX, VCL_INT id, VCL_STRING tag_s, VCL_ENUM side, VCL_STRANDS s)
+{
+ struct vsl_tag2enum *te, key;
+ uint32_t vxid;
+
+ CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
+
+ key.string = tag_s;
+ te = bsearch(&key, vsl_tag2enum, SLT__MAX,
+ sizeof *vsl_tag2enum, vsl_tagcmp);
+
+ if (te == NULL) {
+ VRT_fail(ctx, "No such tag: %s", tag_s);
+ return;
+ }
+
+ if (id < 0 || id > VSL_IDENTMASK) {
+ VRT_fail(ctx, "id out of bounds");
+ return;
+ }
+
+ vxid = id & VSL_IDENTMASK;
+ if (side == VENUM(c))
+ vxid |= VSL_CLIENTMARKER;
+ else if (side == VENUM(b))
+ vxid |= VSL_BACKENDMARKER;
+ else
+ WRONG("side");
+
+ VSLs(te->tag, vxid, s);
+}
+
+static void
+vsl_line(VRT_CTX, char *str)
+{
+ VCL_INT id;
+ VCL_ENUM side;
+ VCL_STRANDS s;
+ const char *tag, *delim = " \t\r\n";
+ char *save;
+
+ if (*str == '*') {
+ // varnishtest
+ str = strstr(str, "vsl|");
+ if (str == NULL)
+ return;
+ str += 4;
+ }
+ if ((str = strtok_r(str, delim, &save)) == NULL)
+ return;
+ id = strtoll(str, NULL, 10);
+
+ if ((str = strtok_r(NULL, delim, &save)) == NULL)
+ return;
+ tag = str;
+
+ if ((str = strtok_r(NULL, delim, &save)) == NULL)
+ return;
+ if (*str == 'c')
+ side = VENUM(c);
+ else if (*str == 'b')
+ side = VENUM(b);
+ else
+ return;
+
+ str = strtok_r(NULL, "\r\n", &save);
+ if (str == NULL)
+ s = vrt_null_strands;
+ else
+ s = TOSTRAND(str);
+
+ vmod_vsl(ctx, id, tag, side, s);
+}
+
+VCL_VOID
+vmod_vsl_replay(VRT_CTX, VCL_STRANDS s)
+{
+ struct vsb cp[1];
+ const char *p, *pp;
+ size_t l;
+ int i, err = 0;
+
+ if (s == NULL || s->n == 0)
+ return;
+
+ CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
+ CHECK_OBJ_NOTNULL(ctx->ws, WS_MAGIC);
+ WS_VSB_new(cp, ctx->ws);
+
+ for (i = 0; i < s->n; i++) {
+ p = s->p[i];
+ if (p == NULL || *p == '\0')
+ continue;
+ pp = strpbrk(p, "\r\n");
+ while (pp != NULL) {
+ l = pp - p;
+ if (VSB_bcat(cp, p, l) || VSB_finish(cp)) {
+ err = 1;
+ break;
+ }
+ vsl_line(ctx, VSB_data(cp));
+ VSB_clear(cp);
+ p = pp + 1;
+ pp = strpbrk(p, "\r\n");
+ }
+ if (err || VSB_cat(cp, p)) {
+ err = 1;
+ break;
+ }
+ }
+ if (err || VSB_finish(cp)) {
+ AZ(WS_VSB_finish(cp, ctx->ws, NULL));
+ VRT_fail(ctx, "out of workspace");
+ return;
+ }
+ vsl_line(ctx, VSB_data(cp));
+ VSB_clear(cp);
+ AN(WS_VSB_finish(cp, ctx->ws, NULL));
+}
diff --git a/vmod/vmod_vtc.vcc b/vmod/vmod_vtc.vcc
index d19aef94d..52578e7b3 100644
--- a/vmod/vmod_vtc.vcc
+++ b/vmod/vmod_vtc.vcc
@@ -169,6 +169,30 @@ version ``v1``).
Candidate for moving into vmod_proxy, but there were concerns about
the interface design
+VSL
+===
+
+These functions allow to generate arbitrary log entries to test the
+Varnish Shared Log (VSL) implementation and readers like varnishlog.
+
+$Function VOID vsl(INT vxid, STRING tag, ENUM { c, b } side, STRANDS s)
+
+Call ``VSLs()`` with the given parameters.
+
+The argument order is chosen to match VSL output.
+
+A VCL error is triggered if `tag` can not be resolved at runtime or
+if vxid is out of bounds.
+
+$Function VOID vsl_replay(STRANDS s)
+
+Replay literal log lines.
+
+The parser accepts the output generated by ``varnishlog -g raw`` and
+varnishtest log ``vsl|`` lines.
+
+Unparsable lines are silently ignored.
+
SEE ALSO
========
More information about the varnish-commit
mailing list