varnish-cache/bin/varnishtest/vtc_varnish.c
1
/*-
2
 * Copyright (c) 2008-2015 Varnish Software AS
3
 * All rights reserved.
4
 *
5
 * Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
6
 *
7
 * Redistribution and use in source and binary forms, with or without
8
 * modification, are permitted provided that the following conditions
9
 * are met:
10
 * 1. Redistributions of source code must retain the above copyright
11
 *    notice, this list of conditions and the following disclaimer.
12
 * 2. Redistributions in binary form must reproduce the above copyright
13
 *    notice, this list of conditions and the following disclaimer in the
14
 *    documentation and/or other materials provided with the distribution.
15
 *
16
 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
17
 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18
 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19
 * ARE DISCLAIMED.  IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
20
 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
21
 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
22
 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
23
 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
24
 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
25
 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
26
 * SUCH DAMAGE.
27
 */
28
29
#include "config.h"
30
31
#include <sys/types.h>
32
#include <sys/socket.h>
33
34
#include <errno.h>
35
#include <fcntl.h>
36
#include <fnmatch.h>
37
#include <inttypes.h>
38
#include <poll.h>
39
#include <stdio.h>
40
#include <stdlib.h>
41
#include <string.h>
42
#include <unistd.h>
43
44
#include "vtc.h"
45
46
#include "vapi/vsc.h"
47
#include "vapi/vsl.h"
48
#include "vapi/vsm.h"
49
#include "vcli.h"
50
#include "vjsn.h"
51
#include "vre.h"
52
#include "vsub.h"
53
#include "vtcp.h"
54
#include "vtim.h"
55
56
struct varnish {
57
        unsigned                magic;
58
#define VARNISH_MAGIC           0x208cd8e3
59
        char                    *name;
60
        struct vtclog           *vl;
61
        VTAILQ_ENTRY(varnish)   list;
62
63
        struct vsb              *args;
64
        int                     fds[4];
65
        pid_t                   pid;
66
67
        double                  syntax;
68
69
        pthread_t               tp;
70
        pthread_t               tp_vsl;
71
72
        int                     expect_exit;
73
74
        int                     cli_fd;
75
        int                     vcl_nbr;
76
        char                    *workdir;
77
        char                    *jail;
78
        char                    *proto;
79
80
        struct vsm              *vsm_vsl;
81
        struct vsm              *vsm_vsc;
82
        struct vsc              *vsc;
83
        int                     has_a_arg;
84
85
        unsigned                vsl_tag_count[256];
86
87
        volatile int            vsl_rec;
88
        volatile int            vsl_idle;
89
};
90
91
#define NONSENSE        "%XJEIFLH|)Xspa8P"
92
93
static VTAILQ_HEAD(, varnish)   varnishes =
94
    VTAILQ_HEAD_INITIALIZER(varnishes);
95
96
/**********************************************************************
97
 * Ask a question over CLI
98
 */
99
100
static enum VCLI_status_e
101 31341
varnish_ask_cli(const struct varnish *v, const char *cmd, char **repl)
102
{
103
        int i;
104
        unsigned retval;
105
        char *r;
106
107 31341
        if (cmd != NULL) {
108 29214
                vtc_dump(v->vl, 4, "CLI TX", cmd, -1);
109 29214
                i = write(v->cli_fd, cmd, strlen(cmd));
110 29214
                if (i != strlen(cmd) && !vtc_stop)
111 0
                        vtc_fatal(v->vl, "CLI write failed (%s) = %u %s",
112 0
                            cmd, errno, strerror(errno));
113 29214
                i = write(v->cli_fd, "\n", 1);
114 29214
                if (i != 1 && !vtc_stop)
115 0
                        vtc_fatal(v->vl, "CLI write failed (%s) = %u %s",
116 0
                            cmd, errno, strerror(errno));
117
        }
118 31341
        i = VCLI_ReadResult(v->cli_fd, &retval, &r, vtc_maxdur);
119 31341
        if (i != 0 && !vtc_stop)
120 0
                vtc_fatal(v->vl, "CLI failed (%s) = %d %u %s",
121
                    cmd, i, retval, r);
122 31341
        vtc_log(v->vl, 3, "CLI RX  %u", retval);
123 31341
        vtc_dump(v->vl, 4, "CLI RX", r, -1);
124 31341
        if (repl != NULL)
125 19929
                *repl = r;
126
        else
127 11412
                free(r);
128 31341
        return ((enum VCLI_status_e)retval);
129
}
130
131
/**********************************************************************
132
 *
133
 */
134
135
static void
136 2244
wait_stopped(const struct varnish *v)
137
{
138 2244
        char *r = NULL;
139
        enum VCLI_status_e st;
140
141 2244
        vtc_log(v->vl, 3, "wait-stopped");
142
        while (1) {
143 2268
                st = varnish_ask_cli(v, "status", &r);
144 2256
                if (st != CLIS_OK)
145 0
                        vtc_fatal(v->vl,
146
                            "CLI status command failed: %u %s", st, r);
147 2256
                if (!strcmp(r, "Child in state stopped")) {
148 2244
                        free(r);
149 2244
                        break;
150
                }
151 12
                free(r);
152 12
                r = NULL;
153 12
                (void)usleep(200000);
154
        }
155 2244
}
156
/**********************************************************************
157
 *
158
 */
159
160
static void
161 2094
wait_running(const struct varnish *v)
162
{
163 2094
        char *r = NULL;
164
        enum VCLI_status_e st;
165
166
        while (1) {
167 2094
                vtc_log(v->vl, 3, "wait-running");
168 2094
                st = varnish_ask_cli(v, "status", &r);
169 2094
                if (st != CLIS_OK)
170 0
                        vtc_fatal(v->vl,
171
                            "CLI status command failed: %u %s", st, r);
172 2094
                if (!strcmp(r, "Child in state stopped"))
173 0
                        vtc_fatal(v->vl,
174
                            "Child stopped before running: %u %s", st, r);
175 2094
                if (!strcmp(r, "Child in state running")) {
176 2094
                        st = varnish_ask_cli(v, "debug.listen_address", &r);
177 2094
                        if (st != CLIS_OK)
178 0
                                vtc_fatal(v->vl,
179
                                          "CLI status command failed: %u %s",
180
                                          st, r);
181 2094
                        free(r);
182 2094
                        break;
183
                }
184 0
                free(r);
185 0
                r = NULL;
186 0
                (void)usleep(200000);
187
        }
188 2094
}
189
190
/**********************************************************************
191
 * Varnishlog gatherer thread
192
 */
