varnish-cache/bin/varnishncsa/varnishncsa.c
1
/*-
2
 * Copyright (c) 2006 Verdens Gang AS
3
 * Copyright (c) 2006-2016 Varnish Software AS
4
 * All rights reserved.
5
 *
6
 * Author: Anders Berg <andersb@vgnett.no>
7
 * Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
8
 * Author: Tollef Fog Heen <tfheen@varnish-software.com>
9
 * Author: Martin Blix Grydeland <mbgrydeland@varnish-software.com>
10
 *
11
 * Redistribution and use in source and binary forms, with or without
12
 * modification, are permitted provided that the following conditions
13
 * are met:
14
 * 1. Redistributions of source code must retain the above copyright
15
 *    notice, this list of conditions and the following disclaimer.
16
 * 2. Redistributions in binary form must reproduce the above copyright
17
 *    notice, this list of conditions and the following disclaimer in the
18
 *    documentation and/or other materials provided with the distribution.
19
 *
20
 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
21
 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
22
 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
23
 * ARE DISCLAIMED.  IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
24
 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
25
 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
26
 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
27
 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
28
 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
29
 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
30
 * SUCH DAMAGE.
31
 *
32
 * Obtain log data from the shared memory log, order it by session ID, and
33
 * display it in Apache / NCSA combined log format.
34
 *
35
 * See doc/sphinx/reference/varnishncsa.rst for the supported format
36
 * specifiers.
37
 *
38
 */
