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 42192
varnish_ask_cli(const struct varnish *v, const char *cmd, char **repl)
102
{
103
        int i;
104
        unsigned retval;
105
        char *r;
106
107 42192
        if (cmd != NULL) {
108 39344
                vtc_dump(v->vl, 4, "CLI TX", cmd, -1);
109 39344
                i = write(v->cli_fd, cmd, strlen(cmd));
110 39344
                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 39344
                i = write(v->cli_fd, "\n", 1);
114 39344
                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 42192
        i = VCLI_ReadResult(v->cli_fd, &retval, &r, vtc_maxdur);
119 42192
        if (i != 0 && !vtc_stop)
120 0
                vtc_fatal(v->vl, "CLI failed (%s) = %d %u %s",
121
                    cmd, i, retval, r);
122 42192
        vtc_log(v->vl, 3, "CLI RX  %u", retval);
123 42192
        vtc_dump(v->vl, 4, "CLI RX", r, -1);
124 42192
        if (repl != NULL)
125 26868
                *repl = r;
126
        else
127 15324
                free(r);
128 42192
        return ((enum VCLI_status_e)retval);
129
}
130
131
/**********************************************************************
132
 *
133
 */
134
135
static void
136 3004
wait_stopped(const struct varnish *v)
137
{
138 3004
        char *r = NULL;
139
        enum VCLI_status_e st;
140
141 3004
        vtc_log(v->vl, 3, "wait-stopped");
142
        while (1) {
143 3036
                st = varnish_ask_cli(v, "status", &r);
144 3020
                if (st != CLIS_OK)
145 0
                        vtc_fatal(v->vl,
146
                            "CLI status command failed: %u %s", st, r);
147 3020
                if (!strcmp(r, "Child in state stopped")) {
148 3004
                        free(r);
149 3004
                        break;
150
                }
151 16
                free(r);
152 16
                r = NULL;
153 16
                (void)usleep(200000);
154
        }
155 3004
}
156
/**********************************************************************
157
 *
158
 */
159
160
static void
161 2804
wait_running(const struct varnish *v)
162
{
163 2804
        char *r = NULL;
164
        enum VCLI_status_e st;
165
166
        while (1) {
167 2804
                vtc_log(v->vl, 3, "wait-running");
168 2804
                st = varnish_ask_cli(v, "status", &r);
169 2804
                if (st != CLIS_OK)
170 0
                        vtc_fatal(v->vl,
171
                            "CLI status command failed: %u %s", st, r);
172 2804
                if (!strcmp(r, "Child in state stopped"))
173 0
                        vtc_fatal(v->vl,
174
                            "Child stopped before running: %u %s", st, r);
175 2804
                if (!strcmp(r, "Child in state running")) {
176 2804
                        st = varnish_ask_cli(v, "debug.listen_address", &r);
177 2804
                        if (st != CLIS_OK)
178 0
                                vtc_fatal(v->vl,
179
                                          "CLI status command failed: %u %s",
180
                                          st, r);
181 2804
                        free(r);
182 2804
                        break;
183
                }
184 0
                free(r);
185 0
                r = NULL;
186 0
                (void)usleep(200000);
187
        }
188 2804
}
189
190
/**********************************************************************
191
 * Varnishlog gatherer thread
192
 */
193
194
static void
195 240
vsl_catchup(const struct varnish *v)
196
{
197
        int vsl_idle;
198
199 240
        vsl_idle = v->vsl_idle;
200 741
        while (!vtc_error && vsl_idle == v->vsl_idle)
201 261
                VTIM_sleep(0.1);
202 240
}
203
204
static void *
205 2848
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 2848
        struct vsb *vsb = NULL;
217
218 2848
        CAST_OBJ_NOTNULL(v, priv, VARNISH_MAGIC);
219
220 2848
        vsl = VSL_New();
221 2848
        AN(vsl);
222 2848
        vsm = v->vsm_vsl;
223
224 2848
        c = NULL;
225 2848
        opt = 0;
226 204889
        while (v->fds[1] > 0 || c != NULL) {    //lint !e845 bug in flint
227 199193
                if (c == NULL) {
228 109999
                        if (vtc_error)
229 0
                                break;
230 109999
                        VTIM_sleep(0.1);
231 109999
                        (void)VSM_Status(vsm);
232 109999
                        c = VSL_CursorVSM(vsl, vsm, opt);
233 109999
                        if (c == NULL) {
234 97744
                                vtc_log(v->vl, 3, "vsl|%s", VSL_Error(vsl));
235 97744
                                VSL_ResetError(vsl);
236 97744
                                continue;
237
                        }
238
                }
239 101449
                AN(c);
240
241 101449
                opt = VSL_COPT_TAIL;
242
243
                while (1) {
244 1472585
                        i = VSL_Next(c);
245 787017
                        if (i != 1)
246 101449
                                break;
247
248 685568
                        v->vsl_rec = 1;
249
250 685568
                        tag = VSL_TAG(c->rec.ptr);
251 685568
                        vxid = VSL_ID(c->rec.ptr);
252 685568
                        if (tag == SLT__Batch)
253 0
                                continue;
254 685568
                        tagname = VSL_tags[tag];
255 685568
                        len = VSL_LEN(c->rec.ptr);
256 1371136
                        type = VSL_CLIENT(c->rec.ptr) ?
257 985240
                            'c' : VSL_BACKEND(c->rec.ptr) ?
258 299672
                            'b' : '-';
259 685568
                        data = VSL_CDATA(c->rec.ptr);
260 685568
                        v->vsl_tag_count[tag]++;
261 685568
                        if (VSL_tagflags[tag] & SLT_F_BINARY) {
262 168
                                if (vsb == NULL)
263 8
                                        vsb = VSB_new_auto();
264 168
                                VSB_clear(vsb);
265 168
                                VSB_quote(vsb, data, len, VSB_QUOTE_HEX);
266 168
                                AZ(VSB_finish(vsb));
267
                                /* +2 to skip "0x" */
268 168
                                vtc_log(v->vl, 4, "vsl| %10u %-15s %c [%s]",
269 168
                                    vxid, tagname, type, VSB_data(vsb) + 2);
270
                        } else {
271 685400
                                vtc_log(v->vl, 4, "vsl| %10u %-15s %c %.*s",
272
                                    vxid, tagname, type, (int)len, data);
273
                        }
274
                }
275 101449
                if (i == 0) {
276
                        /* Nothing to do but wait */
277 101449
                        v->vsl_idle++;
278 101449
                        if (!(VSM_Status(vsm) & VSM_WRK_RUNNING)) {
279
                                /* Abandoned - try reconnect */
280 12255
                                VSL_DeleteCursor(c);
281 12255
                                c = NULL;
282
                        } else {
283 89191
                                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 2848
        if (c)
294 0
                VSL_DeleteCursor(c);
295 2848
        VSL_Delete(vsl);
296 2848
        if (vsb != NULL)
297 8
                VSB_destroy(&vsb);
298
299 2848
        return (NULL);
300
}
301
302
/**********************************************************************
303
 * Allocate and initialize a varnish
304
 */
305
306
static struct varnish *
307 2848
varnish_new(const char *name)
308
{
309
        struct varnish *v;
310
        struct vsb *vsb;
311
        char buf[1024];
312
313 2848
        ALLOC_OBJ(v, VARNISH_MAGIC);
314 2848
        AN(v);
315 2848
        REPLACE(v->name, name);
316
317 2848
        REPLACE(v->jail, "");
318
319 2848
        v->vl = vtc_logopen(name);
320 2848
        AN(v->vl);
321
322 2848
        vsb = macro_expandf(v->vl, "${tmpdir}/%s", name);
323 2848
        AN(vsb);
324 2848
        v->workdir = strdup(VSB_data(vsb));
325 2848
        AN(v->workdir);
326 2848
        VSB_destroy(&vsb);
327
328 2848
        bprintf(buf, "rm -rf %s ; mkdir -p %s", v->workdir, v->workdir);
329 2848
        AZ(system(buf));
330
331 2848
        v->args = VSB_new_auto();
332
333 2848
        v->cli_fd = -1;
334 2848
        VTAILQ_INSERT_TAIL(&varnishes, v, list);
335
336
337 2848
        return (v);
338
}
339
340
/**********************************************************************
341
 * Delete a varnish instance
342
 */
343
344
static void
345 2848
varnish_delete(struct varnish *v)
346
{
347
348 2848
        CHECK_OBJ_NOTNULL(v, VARNISH_MAGIC);
349 2848
        vtc_logclose(v->vl);
350 2848
        free(v->name);
351 2848
        free(v->workdir);
352 2848
        if (v->vsc != NULL)
353 2848
                VSC_Destroy(&v->vsc, v->vsm_vsc);
354 2848
        if (v->vsm_vsc != NULL)
355 2848
                VSM_Destroy(&v->vsm_vsc);
356 2848
        if (v->vsm_vsl != NULL)
357 2848
                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 2848
        FREE_OBJ(v);
368 2848
}
369
370
/**********************************************************************
371
 * Varnish listener
372
 */
373
374
static void *
375 2848
varnish_thread(void *priv)
376
{
377
        struct varnish *v;
378
379 2848
        CAST_OBJ_NOTNULL(v, priv, VARNISH_MAGIC);
380 2848
        return (vtc_record(v->vl, v->fds[0], NULL));
381
}
382
383
/**********************************************************************
384
 * Launch a Varnish
385
 */
386
387
static void
388 2848
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 2848
        char *r = NULL;
397
398
        /* Create listener socket */
399 2848
        v->cli_fd = VTCP_listen_on("127.0.0.1:0", NULL, 1, &err);
400 2848
        if (err != NULL)
401 0
                vtc_fatal(v->vl, "Create CLI listen socket failed: %s", err);
402 2848
        assert(v->cli_fd > 0);
403 2848
        VTCP_myname(v->cli_fd, abuf, sizeof abuf, pbuf, sizeof pbuf);
404
405 2848
        AZ(VSB_finish(v->args));
406 2848
        vtc_log(v->vl, 2, "Launch");
407 2848
        vsb = VSB_new_auto();
408 2848
        AN(vsb);
409 2848
        VSB_printf(vsb, "cd ${pwd} &&");
410 2848
        VSB_printf(vsb, " exec varnishd %s -d -n %s",
411
            v->jail, v->workdir);
412 2848
        VSB_cat(vsb, VSB_data(params_vsb));
413 2848
        if (vtc_witness)
414 0
                VSB_cat(vsb, " -p debug=+witness");
415 2848
        if (leave_temp) {
416 0
                VSB_cat(vsb, " -p debug=+vsm_keep");
417 0
                VSB_cat(vsb, " -p debug=+vmod_so_keep");
418
        }
419 2848
        VSB_printf(vsb, " -l 2m");
420 2848
        VSB_printf(vsb, " -p auto_restart=off");
421 2848
        VSB_printf(vsb, " -p syslog_cli_traffic=off");
422 2848
        VSB_printf(vsb, " -p sigsegv_handler=on");
423 2848
        VSB_printf(vsb, " -p thread_pool_min=10");
424 2848
        VSB_printf(vsb, " -p debug=+vtc_mode");
425 2848
        if (!v->has_a_arg) {
426 2764
                VSB_printf(vsb, " -a '%s'", "127.0.0.1:0");
427 2764
                if (v->proto != NULL)
428 32
                        VSB_printf(vsb, ",%s", v->proto);
429
        }
430 2848
        VSB_printf(vsb, " -M '%s %s'", abuf, pbuf);
431 2848
        VSB_printf(vsb, " -P %s/varnishd.pid", v->workdir);
432 2848
        if (vmod_path != NULL)
433 2844
                VSB_printf(vsb, " -p vmod_path=%s", vmod_path);
434 2848
        VSB_printf(vsb, " %s", VSB_data(v->args));
435 2848
        AZ(VSB_finish(vsb));
436 2848
        vtc_log(v->vl, 3, "CMD: %s", VSB_data(vsb));
437 2848
        vsb1 = macro_expand(v->vl, VSB_data(vsb));
438 2848
        AN(vsb1);
439 2848
        VSB_destroy(&vsb);
440 2848
        vsb = vsb1;
441 2848
        vtc_log(v->vl, 3, "CMD: %s", VSB_data(vsb));
442 2848
        AZ(pipe(&v->fds[0]));
443 2848
        AZ(pipe(&v->fds[2]));
444 2848
        v->pid = fork();
445 5696
        assert(v->pid >= 0);
446 5696
        if (v->pid == 0) {
447 2848
                AZ(dup2(v->fds[0], 0));
448 2848
                assert(dup2(v->fds[3], 1) == 1);
449 2848
                assert(dup2(1, 2) == 2);
450 2848
                closefd(&v->fds[0]);
451 2848
                closefd(&v->fds[1]);
452 2848
                closefd(&v->fds[2]);
453 2848
                closefd(&v->fds[3]);
454 2848
                VSUB_closefrom(STDERR_FILENO + 1);
455 2848
                AZ(execl("/bin/sh", "/bin/sh", "-c", VSB_data(vsb), (char*)0));
456 0
                exit(1);
457
        } else {
458 2848
                vtc_log(v->vl, 3, "PID: %ld", (long)v->pid);
459 2848
                macro_def(v->vl, v->name, "pid", "%ld", (long)v->pid);
460 2848
                macro_def(v->vl, v->name, "name", "%s", v->workdir);
461
        }
462 2848
        closefd(&v->fds[0]);
463 2848
        closefd(&v->fds[3]);
464 2848
        v->fds[0] = v->fds[2];
465 2848
        v->fds[2] = v->fds[3] = -1;
466 2848
        VSB_destroy(&vsb);
467 2848
        AZ(pthread_create(&v->tp, NULL, varnish_thread, v));
468
469
        /* Wait for the varnish to call home */
470 2848
        memset(fd, 0, sizeof fd);
471 2848
        fd[0].fd = v->cli_fd;
472 2848
        fd[0].events = POLLIN;
473 2848
        fd[1].fd = v->fds[1];
474 2848
        fd[1].events = POLLIN;
475 2848
        i = poll(fd, 2, vtc_maxdur * 1000 / 3);
476 5696
        vtc_log(v->vl, 4, "CLIPOLL %d 0x%x 0x%x",
477 5696
            i, fd[0].revents, fd[1].revents);
478 2848
        if (i == 0)
479 0
                vtc_fatal(v->vl, "FAIL timeout waiting for CLI connection");
480 2848
        if (fd[1].revents & POLLHUP)
481 0
                vtc_fatal(v->vl, "FAIL debug pipe closed");
482 2848
        if (!(fd[0].revents & POLLIN))
483 0
                vtc_fatal(v->vl, "FAIL CLI connection wait failure");
484 2848
        nfd = accept(v->cli_fd, NULL, NULL);
485 2848
        if (nfd < 0) {
486 0
                closefd(&v->cli_fd);
487 0
                vtc_fatal(v->vl, "FAIL no CLI connection accepted");
488
        }
489
490 2848
        closefd(&v->cli_fd);
491 2848
        v->cli_fd = nfd;
492
493 2848
        vtc_log(v->vl, 3, "CLI connection fd = %d", v->cli_fd);
494 2848
        assert(v->cli_fd >= 0);
495
496
        /* Receive the banner or auth response */
497 2848
        u = varnish_ask_cli(v, NULL, &r);
498 2848
        if (vtc_error)
499 0
                return;
500 2848
        if (u != CLIS_AUTH)
501 0
                vtc_fatal(v->vl, "CLI auth demand expected: %u %s", u, r);
502
503 2848
        bprintf(abuf, "%s/_.secret", v->workdir);
504 2848
        nfd = open(abuf, O_RDONLY);
505 2848
        assert(nfd >= 0);
506
507
        assert(sizeof abuf >= CLI_AUTH_RESPONSE_LEN + 7);
508 2848
        strcpy(abuf, "auth ");
509 2848
        VCLI_AuthResponse(nfd, r, abuf + 5);
510 2848
        closefd(&nfd);
511 2848
        free(r);
512 2848
        r = NULL;
513 2848
        strcat(abuf, "\n");
514
515 2848
        u = varnish_ask_cli(v, abuf, &r);
516 2848
        if (vtc_error)
517 0
                return;
518 2848
        if (u != CLIS_OK)
519 0
                vtc_fatal(v->vl, "CLI auth command failed: %u %s", u, r);
520 2848
        free(r);
521
522 2848
        v->vsm_vsc = VSM_New();
523 2848
        AN(v->vsm_vsc);
524 2848
        v->vsc = VSC_New();
525 2848
        AN(v->vsc);
526 2848
        assert(VSM_Arg(v->vsm_vsc, 'n', v->workdir) > 0);
527 2848
        AZ(VSM_Attach(v->vsm_vsc, -1));
528
529 2848
        v->vsm_vsl = VSM_New();
530 2848
        assert(VSM_Arg(v->vsm_vsl, 'n', v->workdir) > 0);
531 2848
        AZ(VSM_Attach(v->vsm_vsl, -1));
532
533 2848
        AZ(pthread_create(&v->tp_vsl, NULL, varnishlog_thread, v));
534
}
535
536
/**********************************************************************
537
 * Start a Varnish
538
 */
539
540
static void
541 2792
varnish_start(struct varnish *v)
542
{
543
        enum VCLI_status_e u;
544 2792
        char *resp = NULL, *h, *p;
545
546 2792
        if (v->cli_fd < 0)
547 32
                varnish_launch(v);
548 2792
        if (vtc_error)
549 0
                return;
550 2792
        vtc_log(v->vl, 2, "Start");
551 2792
        u = varnish_ask_cli(v, "start", &resp);
552 2792
        if (vtc_error)
553 0
                return;
554 2792
        if (u != CLIS_OK)
555 0
                vtc_fatal(v->vl, "CLI start command failed: %u %s", u, resp);
556 2792
        wait_running(v);
557 2792
        free(resp);
558 2792
        resp = NULL;
559 2792
        u = varnish_ask_cli(v, "debug.xid 999", &resp);
560 2792
        if (vtc_error)
561 0
                return;
562 2792
        if (u != CLIS_OK)
563 0
                vtc_fatal(v->vl, "CLI debug.xid command failed: %u %s",
564
                    u, resp);
565 2792
        free(resp);
566 2792
        resp = NULL;
567 2792
        u = varnish_ask_cli(v, "debug.listen_address", &resp);
568 2792
        if (vtc_error)
569 0
                return;
570 2792
        if (u != CLIS_OK)
571 0
                vtc_fatal(v->vl,
572
                    "CLI debug.listen_address command failed: %u %s", u, resp);
573 2792
        h = resp;
574 2792
        p = strchr(h, '\n');
575 2792
        if (p != NULL)
576 2792
                *p = '\0';
577 2792
        p = strchr(h, ' ');
578 2792
        AN(p);
579 2792
        *p++ = '\0';
580 2792
        vtc_log(v->vl, 2, "Listen on %s %s", h, p);
581 2792
        macro_def(v->vl, v->name, "addr", "%s", h);
582 2792
        macro_def(v->vl, v->name, "port", "%s", p);
583 2792
        macro_def(v->vl, v->name, "sock", "%s %s", h, p);
584 2792
        free(resp);
585
        /* Wait for vsl logging to get underway */
586 5584
        while (v->vsl_rec == 0)
587 0
                VTIM_sleep(.1);
588
}
589
590
/**********************************************************************
591
 * Stop a Varnish
592
 */
593
594
static void
595 2996
varnish_stop(struct varnish *v)
596
{
597 2996
        if (v->cli_fd < 0)
598 0
                varnish_launch(v);
599 2996
        if (vtc_error)
600 0
                return;
601 2996
        vtc_log(v->vl, 2, "Stop");
602 2996
        (void)varnish_ask_cli(v, "stop", NULL);
603 2996
        wait_stopped(v);
604
}
605
606
/**********************************************************************
607
 * Cleanup
608
 */
609
610
static void
611 2848
varnish_cleanup(struct varnish *v)
612
{
613
        void *p;
614
615
        /* Close the CLI connection */
616 2848
        closefd(&v->cli_fd);
617
618
        /* Close the STDIN connection. */
619 2848
        closefd(&v->fds[1]);
620
621
        /* Wait until STDOUT+STDERR closes */
622 2848
        AZ(pthread_join(v->tp, &p));
623 2848
        closefd(&v->fds[0]);
624
625
        /* Pick up the VSL thread */
626 2848
        AZ(pthread_join(v->tp_vsl, &p));
627
628 2848
        vtc_wait4(v->vl, v->pid, v->expect_exit, 0, 0);
629 2848
        v->pid = 0;
630 2848
}
631
632
/**********************************************************************
633
 * Wait for a Varnish
634
 */
635
636
static void
637 2836
varnish_wait(struct varnish *v)
638
{
639 2836
        if (v->cli_fd < 0)
640 0
                return;
641
642 2836
        vtc_log(v->vl, 2, "Wait");
643
644 2836
        if (!vtc_error) {
645
                /* Do a backend.list to log if child is still running */
646 2836
                (void)varnish_ask_cli(v, "backend.list", NULL);
647
        }
648
649
        /* Then stop it */
650 2836
        varnish_stop(v);
651
652 2836
        if (varnish_ask_cli(v, "panic.clear", NULL) != CLIS_CANT)
653 0
                vtc_fatal(v->vl, "Unexpected panic");
654
655 2836
        varnish_cleanup(v);
656
}
657
658
659
/**********************************************************************
660
 * Ask a CLI JSON question
661
 */
662
663
static void
664 136
varnish_cli_json(struct varnish *v, const char *cli)
665
{
666
        enum VCLI_status_e u;
667 136
        char *resp = NULL;
668
        const char *errptr;
669
        struct vjsn *vj;
670
671 136
        if (v->cli_fd < 0)
672 0
                varnish_launch(v);
673 136
        if (vtc_error)
674 0
                return;
675 136
        u = varnish_ask_cli(v, cli, &resp);
676 136
        vtc_log(v->vl, 2, "CLI %03u <%s>", u, cli);
677 136
        if (u != CLIS_OK)
678 0
                vtc_fatal(v->vl,
679
                    "FAIL CLI response %u expected %u", u, CLIS_OK);
680 136
        vj = vjsn_parse(resp, &errptr);
681 136
        if (vj == NULL)
682 0
                vtc_fatal(v->vl, "FAIL CLI, not good JSON: %s", errptr);
683 136
        vjsn_delete(&vj);
684 136
        free(resp);
685
}
686
687
/**********************************************************************
688
 * Ask a CLI question
689
 */
690
691
static void
692 3164
varnish_cli(struct varnish *v, const char *cli, unsigned exp, const char *re)
693
{
694
        enum VCLI_status_e u;
695 3164
        vre_t *vre = NULL;
696 3164
        char *resp = NULL;
697
        const char *errptr;
698
        int err;
699
700 3164
        if (re != NULL) {
701 104
                vre = VRE_compile(re, 0, &errptr, &err);
702 104
                if (vre == NULL)
703 0
                        vtc_fatal(v->vl, "Illegal regexp");
704
        }
705 3164
        if (v->cli_fd < 0)
706 112
                varnish_launch(v);
707 3164
        if (vtc_error) {
708 0
                if (vre != NULL)
709 0
                        VRE_free(&vre);
710 0
                return;
711
        }
712 3164
        u = varnish_ask_cli(v, cli, &resp);
713 3164
        vtc_log(v->vl, 2, "CLI %03u <%s>", u, cli);
714 3164
        if (exp != 0 && exp != (unsigned)u)
715 0
                vtc_fatal(v->vl, "FAIL CLI response %u expected %u", u, exp);
716 3164
        if (vre != NULL) {
717 104
                err = VRE_exec(vre, resp, strlen(resp), 0, 0, NULL, 0, NULL);
718 104
                if (err < 1)
719 0
                        vtc_fatal(v->vl, "Expect failed (%d)", err);
720 104
                VRE_free(&vre);
721
        }
722 3164
        free(resp);
723
}
724
725
/**********************************************************************
726
 * Load a VCL program
727
 */
728
729
static void
730 1464
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 1464
        if (v->cli_fd < 0)
736 452
                varnish_launch(v);
737 1464
        if (vtc_error)
738 0
                return;
739 1464
        vsb = VSB_new_auto();
740 1464
        AN(vsb);
741
742 4392
        VSB_printf(vsb, "vcl.inline vcl%d << %s\nvcl %.1f;\n%s\n%s\n",
743 2928
            ++v->vcl_nbr, NONSENSE, v->syntax, vcl, NONSENSE);
744 1464
        AZ(VSB_finish(vsb));
745
746 1464
        u = varnish_ask_cli(v, VSB_data(vsb), resp);
747 1464
        if (u == CLIS_OK) {
748 596
                VSB_clear(vsb);
749 596
                VSB_printf(vsb, "vcl.use vcl%d", v->vcl_nbr);
750 596
                AZ(VSB_finish(vsb));
751 596
                u = varnish_ask_cli(v, VSB_data(vsb), NULL);
752
        }
753 1464
        if (u == CLIS_OK && fail) {
754 0
                VSB_destroy(&vsb);
755 0
                vtc_fatal(v->vl, "VCL compilation succeeded expected failure");
756 1464
        } else if (u != CLIS_OK && !fail) {
757 0
                VSB_destroy(&vsb);
758 0
                vtc_fatal(v->vl, "VCL compilation failed expected success");
759 1464
        } else if (fail)
760 868
                vtc_log(v->vl, 2, "VCL compilation failed (as expected)");
761 1464
        VSB_destroy(&vsb);
762
}
763
764
/**********************************************************************
765
 * Load a VCL program prefixed by backend decls for our servers
766
 */
767
768
static void
769 2732
varnish_vclbackend(struct varnish *v, const char *vcl)
770
{
771
        struct vsb *vsb, *vsb2;
772
        enum VCLI_status_e u;
773
774 2732
        if (v->cli_fd < 0)
775 2252
                varnish_launch(v);
776 2732
        if (vtc_error)
777 0
                return;
778 2732
        vsb = VSB_new_auto();
779 2732
        AN(vsb);
780
781 2732
        vsb2 = VSB_new_auto();
782 2732
        AN(vsb2);
783
784 2732
        VSB_printf(vsb2, "vcl %.1f;\n", v->syntax);
785
786 2732
        cmd_server_gen_vcl(vsb2);
787
788 2732
        AZ(VSB_finish(vsb2));
789
790 8196
        VSB_printf(vsb, "vcl.inline vcl%d << %s\n%s\n%s\n%s\n",
791 5464
            ++v->vcl_nbr, NONSENSE, VSB_data(vsb2), vcl, NONSENSE);
792 2732
        AZ(VSB_finish(vsb));
793
794 2732
        u = varnish_ask_cli(v, VSB_data(vsb), NULL);
795 2732
        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 2732
        VSB_clear(vsb);
801 2732
        VSB_printf(vsb, "vcl.use vcl%d", v->vcl_nbr);
802 2732
        AZ(VSB_finish(vsb));
803 2732
        u = varnish_ask_cli(v, VSB_data(vsb), NULL);
804 2732
        assert(u == CLIS_OK);
805 2732
        VSB_destroy(&vsb);
806 2732
        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 8188
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 8188
        if (pt == NULL)
825 0
                return (0);
826 8188
        dp = priv;
827 8188
        v = dp->v;
828
829 8188
        if (strcmp(pt->ctype, "uint64_t"))
830 0
                return (0);
831 8188
        u = *pt->ptr;
832
833 8188
        if (strcmp(dp->arg, "*")) {
834 5836
                if (fnmatch(dp->arg, pt->name, 0))
835 5598
                        return (0);
836
        }
837
838 2590
        vtc_log(v->vl, 4, "VSC %s %ju",  pt->name, (uintmax_t)u);
839 2590
        return (0);
840
}
841
842
static void
843 28
varnish_vsc(const struct varnish *v, const char *arg)
844
{
845
        struct dump_priv dp;
846
847 28
        memset(&dp, 0, sizeof dp);
848 28
        dp.v = v;
849 28
        dp.arg = arg;
850 28
        (void)VSM_Status(v->vsm_vsc);
851 28
        (void)VSC_Iter(v->vsc, v->vsm_vsc, do_stat_dump_cb, &dp);
852 28
}
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 694571
do_expect_cb(void *priv, const struct VSC_point * const pt)
866
{
867 694571
        struct stat_priv *sp = priv;
868
869 694571
        if (pt == NULL)
870 0
                return(0);
871
872 694571
        if (fnmatch(sp->target_pattern, pt->name, 0))
873 692092
                return(0);
874
875 2479
        AZ(strcmp(pt->ctype, "uint64_t"));
876 2479
        AN(pt->ptr);
877 2479
        sp->val = *pt->ptr;
878 2479
        return (1);
879
}
880
881
/**********************************************************************
882
 */
883
884
static void
885 2448
varnish_expect(const struct varnish *v, char * const *av)
886
{
887
        uint64_t ref;
888
        int good;
889
        char *r;
890
        char *p;
891 2448
        int i, not = 0;
892
        struct stat_priv sp;
893
894 2448
        r = av[0];
895 2448
        if (r[0] == '!') {
896 24
                not = 1;
897 24
                r++;
898 24
                AZ(av[1]);
899
        } else {
900 2424
                AN(av[1]);
901 2424
                AN(av[2]);
902
        }
903 2448
        p = strrchr(r, '.');
904 2448
        if (p == NULL) {
905 1496
                bprintf(sp.target_pattern, "MAIN.%s", r);
906
        } else {
907 952
                bprintf(sp.target_pattern, "%s", r);
908
        }
909
910 2448
        sp.val = 0;
911 2448
        sp.v = v;
912 2448
        ref = 0;
913 2448
        good = 0;
914 3703
        for (i = 0; i < 50; i++, (void)usleep(100000)) {
915 3679
                (void)VSM_Status(v->vsm_vsc);
916 3679
                good = VSC_Iter(v->vsc, v->vsm_vsc, do_expect_cb, &sp);
917 3679
                if (!good) {
918 1200
                        good = -2;
919 1200
                        continue;
920
                }
921
922 2479
                if (not)
923 0
                        vtc_fatal(v->vl, "Found (not expected): %s", av[0]+1);
924
925 2479
                good = 0;
926 2479
                ref = strtoumax(av[2], &p, 0);
927 2479
                if (ref == UINTMAX_MAX || *p)
928 0
                        vtc_fatal(v->vl, "Syntax error in number (%s)", av[2]);
929 2479
                if      (!strcmp(av[1], "==")) { if (sp.val == ref) good = 1; }
930 304
                else if (!strcmp(av[1], "!=")) { if (sp.val != ref) good = 1; }
931 296
                else if (!strcmp(av[1], ">"))  { if (sp.val > ref)  good = 1; }
932 144
                else if (!strcmp(av[1], "<"))  { if (sp.val < ref)  good = 1; }
933 76
                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 2479
                if (good)
938 2424
                        break;
939
        }
940 2448
        if (good == -1) {
941 0
                vtc_fatal(v->vl, "VSM error: %s", VSM_Error(v->vsm_vsc));
942
        }
943 2448
        if (good == -2) {
944 24
                if (not) {
945 24
                        vtc_log(v->vl, 2, "not found (as expected): %s",
946 24
                            av[0] + 1);
947 24
                        return;
948
                }
949 0
                vtc_fatal(v->vl, "stats field %s unknown", av[0]);
950
        }
951
952 2424
        if (good == 1) {
953 4848
                vtc_log(v->vl, 2, "as expected: %s (%ju) %s %s",
954 4848
                    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 13544
cmd_varnish(CMD_ARGS)
1068
{
1069
        struct varnish *v, *v2;
1070
1071
        (void)priv;
1072
        (void)cmd;
1073
1074 13544
        if (av == NULL) {
1075
                /* Reset and free */
1076 5900
                VTAILQ_FOREACH_SAFE(v, &varnishes, list, v2) {
1077 2848
                        if (v->cli_fd >= 0)
1078 2816
                                varnish_wait(v);
1079 2848
                        VTAILQ_REMOVE(&varnishes, v, list);
1080 2848
                        varnish_delete(v);
1081
                }
1082 3052
                return;
1083
        }
1084
1085 10492
        AZ(strcmp(av[0], "varnish"));
1086 10492
        av++;
1087
1088 10492
        VTC_CHECK_NAME(vl, av[0], "Varnish", 'v');
1089 10704
        VTAILQ_FOREACH(v, &varnishes, list)
1090 7856
                if (!strcmp(v->name, av[0]))
1091 7644
                        break;
1092 10492
        if (v == NULL)
1093 2848
                v = varnish_new(av[0]);
1094 10492
        av++;
1095 10492
        v->syntax = 4.1;
1096
1097 24840
        for (; *av != NULL; av++) {
1098 14348
                if (vtc_error)
1099 0
                        break;
1100 14348
                if (!strcmp(*av, "-arg")) {
1101 868
                        AN(av[1]);
1102 868
                        AZ(v->pid);
1103 868
                        VSB_cat(v->args, " ");
1104 868
                        VSB_cat(v->args, av[1]);
1105 868
                        if (av[1][0] == '-' && av[1][1] == 'a')
1106 84
                                v->has_a_arg = 1;
1107 868
                        av++;
1108 868
                        continue;
1109
                }
1110 13480
                if (!strcmp(*av, "-cleanup")) {
1111 12
                        AZ(av[1]);
1112 12
                        varnish_cleanup(v);
1113 12
                        continue;
1114
                }
1115 13468
                if (!strcmp(*av, "-cli")) {
1116 188
                        AN(av[1]);
1117 188
                        varnish_cli(v, av[1], 0, NULL);
1118 188
                        av++;
1119 188
                        continue;
1120
                }
1121 13280
                if (!strcmp(*av, "-clierr")) {
1122 472
                        AN(av[1]);
1123 472
                        AN(av[2]);
1124 472
                        varnish_cli(v, av[2], atoi(av[1]), NULL);
1125 472
                        av += 2;
1126 472
                        continue;
1127
                }
1128 12808
                if (!strcmp(*av, "-cliexpect")) {
1129 104
                        AN(av[1]);
1130 104
                        AN(av[2]);
1131 104
                        varnish_cli(v, av[2], 0, av[1]);
1132 104
                        av += 2;
1133 104
                        continue;
1134
                }
1135 12704
                if (!strcmp(*av, "-clijson")) {
1136 136
                        AN(av[1]);
1137 136
                        varnish_cli_json(v, av[1]);
1138 136
                        av++;
1139 136
                        continue;
1140
                }
1141 12568
                if (!strcmp(*av, "-cliok")) {
1142 2400
                        AN(av[1]);
1143 2400
                        varnish_cli(v, av[1], (unsigned)CLIS_OK, NULL);
1144 2400
                        av++;
1145 2400
                        continue;
1146
                }
1147 10168
                if (!strcmp(*av, "-errvcl")) {
1148 868
                        char *r = NULL;
1149 868
                        AN(av[1]);
1150 868
                        AN(av[2]);
1151 868
                        varnish_vcl(v, av[2], 1, &r);
1152 868
                        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 868
                                vtc_log(v->vl, 3,
1158
                                    "Found expected string: (\"%s\")",
1159 868
                                    av[1]);
1160 868
                        free(r);
1161 868
                        av += 2;
1162 868
                        continue;
1163
                }
1164 9300
                if (!strcmp(*av, "-expect")) {
1165 2448
                        av++;
1166 2448
                        varnish_expect(v, av);
1167 2448
                        av += 2;
1168 2448
                        continue;
1169
                }
1170 6852
                if (!strcmp(*av, "-expectexit")) {
1171 24
                        v->expect_exit = strtoul(av[1], NULL, 0);
1172 24
                        av++;
1173 24
                        continue;
1174
                }
1175 6828
                if (!strcmp(*av, "-jail")) {
1176 16
                        AN(av[1]);
1177 16
                        AZ(v->pid);
1178 16
                        REPLACE(v->jail, av[1]);
1179 16
                        av++;
1180 16
                        continue;
1181
                }
1182 6812
                if (!strcmp(*av, "-proto")) {
1183 32
                        AN(av[1]);
1184 32
                        AZ(v->pid);
1185 32
                        REPLACE(v->proto, av[1]);
1186 32
                        av++;
1187 32
                        continue;
1188
                }
1189 6780
                if (!strcmp(*av, "-start")) {
1190 2792
                        varnish_start(v);
1191 2792
                        continue;
1192
                }
1193 3988
                if (!strcmp(*av, "-stop")) {
1194 160
                        varnish_stop(v);
1195 160
                        continue;
1196
                }
1197 3828
                if (!strcmp(*av, "-syntax")) {
1198 192
                        AN(av[1]);
1199 192
                        v->syntax = strtod(av[1], NULL);
1200 192
                        av++;
1201 192
                        continue;
1202
                }
1203 3636
                if (!strcmp(*av, "-vcl")) {
1204 596
                        AN(av[1]);
1205 596
                        varnish_vcl(v, av[1], 0, NULL);
1206 596
                        av++;
1207 596
                        continue;
1208
                }
1209 3040
                if (!strcmp(*av, "-vcl+backend")) {
1210 2732
                        AN(av[1]);
1211 2732
                        varnish_vclbackend(v, av[1]);
1212 2732
                        av++;
1213 2732
                        continue;
1214
                }
1215 308
                if (!strcmp(*av, "-vsc")) {
1216 28
                        AN(av[1]);
1217 28
                        varnish_vsc(v, av[1]);
1218 28
                        av++;
1219 28
                        continue;
1220
                }
1221 280
                if (!strcmp(*av, "-wait-stopped")) {
1222 8
                        wait_stopped(v);
1223 8
                        continue;
1224
                }
1225 272
                if (!strcmp(*av, "-wait-running")) {
1226 12
                        wait_running(v);
1227 12
                        continue;
1228
                }
1229 260
                if (!strcmp(*av, "-wait")) {
1230 20
                        varnish_wait(v);
1231 20
                        continue;
1232
                }
1233 240
                if (!strcmp(*av, "-vsl_catchup")) {
1234 240
                        vsl_catchup(v);
1235 240
                        continue;
1236
                }
1237 0
                vtc_fatal(v->vl, "Unknown varnish argument: %s", *av);
1238
        }
1239
}