193
194
static void
195 159
vsl_catchup(const struct varnish *v)
196
{
197
        int vsl_idle;
198
199 159
        vsl_idle = v->vsl_idle;
200 498
        while (!vtc_error && vsl_idle == v->vsl_idle)
201 180
                VTIM_sleep(0.1);
202 159
}
203
204
static void *
205 2127
varnishlog_thread(void *priv)
206
{
207
        struct varnish *v;
208
        struct VSL_data *vsl;
209
        struct vsm *vsm;
210
        struct VSL_cursor *c;
211
        enum VSL_tag_e tag;
212
        uint32_t vxid;
213
        unsigned len;
214
        const char *tagname, *data;
215
        int type, i, opt;
216 2127
        struct vsb *vsb = NULL;
217
218 2127
        CAST_OBJ_NOTNULL(v, priv, VARNISH_MAGIC);
219
220 2127
        vsl = VSL_New();
221 2127
        AN(vsl);
222 2127
        vsm = v->vsm_vsl;
223
224 2127
        c = NULL;
225 2127
        opt = 0;
226 148924
        while (v->fds[1] > 0 || c != NULL) {    //lint !e845 bug in flint
227 144670
                if (c == NULL) {
228 80038
                        if (vtc_error)
229 0
                                break;
230 80038
                        VTIM_sleep(0.1);
231 80038
                        (void)VSM_Status(vsm);
232 80038
                        c = VSL_CursorVSM(vsl, vsm, opt);
233 80038
                        if (c == NULL) {
234 71046
                                vtc_log(v->vl, 3, "vsl|%s", VSL_Error(vsl));
235 71046
                                VSL_ResetError(vsl);
236 71046
                                continue;
237
                        }
238
                }
239 73624
                AN(c);
240
241 73624
                opt = VSL_COPT_TAIL;
242
243
                while (1) {
244 1092216
                        i = VSL_Next(c);
245 582920
                        if (i != 1)
246 73624
                                break;
247
248 509296
                        v->vsl_rec = 1;
249
250 509296
                        tag = VSL_TAG(c->rec.ptr);
251 509296
                        vxid = VSL_ID(c->rec.ptr);
252 509296
                        if (tag == SLT__Batch)
253 0
                                continue;
254 509296
                        tagname = VSL_tags[tag];
255 509296
                        len = VSL_LEN(c->rec.ptr);
256 1018592
                        type = VSL_CLIENT(c->rec.ptr) ?
257 732440
                            'c' : VSL_BACKEND(c->rec.ptr) ?
258 223144
                            'b' : '-';
259 509296
                        data = VSL_CDATA(c->rec.ptr);
260 509296
                        v->vsl_tag_count[tag]++;
261 509296
                        if (VSL_tagflags[tag] & SLT_F_BINARY) {
262 111
                                if (vsb == NULL)
263 3
                                        vsb = VSB_new_auto();
264 111
                                VSB_clear(vsb);
265 111
                                VSB_quote(vsb, data, len, VSB_QUOTE_HEX);
266 111
                                AZ(VSB_finish(vsb));
267
                                /* +2 to skip "0x" */
268 111
                                vtc_log(v->vl, 4, "vsl| %10u %-15s %c [%s]",
269 111
                                    vxid, tagname, type, VSB_data(vsb) + 2);
270
                        } else {
271 509185
                                vtc_log(v->vl, 4, "vsl| %10u %-15s %c %.*s",
272
                                    vxid, tagname, type, (int)len, data);
273
                        }
274
                }
275 73624
                if (i == 0) {
276
                        /* Nothing to do but wait */
277 73624
                        v->vsl_idle++;
278 73624
                        if (!(VSM_Status(vsm) & VSM_WRK_RUNNING)) {
279
                                /* Abandoned - try reconnect */
280 8992
                                VSL_DeleteCursor(c);
281 8992
                                c = NULL;
282
                        } else {
283 64631
                                VTIM_sleep(0.1);
284
                        }
285 0
                } else if (i == -2) {
286
                        /* Abandoned - try reconnect */
287 0
                        VSL_DeleteCursor(c);
288 0
                        c = NULL;
289
                } else
290 0
                        break;
291
        }
292
293 2127
        if (c)
294 0
                VSL_DeleteCursor(c);
295 2127
        VSL_Delete(vsl);
296 2127
        if (vsb != NULL)
297 3
                VSB_destroy(&vsb);
298
299 2127
        return (NULL);
300
}
301
302
/**********************************************************************
303
 * Allocate and initialize a varnish
304
 */
305
306
static struct varnish *
307 2127
varnish_new(const char *name)
308
{
309
        struct varnish *v;
310
        struct vsb *vsb;
311
        char buf[1024];
312
313 2127
        ALLOC_OBJ(v, VARNISH_MAGIC);
314 2127
        AN(v);
315 2127
        REPLACE(v->name, name);
316
317 2127
        REPLACE(v->jail, "");
318
319 2127
        v->vl = vtc_logopen(name);
320 2127
        AN(v->vl);
321
322 2127
        vsb = macro_expandf(v->vl, "${tmpdir}/%s", name);
323 2127
        AN(vsb);
324 2127
        v->workdir = strdup(VSB_data(vsb));
325 2127
        AN(v->workdir);
326 2127
        VSB_destroy(&vsb);
327
328 2127
        bprintf(buf, "rm -rf %s ; mkdir -p %s", v->workdir, v->workdir);
329 2127
        AZ(system(buf));
330
331 2127
        v->args = VSB_new_auto();
332
333 2127
        v->cli_fd = -1;
334 2127
        VTAILQ_INSERT_TAIL(&varnishes, v, list);
335
336
337 2127
        return (v);
338
}
339
340
/**********************************************************************
341
 * Delete a varnish instance
342
 */