39
40
#include "config.h"
41
42
#define _WITH_GETLINE
43
44
#include <stdlib.h>
45
#include <stdio.h>
46
#include <unistd.h>
47
#include <string.h>
48
#include <errno.h>
49
#include <signal.h>
50
#include <stdarg.h>
51
#include <inttypes.h>
52
#include <limits.h>
53
#include <ctype.h>
54
#include <time.h>
55
#include <math.h>
56
57
#define VOPT_DEFINITION
58
#define VOPT_INC "varnishncsa_options.h"
59
60
#include "vdef.h"
61
62
#include "b64.h"
63
#include "vapi/vsl.h"
64
#include "vapi/voptget.h"
65
#include "vas.h"
66
#include "vsb.h"
67
#include "vut.h"
68
#include "vqueue.h"
69
#include "miniobj.h"
70
71
#define TIME_FMT "[%d/%b/%Y:%T %z]"
72
#define FORMAT "%h %l %u %t \"%r\" %s %b \"%{Referer}i\" \"%{User-agent}i\""
73
74
static struct VUT *vut;
75
76
struct format;
77
78
enum e_frag {
79
        F_H,                    /* %H Proto */
80
        F_U,                    /* %U URL path */
81
        F_q,                    /* %q Query string */
82
        F_b,                    /* %b Body bytes sent */
83
        F_h,                    /* %h Host name / IP Address */
84
        F_m,                    /* %m Method */
85
        F_s,                    /* %s Status */
86
        F_I,                    /* %I Bytes received */
87
        F_O,                    /* %O Bytes sent */
88
        F_tstart,               /* Time start */
89
        F_tend,                 /* Time end */
90
        F_ttfb,                 /* %{Varnish:time_firstbyte}x */
91
        F_host,                 /* Host header */
92
        F_auth,                 /* Authorization header */
93
        F__MAX,
94
};
95
96
struct fragment {
97
        unsigned                gen;
98
        const char              *b, *e;
99
};
100
101
typedef int format_f(const struct format *format);
102
103
struct format {
104
        unsigned                magic;
105
#define FORMAT_MAGIC            0xC3119CDA
106
107
        char                    time_type;
108
        VTAILQ_ENTRY(format)    list;
109
        format_f                *func;
110
        struct fragment         *frag;
111
        char                    *string;
112
        const char *const       *strptr;
113
        char                    *time_fmt;
114
        int32_t                 *int32;
115
};
116
117
struct watch {
118
        unsigned                magic;
119
#define WATCH_MAGIC             0xA7D4005C
120
121
        VTAILQ_ENTRY(watch)     list;
122
        char                    *key;
123
        int                     keylen;
124
        struct fragment         frag;
125
};
126
VTAILQ_HEAD(watch_head, watch);
127
128
struct vsl_watch {
129
        unsigned                magic;
130
#define VSL_WATCH_MAGIC         0xE3E27D23
131
132
        VTAILQ_ENTRY(vsl_watch) list;
133
        enum VSL_tag_e          tag;
134
        int                     idx;
135
        char                    *prefix;
136
        int                     prefixlen;
137
        struct fragment         frag;
138
};
139
VTAILQ_HEAD(vsl_watch_head, vsl_watch);
140
141
static struct ctx {
142
        /* Options */
143
        int                     a_opt;
144
        int                     b_opt;
145
        int                     c_opt;
146
        char                    *w_arg;
147
148
        FILE                    *fo;
149
        struct vsb              *vsb;
150
        unsigned                gen;
151
        VTAILQ_HEAD(,format)    format;
152
153
        /* State */
154
        struct watch_head       watch_vcl_log;
155
        struct watch_head       watch_reqhdr; /* also bereqhdr */
156
        struct watch_head       watch_resphdr; /* also beresphdr */
157
        struct vsl_watch_head   watch_vsl;
158
        struct fragment         frag[F__MAX];
159
        const char              *hitmiss;
160
        const char              *handling;
161
        const char              *side;
162
        int32_t                 vxid;
163
} CTX;
164
165
static void v_noreturn_
166 24
usage(int status)
167
{
168
        const char **opt;
169
170 24
        fprintf(stderr, "Usage: %s <options>\n\n", vut->progname);
171 24
        fprintf(stderr, "Options:\n");
172 456
        for (opt = vopt_spec.vopt_usage; *opt != NULL; opt += 2)
173 432
                fprintf(stderr, " %-25s %s\n", *opt, *(opt + 1));
174 24
        exit(status);
175
}
176
177
static void
178 60
openout(int append)
179
{
180
181 60
        AN(CTX.w_arg);
182 60
        CTX.fo = fopen(CTX.w_arg, append ? "a" : "w");
183 60
        if (CTX.fo == NULL)
184 12
                VUT_Error(vut, 1, "Can't open output file (%s)",
185 12
                    strerror(errno));
186 48
}
187
188
static int v_matchproto_(VUT_cb_f)
189 12
rotateout(struct VUT *v)
190
{
191
192 12
        assert(v == vut);
193 12
        AN(CTX.w_arg);
194 12
        AN(CTX.fo);
195 12
        fclose(CTX.fo);
196 12
        openout(1);
197 12
        AN(CTX.fo);
198 12
        return (0);
199
}
200
201
static int v_matchproto_(VUT_cb_f)
202 4971
flushout(struct VUT *v)
203
{
204
205 4971
        assert(v == vut);
206 4971
        AN(CTX.fo);
207 4971
        if (fflush(CTX.fo))
208 0
                return (-5);
209 4971
        return (0);
210
}
211
212
static int
213 1416
vsb_esc_cat(struct vsb *sb, const char *b, const char *e)
214
{
215 1416
        AN(b);
216
217 8736
        for (; b < e; b++) {
218 7320
                if (isspace(*b)) {
219 120
                        switch (*b) {
220
                        case '\n':
221 0
                                VSB_cat(sb, "\\n");
222 0
                                break;
223
                        case '\t':
224 0
                                VSB_cat(sb, "\\t");
225 0
                                break;
226
                        case '\f':
227 0
                                VSB_cat(sb, "\\f");
228 0
                                break;
229
                        case '\r':
230 0
                                VSB_cat(sb, "\\r");
231 0
                                break;
232
                        case '\v':
233 0
                                VSB_cat(sb, "\\v");
234 0
                                break;
235
                        default:
236 120
                                VSB_putc(sb, *b);
237 120
                                break;
238
                        }
239 7200
                } else if (isprint(*b)) {
240 7200
                        switch (*b) {
241
                        case '"':
242 0
                                VSB_cat(sb, "\\\"");
243 0
                                break;
244
                        case '\\':
245 0
                                VSB_cat(sb, "\\\\");
246 0
                                break;
247
                        default:
248 7200
                                VSB_putc(sb, *b);
249 7200
                                break;
250
                        }
251
                } else
252 0
                        VSB_printf(sb, "\\x%02hhx", *b);
253
        }
254
255 1416
        return (VSB_error(sb));
256
}
257
258
static inline int
259 1068
vsb_fcat(struct vsb *vsb, const struct fragment *f, const char *dflt)
260
{
261 1068
        if (f->gen == CTX.gen) {
262 1068
                assert(f->b <= f->e);
263 1068
                return (vsb_esc_cat(vsb, f->b, f->e));
264
        }
265 0
        if (dflt)
266 0
                return (vsb_esc_cat(vsb, dflt, dflt + strlen(dflt)));
267 0
        return (-1);
268
}
269
270
static int v_matchproto_(format_f)
271 1296
format_string(const struct format *format)
272
{
273
274 1296
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
275 1296
        AN(format->string);
276 1296
        AZ(VSB_cat(CTX.vsb, format->string));
277 1296
        return (1);
278
}
279
280
static int v_matchproto_(format_f)
281 108
format_strptr(const struct format *format)
282
{
283
284 108
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
285 108
        AN(format->strptr);
286 108
        AN(*format->strptr);
287 108
        AZ(VSB_cat(CTX.vsb, *format->strptr));
288 108
        return (1);
289
}
290
291
static int v_matchproto_(format_f)
292 36
format_int32(const struct format *format)
293
{
294
295 36
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
296 36
        VSB_printf(CTX.vsb, "%" PRIi32, *format->int32);
297 36
        return (1);
298
}
299
300
static int v_matchproto_(format_f)
301 984
format_fragment(const struct format *format)
302
{
303
304 984
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
305 984
        AN(format->frag);
306
307 984
        if (format->frag->gen != CTX.gen) {
308 264
                if (format->string == NULL)
309 0
                        return (-1);
310 264
                AZ(vsb_esc_cat(CTX.vsb, format->string,
311
                    format->string + strlen(format->string)));
312 264
                return (0);
313
        }
314 720
        AZ(vsb_fcat(CTX.vsb, format->frag, NULL));
315 720
        return (1);
316
}
317
318
static int v_matchproto_(format_f)
319 180
format_time(const struct format *format)
320
{
321
        double t_start, t_end;
322
        char *p;
323
        char buf[64];
324
        time_t t;
325
        struct tm tm;
326
327 180
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
328 180
        if (CTX.frag[F_tstart].gen == CTX.gen) {
329 180
                t_start = strtod(CTX.frag[F_tstart].b, &p);
330 180
                if (p != CTX.frag[F_tstart].e)
331 0
                        t_start = NAN;
332
        } else
333 0
                t_start = NAN;
334 180
        if (isnan(t_start)) {
335
                /* Missing t_start is a no go */
336 0
                if (format->string == NULL)
337 0
                        return (-1);
338 0
                AZ(VSB_cat(CTX.vsb, format->string));
339 0
                return (0);
340
        }
341
342
        /* Missing t_end defaults to t_start */
343 180
        if (CTX.frag[F_tend].gen == CTX.gen) {
344 180
                t_end = strtod(CTX.frag[F_tend].b, &p);
345 180
                if (p != CTX.frag[F_tend].e)
346 0
                        t_end = t_start;
347
        } else
348 0
                t_end = t_start;
349
350 180
        switch (format->time_type) {
351
        case 'D':
352 36
                AZ(VSB_printf(CTX.vsb, "%d",
353
                    (int)((t_end - t_start) * 1e6)));
354 36
                break;
355
        case 't':
356 108
                AN(format->time_fmt);
357 108
                t = t_start;
358 108
                localtime_r(&t, &tm);
359 108
                strftime(buf, sizeof buf, format->time_fmt, &tm);
360 108
                AZ(VSB_cat(CTX.vsb, buf));
361 108
                break;
362
        case 'T':
363 36
                AZ(VSB_printf(CTX.vsb, "%d", (int)(t_end - t_start)));
364 36
                break;
365
        default:
366 0
                WRONG("Time format specifier");
367
        }
368
369 180
        return (1);
370
}
371
372
static int v_matchproto_(format_f)
373 72
format_requestline(const struct format *format)
374
{
375
376
        (void)format;
377 72
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_m], "-"));
378 72
        AZ(VSB_putc(CTX.vsb, ' '));
