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