343
344
static void
345 2127
varnish_delete(struct varnish *v)
346
{
347
348 2127
        CHECK_OBJ_NOTNULL(v, VARNISH_MAGIC);
349 2127
        vtc_logclose(v->vl);
350 2127
        free(v->name);
351 2127
        free(v->workdir);
352 2127
        if (v->vsc != NULL)
353 2127
                VSC_Destroy(&v->vsc, v->vsm_vsc);
354 2127
        if (v->vsm_vsc != NULL)
355 2127
                VSM_Destroy(&v->vsm_vsc);
356 2127
        if (v->vsm_vsl != NULL)
357 2127
                VSM_Destroy(&v->vsm_vsl);
358
359
        /*
360
         * We do not delete the workdir, it may contain stuff people
361
         * want (coredumps, shmlog/stats etc), and trying to divine
362
         * "may want" is just too much trouble.  Leave it around and
363
         * nuke it at the start of the next test-run.
364
         */
365
366
        /* XXX: MEMLEAK (?) */
367 2127
        FREE_OBJ(v);
368 2127
}
369
370
/**********************************************************************
371
 * Varnish listener
372
 */
373
374
static void *
375 2127
varnish_thread(void *priv)
376
{
377
        struct varnish *v;
378
379 2127
        CAST_OBJ_NOTNULL(v, priv, VARNISH_MAGIC);
380 2127
        return (vtc_record(v->vl, v->fds[0], NULL));
381
}
382
383
/**********************************************************************
384
 * Launch a Varnish
385
 */
386
387
static void
388 2127
varnish_launch(struct varnish *v)
389
{
390
        struct vsb *vsb, *vsb1;
391
        int i, nfd;
392
        char abuf[128], pbuf[128];
393
        struct pollfd fd[2];
394
        enum VCLI_status_e u;
395
        const char *err;
396 2127
        char *r = NULL;
397
398
        /* Create listener socket */
399 2127
        v->cli_fd = VTCP_listen_on("127.0.0.1:0", NULL, 1, &err);
400 2127
        if (err != NULL)
401 0
                vtc_fatal(v->vl, "Create CLI listen socket failed: %s", err);
402 2127
        assert(v->cli_fd > 0);
403 2127
        VTCP_myname(v->cli_fd, abuf, sizeof abuf, pbuf, sizeof pbuf);
404
405 2127
        AZ(VSB_finish(v->args));
406 2127
        vtc_log(v->vl, 2, "Launch");
407 2127
        vsb = VSB_new_auto();
408 2127
        AN(vsb);
409 2127
        VSB_printf(vsb, "cd ${pwd} &&");
410 2127
        VSB_printf(vsb, " exec varnishd %s -d -n %s",
411
            v->jail, v->workdir);
412 2127
        VSB_cat(vsb, VSB_data(params_vsb));
413 2127
        if (vtc_witness)
414 0
                VSB_cat(vsb, " -p debug=+witness");
415 2127
        if (leave_temp) {
416 0
                VSB_cat(vsb, " -p debug=+vsm_keep");
417 0
                VSB_cat(vsb, " -p debug=+vmod_so_keep");
418
        }
419 2127
        VSB_printf(vsb, " -l 2m");
420 2127
        VSB_printf(vsb, " -p auto_restart=off");
421 2127
        VSB_printf(vsb, " -p syslog_cli_traffic=off");
422 2127
        VSB_printf(vsb, " -p sigsegv_handler=on");
423 2127
        VSB_printf(vsb, " -p thread_pool_min=10");
424 2127
        VSB_printf(vsb, " -p debug=+vtc_mode");
425 2127
        if (!v->has_a_arg) {
426 2064
                VSB_printf(vsb, " -a '%s'", "127.0.0.1:0");
427 2064
                if (v->proto != NULL)
428 24
                        VSB_printf(vsb, ",%s", v->proto);
429
        }
430 2127
        VSB_printf(vsb, " -M '%s %s'", abuf, pbuf);
431 2127
        VSB_printf(vsb, " -P %s/varnishd.pid", v->workdir);
432 2127
        if (vmod_path != NULL)
433 2124
                VSB_printf(vsb, " -p vmod_path=%s", vmod_path);
434 2127
        VSB_printf(vsb, " %s", VSB_data(v->args));
435 2127
        AZ(VSB_finish(vsb));
436 2127
        vtc_log(v->vl, 3, "CMD: %s", VSB_data(vsb));
437 2127
        vsb1 = macro_expand(v->vl, VSB_data(vsb));
438 2127
        AN(vsb1);
439 2127
        VSB_destroy(&vsb);
440 2127
        vsb = vsb1;
441 2127
        vtc_log(v->vl, 3, "CMD: %s", VSB_data(vsb));
442 2127
        AZ(pipe(&v->fds[0]));
443 2127
        AZ(pipe(&v->fds[2]));
444 2127
        v->pid = fork();
445 4254
        assert(v->pid >= 0);
446 4254
        if (v->pid == 0) {
447 2127
                AZ(dup2(v->fds[0], 0));
448 2127
                assert(dup2(v->fds[3], 1) == 1);
449 2127
                assert(dup2(1, 2) == 2);
450 2127
                closefd(&v->fds[0]);
451 2127
                closefd(&v->fds[1]);
452 2127
                closefd(&v->fds[2]);
453 2127
                closefd(&v->fds[3]);
454 2127
                VSUB_closefrom(STDERR_FILENO + 1);
455 2127
                AZ(execl("/bin/sh", "/bin/sh", "-c", VSB_data(vsb), (char*)0));
456 0
                exit(1);
457
        } else {
458 2127
                vtc_log(v->vl, 3, "PID: %ld", (long)v->pid);
459 2127
                macro_def(v->vl, v->name, "pid", "%ld", (long)v->pid);
460 2127
                macro_def(v->vl, v->name, "name", "%s", v->workdir);
461
        }
462 2127
        closefd(&v->fds[0]);
463 2127
        closefd(&v->fds[3]);
464 2127
        v->fds[0] = v->fds[2];
465 2127
        v->fds[2] = v->fds[3] = -1;
466 2127
        VSB_destroy(&vsb);
467 2127
        AZ(pthread_create(&v->tp, NULL, varnish_thread, v));
468
469
        /* Wait for the varnish to call home */
470 2127
        memset(fd, 0, sizeof fd);
471 2127
        fd[0].fd = v->cli_fd;
472 2127
        fd[0].events = POLLIN;
473 2127
        fd[1].fd = v->fds[1];
474 2127
        fd[1].events = POLLIN;
475 2127
        i = poll(fd, 2, vtc_maxdur * 1000 / 3);
476 4254
        vtc_log(v->vl, 4, "CLIPOLL %d 0x%x 0x%x",
477 4254
            i, fd[0].revents, fd[1].revents);
478 2127
        if (i == 0)
479 0
                vtc_fatal(v->vl, "FAIL timeout waiting for CLI connection");
480 2127
        if (fd[1].revents & POLLHUP)
481 0
                vtc_fatal(v->vl, "FAIL debug pipe closed");
482 2127
        if (!(fd[0].revents & POLLIN))
483 0
                vtc_fatal(v->vl, "FAIL CLI connection wait failure");
484 2127
        nfd = accept(v->cli_fd, NULL, NULL);
485 2127
        if (nfd < 0) {
486 0
                closefd(&v->cli_fd);
487 0
                vtc_fatal(v->vl, "FAIL no CLI connection accepted");
488
        }
489
490 2127
        closefd(&v->cli_fd);
491 2127
        v->cli_fd = nfd;
492
493 2127
        vtc_log(v->vl, 3, "CLI connection fd = %d", v->cli_fd);
494 2127
        assert(v->cli_fd >= 0);
495
496
        /* Receive the banner or auth response */
497 2127
        u = varnish_ask_cli(v, NULL, &r);
498 2127
        if (vtc_error)
499 0
                return;
500 2127
        if (u != CLIS_AUTH)
501 0
                vtc_fatal(v->vl, "CLI auth demand expected: %u %s", u, r);
502
503 2127
        bprintf(abuf, "%s/_.secret", v->workdir);
504 2127
        nfd = open(abuf, O_RDONLY);
505 2127
        assert(nfd >= 0);
506
507
        assert(sizeof abuf >= CLI_AUTH_RESPONSE_LEN + 7);
508 2127
        strcpy(abuf, "auth ");
509 2127
        VCLI_AuthResponse(nfd, r, abuf + 5);
510 2127
        closefd(&nfd);
511 2127
        free(r);
512 2127
        r = NULL;
513 2127
        strcat(abuf, "\n");
514
515 2127
        u = varnish_ask_cli(v, abuf, &r);
516 2127
        if (vtc_error)
517 0
                return;
518 2127
        if (u != CLIS_OK)
519 0
                vtc_fatal(v->vl, "CLI auth command failed: %u %s", u, r);
520 2127
        free(r);
521
522 2127
        v->vsm_vsc = VSM_New();
523 2127
        AN(v->vsm_vsc);
524 2127
        v->vsc = VSC_New();
525 2127
        AN(v->vsc);
526 2127
        assert(VSM_Arg(v->vsm_vsc, 'n', v->workdir) > 0);
527 2127
        AZ(VSM_Attach(v->vsm_vsc, -1));
528
529 2127
        v->vsm_vsl = VSM_New();
530 2127
        assert(VSM_Arg(v->vsm_vsl, 'n', v->workdir) > 0);
531 2127
        AZ(VSM_Attach(v->vsm_vsl, -1));
532
533 2127
        AZ(pthread_create(&v->tp_vsl, NULL, varnishlog_thread, v));
534
}
535
536
/**********************************************************************
537
 * Start a Varnish
538
 */