379 72
        if (CTX.frag[F_host].gen == CTX.gen) {
380 60
                if (strncmp(CTX.frag[F_host].b, "http://", 7))
381 60
                        AZ(VSB_cat(CTX.vsb, "http://"));
382 60
                AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_host], NULL));
383
        } else
384 12
                AZ(VSB_cat(CTX.vsb, "http://localhost"));
385 72
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_U], ""));
386 72
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_q], ""));
387 72
        AZ(VSB_putc(CTX.vsb, ' '));
388 72
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_H], "HTTP/1.0"));
389 72
        return (1);
390
}
391
392
static int v_matchproto_(format_f)
393 84
format_auth(const struct format *format)
394
{
395
        char buf[128];
396
        char *q;
397
398 120
        if (CTX.frag[F_auth].gen != CTX.gen ||
399 36
            VB64_decode(buf, sizeof buf, CTX.frag[F_auth].b,
400
            CTX.frag[F_auth].e)) {
401 48
                if (format->string == NULL)
402 0
                        return (-1);
403 48
                AZ(vsb_esc_cat(CTX.vsb, format->string,
404
                    format->string + strlen(format->string)));
405 48
                return (0);
406
        }
407 36
        q = strchr(buf, ':');
408 36
        if (q != NULL)
409 36
                *q = '\0';
410 36
        AZ(vsb_esc_cat(CTX.vsb, buf, buf + strlen(buf)));
411 36
        return (1);
412
}
413
414
static int
415 276
print(void)
416
{
417
        const struct format *f;
418 276
        int i, r = 1;
419
420 276
        VSB_clear(CTX.vsb);
421 3036
        VTAILQ_FOREACH(f, &CTX.format, list) {
422 2760
                CHECK_OBJ_NOTNULL(f, FORMAT_MAGIC);
423 2760
                i = (f->func)(f);
424 2760
                if (r > i)
425 144
                        r = i;
426
        }
427 276
        AZ(VSB_putc(CTX.vsb, '\n'));
428 276
        AZ(VSB_finish(CTX.vsb));
429 276
        if (r >= 0) {
430 276
                i = fwrite(VSB_data(CTX.vsb), 1, VSB_len(CTX.vsb), CTX.fo);
431 276
                if (i != VSB_len(CTX.vsb))
432 0
                        return (-5);
433
        }
434 276
        return (0);
435
}
436
437
static void
438 768
addf_string(const char *str)
439
{
440
        struct format *f;
441
442 768
        AN(str);
443 768
        ALLOC_OBJ(f, FORMAT_MAGIC);
444 768
        AN(f);
445 768
        f->func = format_string;
446 768
        f->string = strdup(str);
447 768
        AN(f->string);
448 768
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
449 768
}
450
451
static void
452 36
addf_strptr(const char *const *strptr)
453
{
454
        struct format *f;
455
456 36
        AN(strptr);
457 36
        ALLOC_OBJ(f, FORMAT_MAGIC);
458 36
        AN(f);
459 36
        f->func = format_strptr;
460 36
        f->strptr = strptr;
461 36
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
462 36
}
463
464
static void
465 372
addf_fragment(struct fragment *frag, const char *str)
466
{
467
        struct format *f;
468
469 372
        AN(frag);
470 372
        ALLOC_OBJ(f, FORMAT_MAGIC);
471 372
        AN(f);
472 372
        f->func = format_fragment;
473 372
        f->frag = frag;
474 372
        if (str != NULL) {
475 372
                f->string = strdup(str);
476 372
                AN(f->string);
477
        }
478 372
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
479 372
}
480
481
static void
482 12
addf_int32(int32_t *i)
483
{
484
        struct format *f;
485
486 12
        AN(i);
487 12
        ALLOC_OBJ(f, FORMAT_MAGIC);
488 12
        AN(f);
489 12
        f->func = format_int32;
490 12
        f->int32 = i;
491 12
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
492 12
}
493
494
static void
495 96
addf_time(char type, const char *fmt)
496
{
497
        struct format *f;
498
499 96
        ALLOC_OBJ(f, FORMAT_MAGIC);
500 96
        AN(f);
501 96
        f->func = format_time;
502 96
        f->time_type = type;
503 96
        if (fmt != NULL) {
504 72
                f->time_fmt = strdup(fmt);
505 72
                AN(f->time_fmt);
506
        }
507 96
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
508 96
}
509
510
static void
511 84
addf_requestline(void)
512
{
513
        struct format *f;
514
515 84
        ALLOC_OBJ(f, FORMAT_MAGIC);
516 84
        AN(f);
517 84
        f->func = format_requestline;
518 84
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
519 84
}
520
521
static void
522 12
addf_vcl_log(const char *key)
523
{
524
        struct watch *w;
525
        struct format *f;
526
527 12
        AN(key);
528 12
        ALLOC_OBJ(w, WATCH_MAGIC);
529 12
        AN(w);
530 12
        w->keylen = asprintf(&w->key, "%s:", key);
531 12
        assert(w->keylen > 0);
532 12
        VTAILQ_INSERT_TAIL(&CTX.watch_vcl_log, w, list);
533
534 12
        ALLOC_OBJ(f, FORMAT_MAGIC);
535 12
        AN(f);
536 12
        f->func = format_fragment;
537 12
        f->frag = &w->frag;
538 12
        f->string = strdup("");
539 12
        AN(f->string);
540 12
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
541 12
}
542
543
static void
544 156
addf_hdr(struct watch_head *head, const char *key)
545
{
546
        struct watch *w;
547
        struct format *f;
548
549 156
        AN(head);
550 156
        AN(key);
551 156
        ALLOC_OBJ(w, WATCH_MAGIC);
552 156
        AN(w);
553 156
        w->keylen = asprintf(&w->key, "%s:", key);
554 156
        assert(w->keylen > 0);
555 156
        VTAILQ_INSERT_TAIL(head, w, list);
556
557 156
        ALLOC_OBJ(f, FORMAT_MAGIC);
558 156
        AN(f);
559 156
        f->func = format_fragment;
560 156
        f->frag = &w->frag;
561 156
        f->string = strdup("-");
562 156
        AN(f->string);
563 156
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
564 156
}
565
566
static void
567 60
addf_vsl(enum VSL_tag_e tag, long i, const char *prefix)
568
{
569
        struct vsl_watch *w;
570
571 60
        ALLOC_OBJ(w, VSL_WATCH_MAGIC);
572 60
        AN(w);
573 60
        if (VSL_tagflags[tag])
574 0
                VUT_Error(vut, 1, "Tag %s can contain control characters",
575
                    VSL_tags[tag]);
576 60
        w->tag = tag;
577 60
        assert(i <= INT_MAX);
578 60
        w->idx = i;
579 60
        if (prefix != NULL) {
580 36
                w->prefixlen = asprintf(&w->prefix, "%s:", prefix);
581 36
                assert(w->prefixlen > 0);
582
        }
583 60
        VTAILQ_INSERT_TAIL(&CTX.watch_vsl, w, list);
584 60
        addf_fragment(&w->frag, "-");
585 60
}
586
587
static void
588 72
addf_auth(void)
589
{
590
        struct format *f;
591
592 72
        ALLOC_OBJ(f, FORMAT_MAGIC);
593 72
        AN(f);
594 72
        f->func = format_auth;
595 72
        f->string = strdup("-");
596 72
        AN(f->string);
597 72
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
598 72
}
599
600
static void
601 252
parse_x_format(char *buf)
602
{
603
        char *e, *r, *s;
604
        long lval;
605
        int slt;
606
607 252
        if (!strcmp(buf, "Varnish:time_firstbyte")) {
608 12
                addf_fragment(&CTX.frag[F_ttfb], "");
609 12
                return;
610
        }
611 240
        if (!strcmp(buf, "Varnish:hitmiss")) {
612 12
                addf_strptr(&CTX.hitmiss);
613 12
                return;
614
        }
615 228
        if (!strcmp(buf, "Varnish:handling")) {
616 12
                addf_strptr(&CTX.handling);
617 12
                return;
618
        }
619 216
        if (!strcmp(buf, "Varnish:side")) {
620 12
                addf_strptr(&CTX.side);
621 12
                return;
622
        }
623 204
        if (!strcmp(buf, "Varnish:vxid")) {
624 12
                addf_int32(&CTX.vxid);
625 12
                return;
626
        }
627 192
        if (!strncmp(buf, "VCL_Log:", 8)) {
628 12
                addf_vcl_log(buf + 8);
629 12
                return;
630
        }
631 180
        if (!strncmp(buf, "VSL:", 4)) {
632 168
                buf += 4;
633 168
                e = buf;
634 1836
                while (*e != '\0')
635 1500
                        e++;
636 168
                if (e == buf)
637 12
                        VUT_Error(vut, 1, "Missing tag in VSL:");
638 156
                if (e[-1] == ']') {
639 72
                        r = e - 1;
640 456
                        while (r > buf && *r != '[')
641 312
                                r--;
642 72
                        if (r == buf || r[1] == ']')
643 12
                                VUT_Error(vut, 1, "Syntax error: VSL:%s", buf);
644 60
                        e[-1] = '\0';
645 60
                        lval = strtol(r + 1, &s, 10);
646 60
                        if (s != e - 1)
647 12
                                VUT_Error(vut, 1, "Syntax error: VSL:%s]", buf);
648 48
                        if (lval <= 0 || lval > 255) {
649 24
                                VUT_Error(vut, 1,
650
                                    "Syntax error. Field specifier must be"
651
                                    " between 1 and 255: %s]",
652
                                    buf);
653
                        }
654 24
                        *r = '\0';
655
                } else
656 84
                        lval = 0;
657 108
                r = buf;
658 1020
                while (r < e && *r != ':')
659 804
                        r++;
660 108
                if (r != e) {
661 36
                        slt = VSL_Name2Tag(buf, r - buf);
662 36
                        r++;
663
                } else {
664 72
                        slt = VSL_Name2Tag(buf, -1);
665 72
                        r = NULL;
666
                }
667 108
                if (slt == -2)
668 12
                        VUT_Error(vut, 1, "Tag not unique: %s", buf);
669 96
                if (slt == -1)
670 36
                        VUT_Error(vut, 1, "Unknown log tag: %s", buf);
671 60
                assert(slt >= 0);
672
673 60
                addf_vsl(slt, lval, r);
674 60
                return;
675
        }
676 12
        VUT_Error(vut, 1, "Unknown formatting extension: %s", buf);
677
}
678
679
static void
680 336
parse_format(const char *format)
681
{
682
        const char *p, *q;
683
        struct vsb *vsb;
684
        char buf[256];
685
686 336
        if (format == NULL)
687 48
                format = FORMAT;
688
689 336
        vsb = VSB_new_auto();
690 336
        AN(vsb);
691
692 2244
        for (p = format; *p != '\0'; p++) {
693
694
                /* Allow the most essential escape sequences in format */
695 2064
                if (*p == '\\' && p[1] != '\0') {
696 0
                        if (*++p == 't')
697 0
                                AZ(VSB_putc(vsb, '\t'));
698 0
                        else if (*p == 'n')
699 0
                                AZ(VSB_putc(vsb, '\n'));
700
                        else
701 0
                                AZ(VSB_putc(vsb, *p));
702 0
                        continue;
703
                }
704
705 2064
                if (*p != '%') {
706 1008
                        AZ(VSB_putc(vsb, *p));
707 1008
                        continue;
708
                }
709
710 1056
                if (VSB_len(vsb) > 0) {
711 720
                        AZ(VSB_finish(vsb));
712 720
                        addf_string(VSB_data(vsb));
713 720
                        VSB_clear(vsb);
714
                }
715
716 1056
                p++;
717 1056
                switch (*p) {
718
                case 'b':       /* Body bytes sent */
719 84
                        addf_fragment(&CTX.frag[F_b], "-");
720 84
                        break;
721
                case 'D':       /* Float request time */
722 12
                        addf_time(*p, NULL);
723 12
                        break;
724
                case 'h':       /* Client host name / IP Address */
725 84
                        addf_fragment(&CTX.frag[F_h], "-");
726 84
                        break;
727
                case 'H':       /* Protocol */
728 12
                        addf_fragment(&CTX.frag[F_H], "HTTP/1.0");
729 12
                        break;
730
                case 'I':       /* Bytes received */
731 12
                        addf_fragment(&CTX.frag[F_I], "-");
732 12
                        break;
733
                case 'l':       /* Client user ID (identd) always '-' */
734 60
                        AZ(VSB_putc(vsb, '-'));
735 60
                        break;
736
                case 'm':       /* Method */
737 12
                        addf_fragment(&CTX.frag[F_m], "-");
738 12
                        break;
739
                case 'O':       /* Bytes sent */
740 12
                        addf_fragment(&CTX.frag[F_O], "-");
741 12
                        break;
742
                case 'q':       /* Query string */
743 12
                        addf_fragment(&CTX.frag[F_q], "");
744 12
                        break;
745
                case 'r':       /* Request line */
746 84
                        addf_requestline();
747 84
                        break;
748
                case 's':       /* Status code */
749 60
                        addf_fragment(&CTX.frag[F_s], "-");
750 60
                        break;
751
                case 't':       /* strftime */
752 60
                        addf_time(*p, TIME_FMT);
753 60
                        break;
754
                case 'T':       /* Int request time */
755 12
                        addf_time(*p, NULL);
756 12
                        break;
757
                case 'u':       /* Remote user from auth */
758 72
                        addf_auth();
759 72
                        break;
760
                case 'U':       /* URL */
761 12
                        addf_fragment(&CTX.frag[F_U], "-");
762 12
                        break;
763
                case '{':
764 444
                        p++;
765 444
                        q = p;
766 5292
                        while (*q && *q != '}')
767 4404
                                q++;
768 444
                        if (!*q)
769 12
                                VUT_Error(vut, 1, "Unmatched bracket at: %s",
770
                                    p - 2);
771 432
                        assert(q - p < sizeof buf - 1);
772 432
                        strncpy(buf, p, q - p);
773 432
                        buf[q - p] = '\0';
774 432
                        q++;
775 432
                        switch (*q) {
776
                        case 'i':
777 144
                                addf_hdr(&CTX.watch_reqhdr, buf);
778 144
                                break;
779
                        case 'o':
780 12
                                addf_hdr(&CTX.watch_resphdr, buf);
781 12
                                break;
782
                        case 't':
783 12
                                addf_time(*q, buf);
784 12
                                break;
785
                        case 'x':
786 252
                                parse_x_format(buf);
787 132
                                break;
788
                        default:
789 12
                                VUT_Error(vut, 1,
790
                                    "Unknown format specifier at: %s",
791
                                    p - 2);
792
                        }
793 300
                        p = q;
794 300
                        break;
795
                default:
796 12
                        VUT_Error(vut, 1, "Unknown format specifier at: %s",
797
                            p - 1);
798
                }
799
        }
800
801 180
        if (VSB_len(vsb) > 0) {
802
                /* Add any remaining static */
803 48
                AZ(VSB_finish(vsb));
804 48
                addf_string(VSB_data(vsb));
805 48
                VSB_clear(vsb);
806
        }
807
808 180
        VSB_destroy(&vsb);
809 180
}
810
811
static int
812 7788
isprefix(const char *prefix, size_t len, const char *b,
813
    const char *e, const char **next)
