Permalink
Browse files

Add varnishlog capability to varnishtest

What this adds:

- When given a second -v, varnishlog output is added to the overall test log.

- The varnish component gets a -logexpecttag action. It takes 2 arguments, a
number (0+) and a VSL tag. It will see how many of said tag have passed by
since the child was started, and match it with the number.

- And it gets a -logexpectregex action. Again 2 arguments, a number (0+) and a
regex. The regex is matched with the contents of the loglines, just like
varnishlog et al do.

Do give the varnishd a smidgen of time to write to the VSL before doing your
expects. How much is a bit of an inexact science, but 0.2 has been working for
me. (See a00012.vtc)

Any comments are welcome, as are suggestions for better alternatives to
-logexpect(tag|regex). They're a bit horrible in length.

Also, I'm tempted to scrap the second verbosity level and always include VSL
in the test log. Opinions on that?
  • Loading branch information...
drwilco committed Sep 14, 2011
1 parent 6447d64 commit 8c2c9f21f6ab9225d55d4c6c687c348d8d9ebcda
Showing with 298 additions and 3 deletions.
  1. +94 −0 bin/varnishtest/tests/a00012.vtc
  2. +1 −0 bin/varnishtest/vtc.h
  3. +3 −2 bin/varnishtest/vtc_main.c
  4. +200 −1 bin/varnishtest/vtc_varnish.c
@@ -0,0 +1,94 @@
+varnishtest "Test varnishlog function"
+
+server s1 {
+ rxreq
+ txresp -hdr "X-Foo: Bar" -hdr "Cache-Control: max-age=0"
+} -start
+server s2 {
+ rxreq
+ txresp -hdr "X-Foo: Bar" -hdr "Cache-Control: max-age=0"
+} -start
+
+varnish v1 -vcl+backend {
+import std from "${topbuild}/lib/libvmod_std/.libs/libvmod_std.so";
+ sub vcl_recv {
+ set req.backend = s2;
+ set req.backend = s1;
+ std.log("this is v1");
+ }
+} -start
+
+varnish v2 -vcl+backend {
+import std from "${topbuild}/lib/libvmod_std/.libs/libvmod_std.so";
+ sub vcl_recv {
+ set req.backend = s1;
+ set req.backend = s2;
+ std.log("this is v2");
+ std.log("no really!");
+ }
+} -start
+
+client c1 {
+ txreq
+ rxresp
+ expect resp.http.X-Foo == "Bar"
+} -run
+
+client c2 -connect ${v2_sock} {
+ txreq
+ rxresp
+ expect resp.http.X-Foo == "Bar"
+} -run
+
+# give the log a moment to catch up
+delay 0.2
+
+# there should be no crosstalk
+varnish v1 -logexpecttag 1 VCL_Log
+varnish v2 -logexpecttag 2 VCL_Log
+
+# shouldn't be case sensitive
+varnish v1 -logexpecttag 1 vcl_log
+varnish v1 -logexpecttag 1 vcl_lOG
+
+varnish v1 -logexpecttag 1 RxURL
+
+server s1 -wait
+
+varnish v1 -stop -start
+
+server s1 {
+ rxreq
+ txresp -hdr "X-Foo: Bar"
+} -start
+
+varnish v1 -logexpecttag 0 RxURL
+
+client c1 {
+ txreq
+ rxresp
+ expect resp.http.X-Foo == "Bar"
+} -run
+
+delay 0.2
+
+varnish v1 -logexpectregex 3 "X-Foo: Bar"
+varnish v1 -logexpectregex 3 "X-Foo: B.."
+
+# check proper multiline handling
+varnish v1 -logexpectregex 3 "^X-Foo: Bar"
+varnish v1 -logexpectregex 3 "X-Foo: Bar$"
+varnish v1 -logexpectregex 0 "^Bar"
+varnish v1 -logexpectregex 0 "X-Foo$"
+
+# there should be no crosstalk
+varnish v1 -logexpectregex 1 "^this is v1$"
+varnish v1 -logexpectregex 0 "^this is v2$"
+varnish v2 -logexpectregex 0 "^this is v1$"
+varnish v2 -logexpectregex 1 "^this is v2$"
+
+# and finally, nothing should be found after a restart
+varnish v1 -stop -start
+delay 0.2
+varnish v1 -logexpectregex 0 "X-Foo: Bar"
+varnish v1 -logexpecttag 0 VCL_Log
View
@@ -61,6 +61,7 @@ cmd_f cmd_sema;
extern volatile sig_atomic_t vtc_error; /* Error, bail out */
extern int vtc_stop; /* Abandon current test, no error */
extern pthread_t vtc_thread;
+extern int vtc_verbosity;
void init_sema(void);
@@ -83,11 +83,12 @@ static int njob = 0;
static int npar = 1; /* Number of parallel tests */
static unsigned vtc_maxdur = 60; /* Max duration of any test */
static int vtc_continue; /* Continue on error */
-static int vtc_verbosity = 1; /* Verbosity Level */
static int vtc_good;
static int vtc_fail;
static int leave_temp;
+int vtc_verbosity = 1; /* Verbosity Level */
+
/**********************************************************************
* Parse a -D option argument into a name/val pair, and insert
* into extmacro list
@@ -370,7 +371,7 @@ main(int argc, char * const *argv)
vtc_maxdur = strtoul(optarg, NULL, 0);
break;
case 'v':
- if (vtc_verbosity < 2)
+ if (vtc_verbosity < 3)
vtc_verbosity++;
break;
default:
Oops, something went wrong.

0 comments on commit 8c2c9f2

Please sign in to comment.