539
540
static void
541 2085
varnish_start(struct varnish *v)
542
{
543
        enum VCLI_status_e u;
544 2085
        char *resp = NULL, *h, *p;
545
546 2085
        if (v->cli_fd < 0)
547 24
                varnish_launch(v);
548 2085
        if (vtc_error)
549 0
                return;
550 2085
        vtc_log(v->vl, 2, "Start");
551 2085
        u = varnish_ask_cli(v, "start", &resp);
552 2085
        if (vtc_error)
553 0
                return;
554 2085
        if (u != CLIS_OK)
555 0
                vtc_fatal(v->vl, "CLI start command failed: %u %s", u, resp);
556 2085
        wait_running(v);
557 2085
        free(resp);
558 2085
        resp = NULL;
559 2085
        u = varnish_ask_cli(v, "debug.xid 999", &resp);
560 2085
        if (vtc_error)
561 0
                return;
562 2085
        if (u != CLIS_OK)
563 0
                vtc_fatal(v->vl, "CLI debug.xid command failed: %u %s",
564
                    u, resp);
565 2085
        free(resp);
566 2085
        resp = NULL;
567 2085
        u = varnish_ask_cli(v, "debug.listen_address", &resp);
568 2085
        if (vtc_error)
569 0
                return;
570 2085
        if (u != CLIS_OK)
571 0
                vtc_fatal(v->vl,
572
                    "CLI debug.listen_address command failed: %u %s", u, resp);
573 2085
        h = resp;
574 2085
        p = strchr(h, '\n');
575 2085
        if (p != NULL)
576 2085
                *p = '\0';
577 2085
        p = strchr(h, ' ');
578 2085
        AN(p);
579 2085
        *p++ = '\0';
580 2085
        vtc_log(v->vl, 2, "Listen on %s %s", h, p);
581 2085
        macro_def(v->vl, v->name, "addr", "%s", h);
582 2085
        macro_def(v->vl, v->name, "port", "%s", p);
583 2085
        macro_def(v->vl, v->name, "sock", "%s %s", h, p);
584 2085
        free(resp);
585
        /* Wait for vsl logging to get underway */
586 4170
        while (v->vsl_rec == 0)
587 0
                VTIM_sleep(.1);
588
}
589
590
/**********************************************************************
591
 * Stop a Varnish
592
 */
593
594
static void
595 2238
varnish_stop(struct varnish *v)
596
{
597 2238
        if (v->cli_fd < 0)
598 0
                varnish_launch(v);
599 2238
        if (vtc_error)
600 0
                return;
601 2238
        vtc_log(v->vl, 2, "Stop");
602 2238
        (void)varnish_ask_cli(v, "stop", NULL);
603 2238
        wait_stopped(v);
604
}
605
606
/**********************************************************************
607
 * Cleanup
608
 */