814
{
815 7788
        assert(len > 0);
816 7788
        if (e - b < len || strncasecmp(b, prefix, len))
817 6408
                return (0);
818 1380
        b += len;
819 1380
        if (next) {
820 3984
                while (b < e && *b == ' ')
821 1224
                        b++;
822 1380
                *next = b;
823
        }
824 1380
        return (1);
825
}
826
827
static void
828 1404
frag_fields(int force, const char *b, const char *e, ...)
829
{
830
        va_list ap;
831
        const char *p, *q;
832
        int n, field;
833
        struct fragment *frag;
834
835 1404
        AN(b);
836 1404
        AN(e);
837 1404
        va_start(ap, e);
838
839 1404
        field = va_arg(ap, int);
840 1404
        frag = va_arg(ap, struct fragment *);
841 2988
        for (n = 1, q = b; q < e; n++) {
842
                /* caller must sort the fields, or this loop will not work: */
843 2988
                assert(field >= n);
844 2988
                AN(frag);
845
846 2988
                p = q;
847
                /* Skip WS */
848 7560
                while (p < e && isspace(*p))
849 1584
                        p++;
850 2988
                q = p;
851
                /* Skip non-WS */
852 28992
                while (q < e && !isspace(*q))
853 23016
                        q++;
854
855 2988
                if (field == n) {
856 1896
                        if (frag->gen != CTX.gen || force) {
857
                                /* We only grab the same matching field once */
858 1896
                                frag->gen = CTX.gen;
859 1896
                                frag->b = p;
860 1896
                                frag->e = q;
861
                        }
862 1896
                        field = va_arg(ap, int);
863 1896
                        if (field == 0)
864 1404
                                break;
865 492
                        frag = va_arg(ap, struct fragment *);
866
                }
867
        }
868 1404
        va_end(ap);
869 1404
}
870
871
static void
872 1848
frag_line(int force, const char *b, const char *e, struct fragment *f)
873
{
874
875 1848
        if (f->gen == CTX.gen && !force)
876
                /* We only grab the same matching record once */
877 24
                return;
878
879
        /* Skip leading space */
880 3648
        while (b < e && isspace(*b))
881 0
                ++b;
882
883
        /* Skip trailing space */
884 3648
        while (e > b && isspace(e[-1]))
885 0
                --e;
886
887 1824
        f->gen = CTX.gen;
888 1824
        f->b = b;
889 1824
        f->e = e;
890
}
891
892
static void
893 2028
process_hdr(const struct watch_head *head, const char *b, const char *e)
894
{
895
        struct watch *w;
896
        const char *p;
897
898 2724
        VTAILQ_FOREACH(w, head, list) {
899 696
                CHECK_OBJ_NOTNULL(w, WATCH_MAGIC);
900 696
                if (!isprefix(w->key, w->keylen, b, e, &p))
901 600
                        continue;
902 96
                frag_line(1, p, e, &w->frag);
903
        }
904 2028
}
905
906
static void
907 8208
process_vsl(const struct vsl_watch_head *head, enum VSL_tag_e tag,
908
    const char *b, const char *e)
909
{
910
        struct vsl_watch *w;
911
        const char *p;
912
913 13488
        VTAILQ_FOREACH(w, head, list) {
914 5280
                CHECK_OBJ_NOTNULL(w, VSL_WATCH_MAGIC);
915 5280
                if (tag != w->tag)
916 4740
                        continue;
917 540
                p = b;
918 1008
                if (w->prefixlen > 0 &&
919 468
                    !isprefix(w->prefix, w->prefixlen, b, e, &p))
920 420
                        continue;
921 120
                if (w->idx == 0)
922 60
                        frag_line(0, p, e, &w->frag);
923
                else
924 60
                        frag_fields(0, p, e, w->idx, &w->frag, 0, NULL);
925
        }
926 8208
}
927
928
static int v_matchproto_(VSLQ_dispatch_f)
929 720
dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
930
    void *priv)
931
{
932
        struct VSL_transaction *t;
933
        unsigned tag;
934
        const char *b, *e, *p;
935
        struct watch *w;
936
        int i, skip, be_mark;
937
938
        (void)vsl;
939
        (void)priv;
940
941
#define BACKEND_MARKER (INT_MAX / 2 + 1)
942
        assert(BACKEND_MARKER >= VSL_t__MAX);
943
944 1440
        for (t = pt[0]; t != NULL; t = *++pt) {
945 720
                CTX.gen++;
946
947
                /* Consider client requests only if in client mode.
948
                   Consider backend requests only if in backend mode. */
949 720
                if (t->type == VSL_t_req && CTX.c_opt) {
950 228
                        CTX.side = "c";
951 228
                        be_mark = 0;
952 492
                } else if (t->type == VSL_t_bereq && CTX.b_opt) {
953 48
                        CTX.side = "b";
954 48
                        be_mark = BACKEND_MARKER;
955
                } else
956 444
                        continue;
957 276
                if (t->reason == VSL_r_esi)
958
                        /* Skip ESI requests */
959 0
                        continue;
960 276
                CTX.hitmiss = "-";
961 276
                CTX.handling = "-";
962 276
                CTX.vxid = t->vxid;
963 276
                skip = 0;
964 8760
                while (skip == 0 && 1 == VSL_Next(t->c)) {
965 8208
                        tag = VSL_TAG(t->c->rec.ptr);
966 8208
                        if (VSL_tagflags[tag])
967 0
                                continue;
968
969 8208
                        b = VSL_CDATA(t->c->rec.ptr);
970 8208
                        e = b + VSL_LEN(t->c->rec.ptr);
971 24624
                        while (e > b && e[-1] == '\0')
972 8208
                                e--;
973
974 8208
                        switch (tag + be_mark) {
975
                        case SLT_HttpGarbage + BACKEND_MARKER:
976
                        case SLT_HttpGarbage:
977 0
                                skip = 1;
978 0
                                break;
979
                        case SLT_PipeAcct:
980 60
                                frag_fields(0, b, e,
981
                                    3, &CTX.frag[F_I],
982
                                    4, &CTX.frag[F_O],
983
                                    0, NULL);
984 60
                                break;
985
                        case (SLT_BackendStart + BACKEND_MARKER):
986 48
                                frag_fields(1, b, e,
987
                                    1, &CTX.frag[F_h],
988
                                    0, NULL);
989 48
                                break;
990
                        case SLT_ReqStart:
991 228
                                frag_fields(0, b, e,
992
                                    1, &CTX.frag[F_h],
993
                                    0, NULL);
994 228
                                break;
995
                        case (SLT_BereqMethod + BACKEND_MARKER):
996
                        case SLT_ReqMethod:
997 276
                                frag_line(0, b, e, &CTX.frag[F_m]);
998 276
                                break;
999
                        case (SLT_BereqURL + BACKEND_MARKER):
1000
                        case SLT_ReqURL:
1001 276
                                p = memchr(b, '?', e - b);
1002 276
                                if (p == NULL)
1003 144
                                        p = e;
1004 276
                                frag_line(0, b, p, &CTX.frag[F_U]);
1005 276
                                frag_line(0, p, e, &CTX.frag[F_q]);
1006 276
                                break;
1007
                        case (SLT_BereqProtocol + BACKEND_MARKER):
1008
                        case SLT_ReqProtocol:
1009 300
                                frag_line(0, b, e, &CTX.frag[F_H]);
1010 300
                                break;
1011
                        case (SLT_BerespStatus + BACKEND_MARKER):
1012
                        case SLT_RespStatus:
1013 204
                                frag_line(1, b, e, &CTX.frag[F_s]);
1014 204
                                break;
1015
                        case (SLT_BereqAcct + BACKEND_MARKER):
1016
                        case SLT_ReqAcct:
1017 216
                                frag_fields(0, b, e,
1018
                                    3, &CTX.frag[F_I],
1019
                                    5, &CTX.frag[F_b],
1020
                                    6, &CTX.frag[F_O],
1021
                                    0, NULL);
1022 216
                                break;
1023
                        case (SLT_Timestamp + BACKEND_MARKER):
1024
                        case SLT_Timestamp:
1025
#define ISPREFIX(a, b, c, d)    isprefix(a, strlen(a), b, c, d)
1026 1176
                                if (ISPREFIX("Start:", b, e, &p)) {
1027 264
                                        frag_fields(0, p, e, 1,
1028
                                            &CTX.frag[F_tstart], 0, NULL);
1029
1030 1656
                                } else if (ISPREFIX("Resp:", b, e, &p) ||
1031 1428
                                    ISPREFIX("PipeSess:", b, e, &p) ||
1032 684
                                    ISPREFIX("BerespBody:", b, e, &p)) {
1033 264
                                        frag_fields(0, p, e, 1,
1034
                                            &CTX.frag[F_tend], 0, NULL);
1035
1036 1128
                                } else if (ISPREFIX("Process:", b, e, &p) ||
1037 900
                                    ISPREFIX("Pipe:", b, e, &p) ||
1038 420
                                    ISPREFIX("Beresp:", b, e, &p)) {
1039 264
                                        frag_fields(0, p, e, 2,
1040
                                            &CTX.frag[F_ttfb], 0, NULL);
1041
                                }
1042 1176
                                break;
1043
                        case (SLT_BereqHeader + BACKEND_MARKER):
1044
                        case SLT_ReqHeader:
1045 876
                                if (ISPREFIX("Authorization:", b, e, &p) &&
1046 96
                                    ISPREFIX("basic ", p, e, &p))
1047 96
                                        frag_line(0, p, e,
1048
                                            &CTX.frag[F_auth]);
1049 684
                                else if (ISPREFIX("Host:", b, e, &p))
1050 252
                                        frag_line(0, p, e,
1051
                                            &CTX.frag[F_host]);
1052
#undef ISPREFIX
1053 780
                                break;
1054
                        case SLT_VCL_call:
1055 792
                                if (!strcasecmp(b, "recv")) {
1056 228
                                        CTX.hitmiss = "-";
1057 228
                                        CTX.handling = "-";
1058 564
                                } else if (!strcasecmp(b, "hit")) {
1059 60
                                        CTX.hitmiss = "hit";
1060 60
                                        CTX.handling = "hit";
1061 504
                                } else if (!strcasecmp(b, "miss")) {
1062 84
                                        CTX.hitmiss = "miss";
1063 84
                                        CTX.handling = "miss";
1064 420
                                } else if (!strcasecmp(b, "pass")) {
1065 24
                                        CTX.hitmiss = "miss";
1066 24
                                        CTX.handling = "pass";
1067 396
                                } else if (!strcasecmp(b, "synth")) {
1068
                                        /* Arguably, synth isn't a hit or
1069
                                           a miss, but miss is less
1070
                                           wrong */
1071 60
                                        CTX.hitmiss = "miss";
1072 60
                                        CTX.handling = "synth";
1073
                                }
1074 792
                                break;
1075
                        case SLT_VCL_return:
1076 792
                                if (!strcasecmp(b, "pipe")) {
1077 60
                                        CTX.hitmiss = "miss";
1078 60
                                        CTX.handling = "pipe";
1079 732
                                } else if (!strcasecmp(b, "restart"))
1080 0
                                        skip = 1;
1081 792
                                break;
1082
                        case (SLT_VCL_Log + BACKEND_MARKER):
1083
                        case SLT_VCL_Log:
1084 72
                                VTAILQ_FOREACH(w, &CTX.watch_vcl_log, list) {
1085 12
                                        CHECK_OBJ_NOTNULL(w, WATCH_MAGIC);
1086 24
                                        if (e - b < w->keylen ||
1087 12
                                            strncmp(b, w->key, w->keylen))
1088 0
                                                continue;
1089 12
                                        p = b + w->keylen;
1090 12
                                        frag_line(0, p, e, &w->frag);
1091
                                }
1092 60
                                break;
1093
                        default:
1094 3000
                                break;
1095
                        }
1096
1097 8208
                        if ((tag == SLT_ReqHeader && CTX.c_opt) ||
1098 204
                            (tag == SLT_BereqHeader && CTX.b_opt))
1099 780
                                process_hdr(&CTX.watch_reqhdr, b, e);
1100 7428
                        else if ((tag == SLT_RespHeader && CTX.c_opt) ||
1101 72
                            (tag == SLT_BerespHeader && CTX.b_opt))
1102 1248
                                process_hdr(&CTX.watch_resphdr, b, e);
1103
1104 8208
                        process_vsl(&CTX.watch_vsl, tag, b, e);
1105
                }
1106 276
                if (skip)
1107 0
                        continue;
1108 276
                i = print();
1109 276
                if (i)
1110 0
                        return (i);
1111
        }
1112
1113 720
        return (0);
1114
}
1115
1116
static int v_matchproto_(VUT_cb_f)
1117 0
sighup(struct VUT *v)
1118
{
1119 0
        assert(v == vut);
1120 0
        return (1);
1121
}
1122
1123
static void
1124 48
vut_sighandler(int sig)
1125
{
1126
1127 48
        if (vut != NULL)
1128 48
                VUT_Signaled(vut, sig);
1129 48
}
1130
1131
static char *
1132 36
read_format(const char *formatfile)
1133
{
1134
        FILE *fmtfile;
1135 36
        size_t len = 0;
1136
        int fmtlen;
1137 36
        char *fmt = NULL;
1138
1139 36
        fmtfile = fopen(formatfile, "r");
1140 36
        if (fmtfile == NULL)
1141 12
                VUT_Error(vut, 1, "Can't open format file (%s)",
1142 12
                    strerror(errno));
1143 24
        AN(fmtfile);
1144 24
        fmtlen = getline(&fmt, &len, fmtfile);
1145 24
        if (fmtlen == -1) {
1146 12
                free(fmt);
1147 12
                if (feof(fmtfile))
1148 12
                        VUT_Error(vut, 1, "Empty format file");
1149 0
                VUT_Error(vut, 1, "Can't read format from file (%s)",
1150 0
                    strerror(errno));
1151
        }
1152 12
        fclose(fmtfile);
1153 12
        if (fmt[fmtlen - 1] == '\n')
1154 12
                fmt[fmtlen - 1] = '\0';
1155 12
        return (fmt);
1156
}
1157
1158
int
1159 444
main(int argc, char * const *argv)
1160
{
1161
        signed char opt;
1162 444
        char *format = NULL;
1163
1164 444
        vut = VUT_InitProg(argc, argv, &vopt_spec);
1165 420
        AN(vut);
1166 420
        memset(&CTX, 0, sizeof CTX);
1167 420
        VTAILQ_INIT(&CTX.format);
1168 420
        VTAILQ_INIT(&CTX.watch_vcl_log);
1169 420
        VTAILQ_INIT(&CTX.watch_reqhdr);
1170 420
        VTAILQ_INIT(&CTX.watch_resphdr);
1171 420
        VTAILQ_INIT(&CTX.watch_vsl);
1172 420
        CTX.vsb = VSB_new_auto();
1173 420
        AN(CTX.vsb);
1174 420
        VB64_init();
1175
1176 420
        while ((opt = getopt(argc, argv, vopt_spec.vopt_optstring)) != -1) {
1177 828
                switch (opt) {
1178
                case 'a':
1179
                        /* Append to file */
1180 0
                        CTX.a_opt = 1;
1181 0
                        break;
1182
                case 'b':
1183
                        /* backend mode */
1184 36
                        CTX.b_opt = 1;
1185 36
                        break;
1186
                case 'c':
1187
                        /* client mode */
1188 36
                        CTX.c_opt = 1;
1189 36
                        break;
1190
                case 'F':
1191
                        /* Format string */
1192 276
                        if (format != NULL)
1193 0
                                free(format);
1194 276
                        format = strdup(optarg);
1195 276
                        AN(format);
1196 276
                        break;
1197
                case 'f':
1198
                        /* Format string from file */
1199 36
                        if (format != NULL)
1200 0
                                free(format);
1201 36
                        format = read_format(optarg);
1202 12
                        AN(format);
1203 12
                        break;
1204
                case 'h':
1205
                        /* Usage help */
1206 12
                        usage(0);
1207
                        break;
1208
                case 'w':
1209
                        /* Write to file */
1210 48
                        REPLACE(CTX.w_arg, optarg);
1211 48
                        break;
1212
                default:
1213 384
                        if (!VUT_Arg(vut, opt, optarg))
1214 0
                                usage(1);
1215
                }
1216
        }
1217
        /* default is client mode: */
1218 372
        if (!CTX.b_opt)
1219 336
                CTX.c_opt = 1;
1220
1221 372
        if (optind != argc)
1222 12
                usage(1);
1223
1224 360
        if (vut->D_opt && !CTX.w_arg)
1225 12
                VUT_Error(vut, 1, "Missing -w option");
1226
1227
        /* Check for valid grouping mode */
1228 348
        assert(vut->g_arg < VSL_g__MAX);
1229 348
        if (vut->g_arg != VSL_g_vxid && vut->g_arg != VSL_g_request)
1230 12
                VUT_Error(vut, 1, "Invalid grouping mode: %s",
1231 12
                    VSLQ_grouping[vut->g_arg]);
1232
1233
        /* Prepare output format */
1234 336
        parse_format(format);
1235 180
        free(format);
1236 180
        format = NULL;
1237
1238
        /* Setup output */
1239 180
        vut->dispatch_f = dispatch_f;
1240 180
        vut->dispatch_priv = NULL;
1241 180
        vut->sighup_f = sighup;
1242 180
        if (CTX.w_arg) {
1243 48
                openout(CTX.a_opt);
1244 36
                AN(CTX.fo);
1245 36
                if (vut->D_opt)
1246 12
                        vut->sighup_f = rotateout;
1247
        } else
1248 132
                CTX.fo = stdout;
1249 168
        vut->idle_f = flushout;
1250
1251 168
        VUT_Signal(vut_sighandler);
1252 168
        VUT_Setup(vut);
1253 168
        VUT_Main(vut);
1254 168
        VUT_Fini(&vut);
1255
1256 168
        exit(0);
1257
}