609
610
static void
611 2127
varnish_cleanup(struct varnish *v)
612
{
613
        void *p;
614
615
        /* Close the CLI connection */
616 2127
        closefd(&v->cli_fd);
617
618
        /* Close the STDIN connection. */
619 2127
        closefd(&v->fds[1]);
620
621
        /* Wait until STDOUT+STDERR closes */
622 2127
        AZ(pthread_join(v->tp, &p));
623 2127
        closefd(&v->fds[0]);
624
625
        /* Pick up the VSL thread */
626 2127
        AZ(pthread_join(v->tp_vsl, &p));
627
628 2127
        vtc_wait4(v->vl, v->pid, v->expect_exit, 0, 0);
629 2127
        v->pid = 0;
630 2127
}
631
632
/**********************************************************************
633
 * Wait for a Varnish
634
 */
635
636
static void
637 2118
varnish_wait(struct varnish *v)
638
{
639 2118
        if (v->cli_fd < 0)
640 0
                return;
641
642 2118
        vtc_log(v->vl, 2, "Wait");
643
644 2118
        if (!vtc_error) {
645
                /* Do a backend.list to log if child is still running */
646 2118
                (void)varnish_ask_cli(v, "backend.list", NULL);
647
        }
648
649
        /* Then stop it */
650 2118
        varnish_stop(v);
651
652 2118
        if (varnish_ask_cli(v, "panic.clear", NULL) != CLIS_CANT)
653 0
                vtc_fatal(v->vl, "Unexpected panic");
654
655 2118
        varnish_cleanup(v);
656
}
657
658
659
/**********************************************************************
660
 * Ask a CLI JSON question
661
 */
662
663
static void
664 24
varnish_cli_json(struct varnish *v, const char *cli)
665
{
666
        enum VCLI_status_e u;
667 24
        char *resp = NULL;
668
        const char *errptr;
669
        struct vjsn *vj;
670
671 24
        if (v->cli_fd < 0)
672 0
                varnish_launch(v);
673 24
        if (vtc_error)
674 0
                return;
675 24
        u = varnish_ask_cli(v, cli, &resp);
676 24
        vtc_log(v->vl, 2, "CLI %03u <%s>", u, cli);
677 24
        if (u != CLIS_OK)
678 0
                vtc_fatal(v->vl,
679
                    "FAIL CLI response %u expected %u", u, CLIS_OK);
680 24
        vj = vjsn_parse(resp, &errptr);
681 24
        if (vj == NULL)
682 0
                vtc_fatal(v->vl, "FAIL CLI, not good JSON: %s", errptr);
683 24
        vjsn_delete(&vj);
684 24
        free(resp);
685
}
686
687
/**********************************************************************
688
 * Ask a CLI question
689
 */
690
691
static void
692 2307
varnish_cli(struct varnish *v, const char *cli, unsigned exp, const char *re)
693
{
694
        enum VCLI_status_e u;
695 2307
        vre_t *vre = NULL;
696 2307
        char *resp = NULL;
697
        const char *errptr;
698
        int err;
699
700 2307
        if (re != NULL) {
701 63
                vre = VRE_compile(re, 0, &errptr, &err);
702 63
                if (vre == NULL)
703 0
                        vtc_fatal(v->vl, "Illegal regexp");
704
        }
705 2307
        if (v->cli_fd < 0)
706 81
                varnish_launch(v);
707 2307
        if (vtc_error) {
708 0
                if (vre != NULL)
709 0
                        VRE_free(&vre);
710 0
                return;
711
        }
712 2307
        u = varnish_ask_cli(v, cli, &resp);
713 2307
        vtc_log(v->vl, 2, "CLI %03u <%s>", u, cli);
714 2307
        if (exp != 0 && exp != (unsigned)u)
715 0
                vtc_fatal(v->vl, "FAIL CLI response %u expected %u", u, exp);
716 2307
        if (vre != NULL) {
717 63
                err = VRE_exec(vre, resp, strlen(resp), 0, 0, NULL, 0, NULL);
718 63
                if (err < 1)
719 0
                        vtc_fatal(v->vl, "Expect failed (%d)", err);
720 63
                VRE_free(&vre);
721
        }
722 2307
        free(resp);
723
}
724
725
/**********************************************************************
726
 * Load a VCL program
727
 */
728
729
static void
730 1086
varnish_vcl(struct varnish *v, const char *vcl, int fail, char **resp)
731
{
732
        struct vsb *vsb;
733
        enum VCLI_status_e u;
734
735 1086
        if (v->cli_fd < 0)
736 336
                varnish_launch(v);
737 1086
        if (vtc_error)
738 0
                return;
739 1086
        vsb = VSB_new_auto();
740 1086
        AN(vsb);
741
742 3258
        VSB_printf(vsb, "vcl.inline vcl%d << %s\nvcl %.1f;\n%s\n%s\n",
743 2172
            ++v->vcl_nbr, NONSENSE, v->syntax, vcl, NONSENSE);
744 1086
        AZ(VSB_finish(vsb));
745
746 1086
        u = varnish_ask_cli(v, VSB_data(vsb), resp);
747 1086
        if (u == CLIS_OK) {
748 441
                VSB_clear(vsb);
749 441
                VSB_printf(vsb, "vcl.use vcl%d", v->vcl_nbr);
750 441
                AZ(VSB_finish(vsb));
751 441
                u = varnish_ask_cli(v, VSB_data(vsb), NULL);
752
        }
753 1086
        if (u == CLIS_OK && fail) {
754 0
                VSB_destroy(&vsb);
755 0
                vtc_fatal(v->vl, "VCL compilation succeeded expected failure");
756 1086
        } else if (u != CLIS_OK && !fail) {
757 0
                VSB_destroy(&vsb);
758 0
                vtc_fatal(v->vl, "VCL compilation failed expected success");
759 1086
        } else if (fail)
760 645
                vtc_log(v->vl, 2, "VCL compilation failed (as expected)");
761 1086
        VSB_destroy(&vsb);
762
}
763
764
/**********************************************************************
765
 * Load a VCL program prefixed by backend decls for our servers
766
 */
767
768
static void
769 2028
varnish_vclbackend(struct varnish *v, const char *vcl)
770
{
771
        struct vsb *vsb, *vsb2;
772
        enum VCLI_status_e u;
773
774 2028
        if (v->cli_fd < 0)
775 1686
                varnish_launch(v);
776 2028
        if (vtc_error)
777 0
                return;
778 2028
        vsb = VSB_new_auto();
779 2028
        AN(vsb);
780
781 2028
        vsb2 = VSB_new_auto();
782 2028
        AN(vsb2);
783
784 2028
        VSB_printf(vsb2, "vcl %.1f;\n", v->syntax);
785
786 2028
        cmd_server_gen_vcl(vsb2);
787
788 2028
        AZ(VSB_finish(vsb2));
789
790 6084
        VSB_printf(vsb, "vcl.inline vcl%d << %s\n%s\n%s\n%s\n",
791 4056
            ++v->vcl_nbr, NONSENSE, VSB_data(vsb2), vcl, NONSENSE);
792 2028
        AZ(VSB_finish(vsb));
793
794 2028
        u = varnish_ask_cli(v, VSB_data(vsb), NULL);
795 2028
        if (u != CLIS_OK) {
796 0
                VSB_destroy(&vsb);
797 0
                VSB_destroy(&vsb2);
798 0
                vtc_fatal(v->vl, "FAIL VCL does not compile");
799
        }
800 2028
        VSB_clear(vsb);
801 2028
        VSB_printf(vsb, "vcl.use vcl%d", v->vcl_nbr);
802 2028
        AZ(VSB_finish(vsb));
803 2028
        u = varnish_ask_cli(v, VSB_data(vsb), NULL);
804 2028
        assert(u == CLIS_OK);
805 2028
        VSB_destroy(&vsb);
806 2028
        VSB_destroy(&vsb2);
807
}
808
809
/**********************************************************************
810
 */
811
812
struct dump_priv {
813
        const char *arg;
814
        const struct varnish *v;
815
};
816
817
static int
818 6025
do_stat_dump_cb(void *priv, const struct VSC_point * const pt)
819
{
820
        const struct varnish *v;
821
        struct dump_priv *dp;
822
        uint64_t u;
823
824 6025
        if (pt == NULL)
825 0
                return (0);
826 6025
        dp = priv;
827 6025
        v = dp->v;
828
829 6025
        if (strcmp(pt->ctype, "uint64_t"))
830 0
                return (0);
831 6025
        u = *pt->ptr;
832
833 6025
        if (strcmp(dp->arg, "*")) {
834 4291
                if (fnmatch(dp->arg, pt->name, 0))
835 4119
                        return (0);
836
        }
837
838 1906
        vtc_log(v->vl, 4, "VSC %s %ju",  pt->name, (uintmax_t)u);
839 1906
        return (0);
840
}
841
842
static void
843 21
varnish_vsc(const struct varnish *v, const char *arg)
844
{
845
        struct dump_priv dp;
846
847 21
        memset(&dp, 0, sizeof dp);
848 21
        dp.v = v;
849 21
        dp.arg = arg;
850 21
        (void)VSM_Status(v->vsm_vsc);
851 21
        (void)VSC_Iter(v->vsc, v->vsm_vsc, do_stat_dump_cb, &dp);
852 21
}
853
854
/**********************************************************************
855
 * Check statistics
856
 */
857
858
struct stat_priv {
859
        char target_pattern[256];
860
        uintmax_t val;
861
        const struct varnish *v;
862
};
863
864
static int
865 508062
do_expect_cb(void *priv, const struct VSC_point * const pt)
866
{
867 508062
        struct stat_priv *sp = priv;
868
869 508062
        if (pt == NULL)
870 0
                return(0);
871
872 508062
        if (fnmatch(sp->target_pattern, pt->name, 0))
873 506225
                return(0);
874
875 1837
        AZ(strcmp(pt->ctype, "uint64_t"));
876 1837
        AN(pt->ptr);
877 1837
        sp->val = *pt->ptr;
878 1837
        return (1);
879
}
880
881
/**********************************************************************
882
 */
883
884
static void
885 1815
varnish_expect(const struct varnish *v, char * const *av)
886
{
887
        uint64_t ref;
888
        int good;
889
        char *r;
890
        char *p;
891 1815
        int i, not = 0;
892
        struct stat_priv sp;
893
894 1815
        r = av[0];
895 1815
        if (r[0] == '!') {
896 18
                not = 1;
897 18
                r++;
898 18
                AZ(av[1]);
899
        } else {
900 1797
                AN(av[1]);
901 1797
                AN(av[2]);
902
        }
903 1815
        p = strrchr(r, '.');
904 1815
        if (p == NULL) {
905 1104
                bprintf(sp.target_pattern, "MAIN.%s", r);
906
        } else {
907 711
                bprintf(sp.target_pattern, "%s", r);
908
        }
909
910 1815
        sp.val = 0;
911 1815
        sp.v = v;
912 1815
        ref = 0;
913 1815
        good = 0;
914 2755
        for (i = 0; i < 50; i++, (void)usleep(100000)) {
915 2737
                (void)VSM_Status(v->vsm_vsc);
916 2737
                good = VSC_Iter(v->vsc, v->vsm_vsc, do_expect_cb, &sp);
917 2737
                if (!good) {
918 900
                        good = -2;
919 900
                        continue;
920
                }
921
922 1837
                if (not)
923 0
                        vtc_fatal(v->vl, "Found (not expected): %s", av[0]+1);
924
925 1837
                good = 0;
926 1837
                ref = strtoumax(av[2], &p, 0);
927 1837
                if (ref == UINTMAX_MAX || *p)
928 0
                        vtc_fatal(v->vl, "Syntax error in number (%s)", av[2]);
929 1837
                if      (!strcmp(av[1], "==")) { if (sp.val == ref) good = 1; }
930 225
                else if (!strcmp(av[1], "!=")) { if (sp.val != ref) good = 1; }
931 216
                else if (!strcmp(av[1], ">"))  { if (sp.val > ref)  good = 1; }
932 105
                else if (!strcmp(av[1], "<"))  { if (sp.val < ref)  good = 1; }
933 54
                else if (!strcmp(av[1], ">=")) { if (sp.val >= ref) good = 1; }
934 0
                else if (!strcmp(av[1], "<=")) { if (sp.val <= ref) good = 1; }
935
                else
936 0
                        vtc_fatal(v->vl, "comparison %s unknown", av[1]);
937 1837
                if (good)
938 1797
                        break;
939
        }
940 1815
        if (good == -1) {
941 0
                vtc_fatal(v->vl, "VSM error: %s", VSM_Error(v->vsm_vsc));
942
        }
943 1815
        if (good == -2) {
944 18
                if (not) {
945 18
                        vtc_log(v->vl, 2, "not found (as expected): %s",
946 18
                            av[0] + 1);
947 18
                        return;
948
                }
949 0
                vtc_fatal(v->vl, "stats field %s unknown", av[0]);
950
        }
951
952 1797
        if (good == 1) {
953 3594
                vtc_log(v->vl, 2, "as expected: %s (%ju) %s %s",
954 3594
                    av[0], sp.val, av[1], av[2]);
955
        } else {
956 0
                vtc_fatal(v->vl, "Not true: %s (%ju) %s %s (%ju)",
957 0
                    av[0], (uintmax_t)sp.val, av[1], av[2], (uintmax_t)ref);
958
        }
959
}
960
961
/* SECTION: varnish varnish
962
 *
963
 * Define and interact with varnish instances.
964
 *
965
 * To define a Varnish server, you'll use this syntax::
966
 *
967
 *      varnish vNAME [-arg STRING] [-vcl STRING] [-vcl+backend STRING]
968
 *              [-errvcl STRING STRING] [-jail STRING] [-proto PROXY]
969
 *
970
 * The first ``varnish vNAME`` invocation will start the varnishd master
971
 * process in the background, waiting for the ``-start`` switch to actually
972
 * start the child.
973
 *
974
 * Types used in the description below:
975
 *
976
 * PATTERN
977
 *         is a 'glob' style pattern (ie: fnmatch(3)) as used in shell filename
978
 *         expansion.
979
 *
980
 * Arguments:
981
 *
982
 * vNAME
983
 *         Identify the Varnish server with a string, it must starts with 'v'.
984
 *
985
 * \-arg STRING
986
 *         Pass an argument to varnishd, for example "-h simple_list".
987
 *
988
 * \-vcl STRING
989
 *         Specify the VCL to load on this Varnish instance. You'll probably
990
 *         want to use multi-lines strings for this ({...}).
991
 *
992
 * \-vcl+backend STRING
993
 *         Do the exact same thing as -vcl, but adds the definition block of
994
 *         known backends (ie. already defined).
995
 *
996
 * \-errvcl STRING1 STRING2
997
 *         Load STRING2 as VCL, expecting it to fail, and Varnish to send an
998
 *         error string matching STRING2
999
 *
1000
 * \-jail STRING
1001
 *         Look at ``man varnishd`` (-j) for more information.
1002
 *
1003
 * \-proto PROXY
1004
 *         Have Varnish use the proxy protocol. Note that PROXY here is the
1005
 *         actual string.
1006
 *
1007
 * You can decide to start the Varnish instance and/or wait for several events::
1008
 *
1009
 *         varnish vNAME [-start] [-wait] [-wait-running] [-wait-stopped]
1010
 *
1011
 * \-start
1012
 *         Start the child process.
1013
 *
1014
 * \-stop
1015
 *         Stop the child process.
1016
 *
1017
 * \-syntax
1018
 *         Set the VCL syntax level for this command (default: 4.1)
1019
 *
1020
 * \-wait
1021
 *         Wait for that instance to terminate.
1022
 *
1023
 * \-wait-running
1024
 *         Wait for the Varnish child process to be started.
1025
 *
1026
 * \-wait-stopped
1027
 *         Wait for the Varnish child process to stop.
1028
 *
1029
 * \-cleanup
1030
 *         Once Varnish is stopped, clean everything after it. This is only used
1031
 *         in very few tests and you should never need it.
1032
 *
1033
 * Once Varnish is started, you can talk to it (as you would through
1034
 * ``varnishadm``) with these additional switches::
1035
 *
1036
 *         varnish vNAME [-cli STRING] [-cliok STRING] [-clierr STRING]
1037
 *                       [-clijson STRING] [-expect STRING OP NUMBER]
1038
 *
1039
 * \-cli STRING|-cliok STRING|-clierr STATUS STRING|-cliexpect REGEXP STRING
1040
 *         All four of these will send STRING to the CLI, the only difference
1041
 *         is what they expect the result to be. -cli doesn't expect
1042
 *         anything, -cliok expects 200, -clierr expects STATUS, and
1043
 *         -cliexpect expects the REGEXP to match the returned response.
1044
 *
1045
 * \-clijson STRING
1046
 *         Send STRING to the CLI, expect success (CLIS_OK/200) and check
1047
 *         that the response is parsable JSON.
1048
 *
1049
 * \-expect PATTERN OP NUMBER
1050
 *         Look into the VSM and make sure the first VSC counter identified by
1051
 *         PATTERN has a correct value. OP can be ==, >, >=, <, <=. For
1052
 *         example::
1053
 *
1054
 *                 varnish v1 -expect SM?.s1.g_space > 1000000
1055
 * \-expectexit NUMBER
1056
 *         Expect varnishd to exit(3) with this value
1057
 *
1058
 * \-vsc PATTERN
1059
 *         Dump VSC counters matching PATTERN.
1060
 *
1061
 * \-vsl_catchup
1062
 *         Wait until the logging thread has idled to make sure that all
1063
 *         the generated log is flushed
1064
 */
1065
1066
void
1067 9933
cmd_varnish(CMD_ARGS)
1068
{
1069
        struct varnish *v, *v2;
1070
1071
        (void)priv;
1072
        (void)cmd;
1073
1074 9933
        if (av == NULL) {
1075
                /* Reset and free */
1076 4416
                VTAILQ_FOREACH_SAFE(v, &varnishes, list, v2) {
1077 2127
                        if (v->cli_fd >= 0)
1078 2103
                                varnish_wait(v);
1079 2127
                        VTAILQ_REMOVE(&varnishes, v, list);
1080 2127
                        varnish_delete(v);
1081
                }
1082 2289
                return;
1083
        }
1084
1085 7644
        AZ(strcmp(av[0], "varnish"));
1086 7644
        av++;
1087
1088 7644
        VTC_CHECK_NAME(vl, av[0], "Varnish", 'v');
1089 7803
        VTAILQ_FOREACH(v, &varnishes, list)
1090 5676
                if (!strcmp(v->name, av[0]))
1091 5517
                        break;
1092 7644
        if (v == NULL)
1093 2127
                v = varnish_new(av[0]);
1094 7644
        av++;
1095 7644
        v->syntax = 4.1;
1096
1097 18171
        for (; *av != NULL; av++) {
1098 10527
                if (vtc_error)
1099 0
                        break;
1100 10527
                if (!strcmp(*av, "-arg")) {
1101 648
                        AN(av[1]);
1102 648
                        AZ(v->pid);
1103 648
                        VSB_cat(v->args, " ");
1104 648
                        VSB_cat(v->args, av[1]);
1105 648
                        if (av[1][0] == '-' && av[1][1] == 'a')
1106 63
                                v->has_a_arg = 1;
1107 648
                        av++;
1108 648
                        continue;
1109
                }
1110 9879
                if (!strcmp(*av, "-cleanup")) {
1111 9
                        AZ(av[1]);
1112 9
                        varnish_cleanup(v);
1113 9
                        continue;
1114
                }
1115 9870
                if (!strcmp(*av, "-cli")) {
1116 141
                        AN(av[1]);
1117 141
                        varnish_cli(v, av[1], 0, NULL);
1118 141
                        av++;
1119 141
                        continue;
1120
                }
1121 9729
                if (!strcmp(*av, "-clierr")) {
1122 348
                        AN(av[1]);
1123 348
                        AN(av[2]);
1124 348
                        varnish_cli(v, av[2], atoi(av[1]), NULL);
1125 348
                        av += 2;
1126 348
                        continue;
1127
                }
1128 9381
                if (!strcmp(*av, "-cliexpect")) {
1129 63
                        AN(av[1]);
1130 63
                        AN(av[2]);
1131 63
                        varnish_cli(v, av[2], 0, av[1]);
1132 63
                        av += 2;
1133 63
                        continue;
1134
                }
1135 9318
                if (!strcmp(*av, "-clijson")) {
1136 24
                        AN(av[1]);
1137 24
                        varnish_cli_json(v, av[1]);
1138 24
                        av++;
1139 24
                        continue;
1140
                }
1141 9294
                if (!strcmp(*av, "-cliok")) {
1142 1755
                        AN(av[1]);
1143 1755
                        varnish_cli(v, av[1], (unsigned)CLIS_OK, NULL);
1144 1755
                        av++;
1145 1755
                        continue;
1146
                }
1147 7539
                if (!strcmp(*av, "-errvcl")) {
1148 645
                        char *r = NULL;
1149 645
                        AN(av[1]);
1150 645
                        AN(av[2]);
1151 645
                        varnish_vcl(v, av[2], 1, &r);
1152 645
                        if (strstr(r, av[1]) == NULL)
1153 0
                                vtc_fatal(v->vl,
1154
                                    "Did not find expected string: (\"%s\")",
1155 0
                                    av[1]);
1156
                        else
1157 645
                                vtc_log(v->vl, 3,
1158
                                    "Found expected string: (\"%s\")",
1159 645
                                    av[1]);
1160 645
                        free(r);
1161 645
                        av += 2;
1162 645
                        continue;
1163
                }
1164 6894
                if (!strcmp(*av, "-expect")) {
1165 1815
                        av++;
1166 1815
                        varnish_expect(v, av);
1167 1815
                        av += 2;
1168 1815
                        continue;
1169
                }
1170 5079
                if (!strcmp(*av, "-expectexit")) {
1171 15
                        v->expect_exit = strtoul(av[1], NULL, 0);
1172 15
                        av++;
1173 15
                        continue;
1174
                }
1175 5064
                if (!strcmp(*av, "-jail")) {
1176 12
                        AN(av[1]);
1177 12
                        AZ(v->pid);
1178 12
                        REPLACE(v->jail, av[1]);
1179 12
                        av++;
1180 12
                        continue;
1181
                }
1182 5052
                if (!strcmp(*av, "-proto")) {
1183 24
                        AN(av[1]);
1184 24
                        AZ(v->pid);
1185 24
                        REPLACE(v->proto, av[1]);
1186 24
                        av++;
1187 24
                        continue;
1188
                }
1189 5028
                if (!strcmp(*av, "-start")) {
1190 2085
                        varnish_start(v);
1191 2085
                        continue;
1192
                }
1193 2943
                if (!strcmp(*av, "-stop")) {
1194 120
                        varnish_stop(v);
1195 120
                        continue;
1196
                }
1197 2823
                if (!strcmp(*av, "-syntax")) {
1198 144
                        AN(av[1]);
1199 144
                        v->syntax = strtod(av[1], NULL);
1200 144
                        av++;
1201 144
                        continue;
1202
                }
1203 2679
                if (!strcmp(*av, "-vcl")) {
1204 441
                        AN(av[1]);
1205 441
                        varnish_vcl(v, av[1], 0, NULL);
1206 441
                        av++;
1207 441
                        continue;
1208
                }
1209 2238
                if (!strcmp(*av, "-vcl+backend")) {
1210 2028
                        AN(av[1]);
1211 2028
                        varnish_vclbackend(v, av[1]);
1212 2028
                        av++;
1213 2028
                        continue;
1214
                }
1215 210
                if (!strcmp(*av, "-vsc")) {
1216 21
                        AN(av[1]);
1217 21
                        varnish_vsc(v, av[1]);
1218 21
                        av++;
1219 21
                        continue;
1220
                }
1221 189
                if (!strcmp(*av, "-wait-stopped")) {
1222 6
                        wait_stopped(v);
1223 6
                        continue;
1224
                }
1225 183
                if (!strcmp(*av, "-wait-running")) {
1226 9
                        wait_running(v);
1227 9
                        continue;
1228
                }
1229 174
                if (!strcmp(*av, "-wait")) {
1230 15
                        varnish_wait(v);
1231 15
                        continue;
1232
                }
1233 159
                if (!strcmp(*av, "-vsl_catchup")) {
1234 159
                        vsl_catchup(v);
1235 159
                        continue;
1236
                }
1237 0
                vtc_fatal(v->vl, "Unknown varnish argument: %s", *av);
1238
        }
1239
}