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 4
usage(int status)
167
{
168
        const char **opt;
169
170 4
        fprintf(stderr, "Usage: %s <options>\n\n", vut->progname);
171 4
        fprintf(stderr, "Options:\n");
172 76
        for (opt = vopt_spec.vopt_usage; *opt != NULL; opt += 2)
173 72
                fprintf(stderr, " %-25s %s\n", *opt, *(opt + 1));
174 4
        exit(status);
175
}
176
177
static void
178 10
openout(int append)
179
{
180
181 10
        AN(CTX.w_arg);
182 10
        CTX.fo = fopen(CTX.w_arg, append ? "a" : "w");
183 10
        if (CTX.fo == NULL)
184 2
                VUT_Error(vut, 1, "Can't open output file (%s)",
185 2
                    strerror(errno));
186 8
}
187
188
static int v_matchproto_(VUT_cb_f)
189 2
rotateout(struct VUT *v)
190
{
191
192 2
        assert(v == vut);
193 2
        AN(CTX.w_arg);
194 2
        AN(CTX.fo);
195 2
        fclose(CTX.fo);
196 2
        openout(1);
197 2
        AN(CTX.fo);
198 2
        return (0);
199
}
200
201
static int v_matchproto_(VUT_cb_f)
202 828
flushout(struct VUT *v)
203
{
204
205 828
        assert(v == vut);
206 828
        AN(CTX.fo);
207 828
        if (fflush(CTX.fo))
208 0
                return (-5);
209 828
        return (0);
210
}
211
212
static int
213 236
vsb_esc_cat(struct vsb *sb, const char *b, const char *e)
214
{
215 236
        AN(b);
216
217 1456
        for (; b < e; b++) {
218 1220
                if (isspace(*b)) {
219 20
                        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 20
                                VSB_putc(sb, *b);
237 20
                                break;
238
                        }
239 1200
                } else if (isprint(*b)) {
240 1200
                        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 1200
                                VSB_putc(sb, *b);
249 1200
                                break;
250
                        }
251
                } else
252 0
                        VSB_printf(sb, "\\x%02hhx", *b);
253
        }
254
255 236
        return (VSB_error(sb));
256
}
257
258
static inline int
259 178
vsb_fcat(struct vsb *vsb, const struct fragment *f, const char *dflt)
260
{
261 178
        if (f->gen == CTX.gen) {
262 178
                assert(f->b <= f->e);
263 178
                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 216
format_string(const struct format *format)
272
{
273
274 216
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
275 216
        AN(format->string);
276 216
        AZ(VSB_cat(CTX.vsb, format->string));
277 216
        return (1);
278
}
279
280
static int v_matchproto_(format_f)
281 18
format_strptr(const struct format *format)
282
{
283
284 18
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
285 18
        AN(format->strptr);
286 18
        AN(*format->strptr);
287 18
        AZ(VSB_cat(CTX.vsb, *format->strptr));
288 18
        return (1);
289
}
290
291
static int v_matchproto_(format_f)
292 6
format_int32(const struct format *format)
293
{
294
295 6
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
296 6
        VSB_printf(CTX.vsb, "%" PRIi32, *format->int32);
297 6
        return (1);
298
}
299
300
static int v_matchproto_(format_f)
301 164
format_fragment(const struct format *format)
302
{
303
304 164
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
305 164
        AN(format->frag);
306
307 164
        if (format->frag->gen != CTX.gen) {
308 44
                if (format->string == NULL)
309 0
                        return (-1);
310 44
                AZ(vsb_esc_cat(CTX.vsb, format->string,
311
                    format->string + strlen(format->string)));
312 44
                return (0);
313
        }
314 120
        AZ(vsb_fcat(CTX.vsb, format->frag, NULL));
315 120
        return (1);
316
}
317
318
static int v_matchproto_(format_f)
319 30
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 30
        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
328 30
        if (CTX.frag[F_tstart].gen == CTX.gen) {
329 30
                t_start = strtod(CTX.frag[F_tstart].b, &p);
330 30
                if (p != CTX.frag[F_tstart].e)
331 0
                        t_start = NAN;
332
        } else
333 0
                t_start = NAN;
334 30
        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 30
        if (CTX.frag[F_tend].gen == CTX.gen) {
344 30
                t_end = strtod(CTX.frag[F_tend].b, &p);
345 30
                if (p != CTX.frag[F_tend].e)
346 0
                        t_end = t_start;
347
        } else
348 0
                t_end = t_start;
349
350 30
        switch (format->time_type) {
351
        case 'D':
352 6
                AZ(VSB_printf(CTX.vsb, "%d",
353
                    (int)((t_end - t_start) * 1e6)));
354 6
                break;
355
        case 't':
356 18
                AN(format->time_fmt);
357 18
                t = t_start;
358 18
                localtime_r(&t, &tm);
359 18
                strftime(buf, sizeof buf, format->time_fmt, &tm);
360 18
                AZ(VSB_cat(CTX.vsb, buf));
361 18
                break;
362
        case 'T':
363 6
                AZ(VSB_printf(CTX.vsb, "%d", (int)(t_end - t_start)));
364 6
                break;
365
        default:
366 0
                WRONG("Time format specifier");
367
        }
368
369 30
        return (1);
370
}
371
372
static int v_matchproto_(format_f)
373 12
format_requestline(const struct format *format)
374
{
375
376
        (void)format;
377 12
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_m], "-"));
378 12
        AZ(VSB_putc(CTX.vsb, ' '));
379 12
        if (CTX.frag[F_host].gen == CTX.gen) {
380 10
                if (strncmp(CTX.frag[F_host].b, "http://", 7))
381 10
                        AZ(VSB_cat(CTX.vsb, "http://"));
382 10
                AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_host], NULL));
383
        } else
384 2
                AZ(VSB_cat(CTX.vsb, "http://localhost"));
385 12
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_U], ""));
386 12
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_q], ""));
387 12
        AZ(VSB_putc(CTX.vsb, ' '));
388 12
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_H], "HTTP/1.0"));
389 12
        return (1);
390
}
391
392
static int v_matchproto_(format_f)
393 14
format_auth(const struct format *format)
394
{
395
        char buf[128];
396
        char *q;
397
398 20
        if (CTX.frag[F_auth].gen != CTX.gen ||
399 6
            VB64_decode(buf, sizeof buf, CTX.frag[F_auth].b,
400
            CTX.frag[F_auth].e)) {
401 8
                if (format->string == NULL)
402 0
                        return (-1);
403 8
                AZ(vsb_esc_cat(CTX.vsb, format->string,
404
                    format->string + strlen(format->string)));
405 8
                return (0);
406
        }
407 6
        q = strchr(buf, ':');
408 6
        if (q != NULL)
409 6
                *q = '\0';
410 6
        AZ(vsb_esc_cat(CTX.vsb, buf, buf + strlen(buf)));
411 6
        return (1);
412
}
413
414
static int
415 46
print(void)
416
{
417
        const struct format *f;
418 46
        int i, r = 1;
419
420 46
        VSB_clear(CTX.vsb);
421 506
        VTAILQ_FOREACH(f, &CTX.format, list) {
422 460
                CHECK_OBJ_NOTNULL(f, FORMAT_MAGIC);
423 460
                i = (f->func)(f);
424 460
                if (r > i)
425 24
                        r = i;
426
        }
427 46
        AZ(VSB_putc(CTX.vsb, '\n'));
428 46
        AZ(VSB_finish(CTX.vsb));
429 46
        if (r >= 0) {
430 46
                i = fwrite(VSB_data(CTX.vsb), 1, VSB_len(CTX.vsb), CTX.fo);
431 46
                if (i != VSB_len(CTX.vsb))
432 0
                        return (-5);
433
        }
434 46
        return (0);
435
}
436
437
static void
438 128
addf_string(const char *str)
439
{
440
        struct format *f;
441
442 128
        AN(str);
443 128
        ALLOC_OBJ(f, FORMAT_MAGIC);
444 128
        AN(f);
445 128
        f->func = format_string;
446 128
        f->string = strdup(str);
447 128
        AN(f->string);
448 128
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
449 128
}
450
451
static void
452 6
addf_strptr(const char *const *strptr)
453
{
454
        struct format *f;
455
456 6
        AN(strptr);
457 6
        ALLOC_OBJ(f, FORMAT_MAGIC);
458 6
        AN(f);
459 6
        f->func = format_strptr;
460 6
        f->strptr = strptr;
461 6
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
462 6
}
463
464
static void
465 62
addf_fragment(struct fragment *frag, const char *str)
466
{
467
        struct format *f;
468
469 62
        AN(frag);
470 62
        ALLOC_OBJ(f, FORMAT_MAGIC);
471 62
        AN(f);
472 62
        f->func = format_fragment;
473 62
        f->frag = frag;
474 62
        if (str != NULL) {
475 62
                f->string = strdup(str);
476 62
                AN(f->string);
477
        }
478 62
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
479 62
}
480
481
static void
482 2
addf_int32(int32_t *i)
483
{
484
        struct format *f;
485
486 2
        AN(i);
487 2
        ALLOC_OBJ(f, FORMAT_MAGIC);
488 2
        AN(f);
489 2
        f->func = format_int32;
490 2
        f->int32 = i;
491 2
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
492 2
}
493
494
static void
495 16
addf_time(char type, const char *fmt)
496
{
497
        struct format *f;
498
499 16
        ALLOC_OBJ(f, FORMAT_MAGIC);
500 16
        AN(f);
501 16
        f->func = format_time;
502 16
        f->time_type = type;
503 16
        if (fmt != NULL) {
504 12
                f->time_fmt = strdup(fmt);
505 12
                AN(f->time_fmt);
506
        }
507 16
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
508 16
}
509
510
static void
511 14
addf_requestline(void)
512
{
513
        struct format *f;
514
515 14
        ALLOC_OBJ(f, FORMAT_MAGIC);
516 14
        AN(f);
517 14
        f->func = format_requestline;
518 14
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
519 14
}
520
521
static void
522 2
addf_vcl_log(const char *key)
523
{
524
        struct watch *w;
525
        struct format *f;
526
527 2
        AN(key);
528 2
        ALLOC_OBJ(w, WATCH_MAGIC);
529 2
        AN(w);
530 2
        w->keylen = asprintf(&w->key, "%s:", key);
531 2
        assert(w->keylen > 0);
532 2
        VTAILQ_INSERT_TAIL(&CTX.watch_vcl_log, w, list);
533
534 2
        ALLOC_OBJ(f, FORMAT_MAGIC);
535 2
        AN(f);
536 2
        f->func = format_fragment;
537 2
        f->frag = &w->frag;
538 2
        f->string = strdup("");
539 2
        AN(f->string);
540 2
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
541 2
}
542
543
static void
544 26
addf_hdr(struct watch_head *head, const char *key)
545
{
546
        struct watch *w;
547
        struct format *f;
548
549 26
        AN(head);
550 26
        AN(key);
551 26
        ALLOC_OBJ(w, WATCH_MAGIC);
552 26
        AN(w);
553 26
        w->keylen = asprintf(&w->key, "%s:", key);
554 26
        assert(w->keylen > 0);
555 26
        VTAILQ_INSERT_TAIL(head, w, list);
556
557 26
        ALLOC_OBJ(f, FORMAT_MAGIC);
558 26
        AN(f);
559 26
        f->func = format_fragment;
560 26
        f->frag = &w->frag;
561 26
        f->string = strdup("-");
562 26
        AN(f->string);
563 26
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
564 26
}
565
566
static void
567 10
addf_vsl(enum VSL_tag_e tag, long i, const char *prefix)
568
{
569
        struct vsl_watch *w;
570
571 10
        ALLOC_OBJ(w, VSL_WATCH_MAGIC);
572 10
        AN(w);
573 10
        if (VSL_tagflags[tag])
574 0
                VUT_Error(vut, 1, "Tag %s can contain control characters",
575
                    VSL_tags[tag]);
576 10
        w->tag = tag;
577 10
        assert(i <= INT_MAX);
578 10
        w->idx = i;
579 10
        if (prefix != NULL) {
580 6
                w->prefixlen = asprintf(&w->prefix, "%s:", prefix);
581 6
                assert(w->prefixlen > 0);
582
        }
583 10
        VTAILQ_INSERT_TAIL(&CTX.watch_vsl, w, list);
584 10
        addf_fragment(&w->frag, "-");
585 10
}
586
587
static void
588 12
addf_auth(void)
589
{
590
        struct format *f;
591
592 12
        ALLOC_OBJ(f, FORMAT_MAGIC);
593 12
        AN(f);
594 12
        f->func = format_auth;
595 12
        f->string = strdup("-");
596 12
        AN(f->string);
597 12
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
598 12
}
599
600
static void
601 42
parse_x_format(char *buf)
602
{
603
        char *e, *r, *s;
604
        long lval;
605
        int slt;
606
607 42
        if (!strcmp(buf, "Varnish:time_firstbyte")) {
608 2
                addf_fragment(&CTX.frag[F_ttfb], "");
609 2
                return;
610
        }
611 40
        if (!strcmp(buf, "Varnish:hitmiss")) {
612 2
                addf_strptr(&CTX.hitmiss);
613 2
                return;
614
        }
615 38
        if (!strcmp(buf, "Varnish:handling")) {
616 2
                addf_strptr(&CTX.handling);
617 2
                return;
618
        }
619 36
        if (!strcmp(buf, "Varnish:side")) {
620 2
                addf_strptr(&CTX.side);
621 2
                return;
622
        }
623 34
        if (!strcmp(buf, "Varnish:vxid")) {
624 2
                addf_int32(&CTX.vxid);
625 2
                return;
626
        }
627 32
        if (!strncmp(buf, "VCL_Log:", 8)) {
628 2
                addf_vcl_log(buf + 8);
629 2
                return;
630
        }
631 30
        if (!strncmp(buf, "VSL:", 4)) {
632 28
                buf += 4;
633 28
                e = buf;
634 306
                while (*e != '\0')
635 250
                        e++;
636 28
                if (e == buf)
637 2
                        VUT_Error(vut, 1, "Missing tag in VSL:");
638 26
                if (e[-1] == ']') {
639 12
                        r = e - 1;
640 76
                        while (r > buf && *r != '[')
641 52
                                r--;
642 12
                        if (r == buf || r[1] == ']')
643 2
                                VUT_Error(vut, 1, "Syntax error: VSL:%s", buf);
644 10
                        e[-1] = '\0';
645 10
                        lval = strtol(r + 1, &s, 10);
646 10
                        if (s != e - 1)
647 2
                                VUT_Error(vut, 1, "Syntax error: VSL:%s]", buf);
648 8
                        if (lval <= 0 || lval > 255) {
649 4
                                VUT_Error(vut, 1,
650
                                    "Syntax error. Field specifier must be"
651
                                    " between 1 and 255: %s]",
652
                                    buf);
653
                        }
654 4
                        *r = '\0';
655
                } else
656 14
                        lval = 0;
657 18
                r = buf;
658 170
                while (r < e && *r != ':')
659 134
                        r++;
660 18
                if (r != e) {
661 6
                        slt = VSL_Name2Tag(buf, r - buf);
662 6
                        r++;
663
                } else {
664 12
                        slt = VSL_Name2Tag(buf, -1);
665 12
                        r = NULL;
666
                }
667 18
                if (slt == -2)
668 2
                        VUT_Error(vut, 1, "Tag not unique: %s", buf);
669 16
                if (slt == -1)
670 6
                        VUT_Error(vut, 1, "Unknown log tag: %s", buf);
671 10
                assert(slt >= 0);
672
673 10
                addf_vsl(slt, lval, r);
674 10
                return;
675
        }
676 2
        VUT_Error(vut, 1, "Unknown formatting extension: %s", buf);
677
}
678
679
static void
680 56
parse_format(const char *format)
681
{
682
        const char *p, *q;
683
        struct vsb *vsb;
684
        char buf[256];
685
686 56
        if (format == NULL)
687 8
                format = FORMAT;
688
689 56
        vsb = VSB_new_auto();
690 56
        AN(vsb);
691
692 374
        for (p = format; *p != '\0'; p++) {
693
694
                /* Allow the most essential escape sequences in format */
695 344
                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 344
                if (*p != '%') {
706 168
                        AZ(VSB_putc(vsb, *p));
707 168
                        continue;
708
                }
709
710 176
                if (VSB_len(vsb) > 0) {
711 120
                        AZ(VSB_finish(vsb));
712 120
                        addf_string(VSB_data(vsb));
713 120
                        VSB_clear(vsb);
714
                }
715
716 176
                p++;
717 176
                switch (*p) {
718
                case 'b':       /* Body bytes sent */
719 14
                        addf_fragment(&CTX.frag[F_b], "-");
720 14
                        break;
721
                case 'D':       /* Float request time */
722 2
                        addf_time(*p, NULL);
723 2
                        break;
724
                case 'h':       /* Client host name / IP Address */
725 14
                        addf_fragment(&CTX.frag[F_h], "-");
726 14
                        break;
727
                case 'H':       /* Protocol */
728 2
                        addf_fragment(&CTX.frag[F_H], "HTTP/1.0");
729 2
                        break;
730
                case 'I':       /* Bytes received */
731 2
                        addf_fragment(&CTX.frag[F_I], "-");
732 2
                        break;
733
                case 'l':       /* Client user ID (identd) always '-' */
734 10
                        AZ(VSB_putc(vsb, '-'));
735 10
                        break;
736
                case 'm':       /* Method */
737 2
                        addf_fragment(&CTX.frag[F_m], "-");
738 2
                        break;
739
                case 'O':       /* Bytes sent */
740 2
                        addf_fragment(&CTX.frag[F_O], "-");
741 2
                        break;
742
                case 'q':       /* Query string */
743 2
                        addf_fragment(&CTX.frag[F_q], "");
744 2
                        break;
745
                case 'r':       /* Request line */
746 14
                        addf_requestline();
747 14
                        break;
748
                case 's':       /* Status code */
749 10
                        addf_fragment(&CTX.frag[F_s], "-");
750 10
                        break;
751
                case 't':       /* strftime */
752 10
                        addf_time(*p, TIME_FMT);
753 10
                        break;
754
                case 'T':       /* Int request time */
755 2
                        addf_time(*p, NULL);
756 2
                        break;
757
                case 'u':       /* Remote user from auth */
758 12
                        addf_auth();
759 12
                        break;
760
                case 'U':       /* URL */
761 2
                        addf_fragment(&CTX.frag[F_U], "-");
762 2
                        break;
763
                case '{':
764 74
                        p++;
765 74
                        q = p;
766 882
                        while (*q && *q != '}')
767 734
                                q++;
768 74
                        if (!*q)
769 2
                                VUT_Error(vut, 1, "Unmatched bracket at: %s",
770
                                    p - 2);
771 72
                        assert(q - p < sizeof buf - 1);
772 72
                        strncpy(buf, p, q - p);
773 72
                        buf[q - p] = '\0';
774 72
                        q++;
775 72
                        switch (*q) {
776
                        case 'i':
777 24
                                addf_hdr(&CTX.watch_reqhdr, buf);
778 24
                                break;
779
                        case 'o':
780 2
                                addf_hdr(&CTX.watch_resphdr, buf);
781 2
                                break;
782
                        case 't':
783 2
                                addf_time(*q, buf);
784 2
                                break;
785
                        case 'x':
786 42
                                parse_x_format(buf);
787 22
                                break;
788
                        default:
789 2
                                VUT_Error(vut, 1,
790
                                    "Unknown format specifier at: %s",
791
                                    p - 2);
792
                        }
793 50
                        p = q;
794 50
                        break;
795
                default:
796 2
                        VUT_Error(vut, 1, "Unknown format specifier at: %s",
797
                            p - 1);
798
                }
799
        }
800
801 30
        if (VSB_len(vsb) > 0) {
802
                /* Add any remaining static */
803 8
                AZ(VSB_finish(vsb));
804 8
                addf_string(VSB_data(vsb));
805 8
                VSB_clear(vsb);
806
        }
807
808 30
        VSB_destroy(&vsb);
809 30
}
810
811
static int
812 1298
isprefix(const char *prefix, size_t len, const char *b,
813
    const char *e, const char **next)
814
{
815 1298
        assert(len > 0);
816 1298
        if (e - b < len || strncasecmp(b, prefix, len))
817 1068
                return (0);
818 230
        b += len;
819 230
        if (next) {
820 664
                while (b < e && *b == ' ')
821 204
                        b++;
822 230
                *next = b;
823
        }
824 230
        return (1);
825
}
826
827
static void
828 234
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 234
        AN(b);
836 234
        AN(e);
837 234
        va_start(ap, e);
838
839 234
        field = va_arg(ap, int);
840 234
        frag = va_arg(ap, struct fragment *);
841 498
        for (n = 1, q = b; q < e; n++) {
842
                /* caller must sort the fields, or this loop will not work: */
843 498
                assert(field >= n);
844 498
                AN(frag);
845
846 498
                p = q;
847
                /* Skip WS */
848 1260
                while (p < e && isspace(*p))
849 264
                        p++;
850 498
                q = p;
851
                /* Skip non-WS */
852 4832
                while (q < e && !isspace(*q))
853 3836
                        q++;
854
855 498
                if (field == n) {
856 316
                        if (frag->gen != CTX.gen || force) {
857
                                /* We only grab the same matching field once */
858 316
                                frag->gen = CTX.gen;
859 316
                                frag->b = p;
860 316
                                frag->e = q;
861
                        }
862 316
                        field = va_arg(ap, int);
863 316
                        if (field == 0)
864 234
                                break;
865 82
                        frag = va_arg(ap, struct fragment *);
866
                }
867
        }
868 234
        va_end(ap);
869 234
}
870
871
static void
872 308
frag_line(int force, const char *b, const char *e, struct fragment *f)
873
{
874
875 308
        if (f->gen == CTX.gen && !force)
876
                /* We only grab the same matching record once */
877 4
                return;
878
879
        /* Skip leading space */
880 608
        while (b < e && isspace(*b))
881 0
                ++b;
882
883
        /* Skip trailing space */
884 608
        while (e > b && isspace(e[-1]))
885 0
                --e;
886
887 304
        f->gen = CTX.gen;
888 304
        f->b = b;
889 304
        f->e = e;
890
}
891
892
static void
893 338
process_hdr(const struct watch_head *head, const char *b, const char *e)
894
{
895
        struct watch *w;
896
        const char *p;
897
898 454
        VTAILQ_FOREACH(w, head, list) {
899 116
                CHECK_OBJ_NOTNULL(w, WATCH_MAGIC);
900 116
                if (!isprefix(w->key, w->keylen, b, e, &p))
901 100
                        continue;
902 16
                frag_line(1, p, e, &w->frag);
903
        }
904 338
}
905
906
static void
907 1368
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 2248
        VTAILQ_FOREACH(w, head, list) {
914 880
                CHECK_OBJ_NOTNULL(w, VSL_WATCH_MAGIC);
915 880
                if (tag != w->tag)
916 790
                        continue;
917 90
                p = b;
918 168
                if (w->prefixlen > 0 &&
919 78
                    !isprefix(w->prefix, w->prefixlen, b, e, &p))
920 70
                        continue;
921 20
                if (w->idx == 0)
922 10
                        frag_line(0, p, e, &w->frag);
923
                else
924 10
                        frag_fields(0, p, e, w->idx, &w->frag, 0, NULL);
925
        }
926 1368
}
927
928
static int v_matchproto_(VSLQ_dispatch_f)
929 120
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 240
        for (t = pt[0]; t != NULL; t = *++pt) {
945 120
                CTX.gen++;
946
947
                /* Consider client requests only if in client mode.
948
                   Consider backend requests only if in backend mode. */
949 120
                if (t->type == VSL_t_req && CTX.c_opt) {
950 38
                        CTX.side = "c";
951 38
                        be_mark = 0;
952 82
                } else if (t->type == VSL_t_bereq && CTX.b_opt) {
953 8
                        CTX.side = "b";
954 8
                        be_mark = BACKEND_MARKER;
955
                } else
956 74
                        continue;
957 46
                if (t->reason == VSL_r_esi)
958
                        /* Skip ESI requests */
959 0
                        continue;
960 46
                CTX.hitmiss = "-";
961 46
                CTX.handling = "-";
962 46
                CTX.vxid = t->vxid;
963 46
                skip = 0;
964 1460
                while (skip == 0 && 1 == VSL_Next(t->c)) {
965 1368
                        tag = VSL_TAG(t->c->rec.ptr);
966 1368
                        if (VSL_tagflags[tag])
967 0
                                continue;
968
969 1368
                        b = VSL_CDATA(t->c->rec.ptr);
970 1368
                        e = b + VSL_LEN(t->c->rec.ptr);
971 4104
                        while (e > b && e[-1] == '\0')
972 1368
                                e--;
973
974 1368
                        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 10
                                frag_fields(0, b, e,
981
                                    3, &CTX.frag[F_I],
982
                                    4, &CTX.frag[F_O],
983
                                    0, NULL);
984 10
                                break;
985
                        case (SLT_BackendStart + BACKEND_MARKER):
986 8
                                frag_fields(1, b, e,
987
                                    1, &CTX.frag[F_h],
988
                                    0, NULL);
989 8
                                break;
990
                        case SLT_ReqStart:
991 38
                                frag_fields(0, b, e,
992
                                    1, &CTX.frag[F_h],
993
                                    0, NULL);
994 38
                                break;
995
                        case (SLT_BereqMethod + BACKEND_MARKER):
996
                        case SLT_ReqMethod:
997 46
                                frag_line(0, b, e, &CTX.frag[F_m]);
998 46
                                break;
999
                        case (SLT_BereqURL + BACKEND_MARKER):
1000
                        case SLT_ReqURL:
1001 46
                                p = memchr(b, '?', e - b);
1002 46
                                if (p == NULL)
1003 24
                                        p = e;
1004 46
                                frag_line(0, b, p, &CTX.frag[F_U]);
1005 46
                                frag_line(0, p, e, &CTX.frag[F_q]);
1006 46
                                break;
1007
                        case (SLT_BereqProtocol + BACKEND_MARKER):
1008
                        case SLT_ReqProtocol:
1009 50
                                frag_line(0, b, e, &CTX.frag[F_H]);
1010 50
                                break;
1011
                        case (SLT_BerespStatus + BACKEND_MARKER):
1012
                        case SLT_RespStatus:
1013 34
                                frag_line(1, b, e, &CTX.frag[F_s]);
1014 34
                                break;
1015
                        case (SLT_BereqAcct + BACKEND_MARKER):
1016
                        case SLT_ReqAcct:
1017 36
                                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 36
                                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 196
                                if (ISPREFIX("Start:", b, e, &p)) {
1027 44
                                        frag_fields(0, p, e, 1,
1028
                                            &CTX.frag[F_tstart], 0, NULL);
1029
1030 276
                                } else if (ISPREFIX("Resp:", b, e, &p) ||
1031 238
                                    ISPREFIX("PipeSess:", b, e, &p) ||
1032 114
                                    ISPREFIX("BerespBody:", b, e, &p)) {
1033 44
                                        frag_fields(0, p, e, 1,
1034
                                            &CTX.frag[F_tend], 0, NULL);
1035
1036 188
                                } else if (ISPREFIX("Process:", b, e, &p) ||
1037 150
                                    ISPREFIX("Pipe:", b, e, &p) ||
1038 70
                                    ISPREFIX("Beresp:", b, e, &p)) {
1039 44
                                        frag_fields(0, p, e, 2,
1040
                                            &CTX.frag[F_ttfb], 0, NULL);
1041
                                }
1042 196
                                break;
1043
                        case (SLT_BereqHeader + BACKEND_MARKER):
1044
                        case SLT_ReqHeader:
1045 146
                                if (ISPREFIX("Authorization:", b, e, &p) &&
1046 16
                                    ISPREFIX("basic ", p, e, &p))
1047 16
                                        frag_line(0, p, e,
1048
                                            &CTX.frag[F_auth]);
1049 114
                                else if (ISPREFIX("Host:", b, e, &p))
1050 42
                                        frag_line(0, p, e,
1051
                                            &CTX.frag[F_host]);
1052
#undef ISPREFIX
1053 130
                                break;
1054
                        case SLT_VCL_call:
1055 132
                                if (!strcasecmp(b, "recv")) {
1056 38
                                        CTX.hitmiss = "-";
1057 38
                                        CTX.handling = "-";
1058 94
                                } else if (!strcasecmp(b, "hit")) {
1059 10
                                        CTX.hitmiss = "hit";
1060 10
                                        CTX.handling = "hit";
1061 84
                                } else if (!strcasecmp(b, "miss")) {
1062 14
                                        CTX.hitmiss = "miss";
1063 14
                                        CTX.handling = "miss";
1064 70
                                } else if (!strcasecmp(b, "pass")) {
1065 4
                                        CTX.hitmiss = "miss";
1066 4
                                        CTX.handling = "pass";
1067 66
                                } else if (!strcasecmp(b, "synth")) {
1068
                                        /* Arguably, synth isn't a hit or
1069
                                           a miss, but miss is less
1070
                                           wrong */
1071 10
                                        CTX.hitmiss = "miss";
1072 10
                                        CTX.handling = "synth";
1073
                                }
1074 132
                                break;
1075
                        case SLT_VCL_return:
1076 132
                                if (!strcasecmp(b, "pipe")) {
1077 10
                                        CTX.hitmiss = "miss";
1078 10
                                        CTX.handling = "pipe";
1079 122
                                } else if (!strcasecmp(b, "restart"))
1080 0
                                        skip = 1;
1081 132
                                break;
1082
                        case (SLT_VCL_Log + BACKEND_MARKER):
1083
                        case SLT_VCL_Log:
1084 12
                                VTAILQ_FOREACH(w, &CTX.watch_vcl_log, list) {
1085 2
                                        CHECK_OBJ_NOTNULL(w, WATCH_MAGIC);
1086 4
                                        if (e - b < w->keylen ||
1087 2
                                            strncmp(b, w->key, w->keylen))
1088 0
                                                continue;
1089 2
                                        p = b + w->keylen;
1090 2
                                        frag_line(0, p, e, &w->frag);
1091
                                }
1092 10
                                break;
1093
                        default:
1094 500
                                break;
1095
                        }
1096
1097 1368
                        if ((tag == SLT_ReqHeader && CTX.c_opt) ||
1098 34
                            (tag == SLT_BereqHeader && CTX.b_opt))
1099 130
                                process_hdr(&CTX.watch_reqhdr, b, e);
1100 1238
                        else if ((tag == SLT_RespHeader && CTX.c_opt) ||
1101 12
                            (tag == SLT_BerespHeader && CTX.b_opt))
1102 208
                                process_hdr(&CTX.watch_resphdr, b, e);
1103
1104 1368
                        process_vsl(&CTX.watch_vsl, tag, b, e);
1105
                }
1106 46
                if (skip)
1107 0
                        continue;
1108 46
                i = print();
1109 46
                if (i)
1110 0
                        return (i);
1111
        }
1112
1113 120
        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 8
vut_sighandler(int sig)
1125
{
1126
1127 8
        if (vut != NULL)
1128 8
                VUT_Signaled(vut, sig);
1129 8
}
1130
1131
static char *
1132 6
read_format(const char *formatfile)
1133
{
1134
        FILE *fmtfile;
1135 6
        size_t len = 0;
1136
        int fmtlen;
1137 6
        char *fmt = NULL;
1138
1139 6
        fmtfile = fopen(formatfile, "r");
1140 6
        if (fmtfile == NULL)
1141 2
                VUT_Error(vut, 1, "Can't open format file (%s)",
1142 2
                    strerror(errno));
1143 4
        AN(fmtfile);
1144 4
        fmtlen = getline(&fmt, &len, fmtfile);
1145 4
        if (fmtlen == -1) {
1146 2
                free(fmt);
1147 2
                if (feof(fmtfile))
1148 2
                        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 2
        fclose(fmtfile);
1153 2
        if (fmt[fmtlen - 1] == '\n')
1154 2
                fmt[fmtlen - 1] = '\0';
1155 2
        return (fmt);
1156
}
1157
1158
int
1159 74
main(int argc, char * const *argv)
1160
{
1161
        signed char opt;
1162 74
        char *format = NULL;
1163
1164 74
        vut = VUT_InitProg(argc, argv, &vopt_spec);
1165 70
        AN(vut);
1166 70
        memset(&CTX, 0, sizeof CTX);
1167 70
        VTAILQ_INIT(&CTX.format);
1168 70
        VTAILQ_INIT(&CTX.watch_vcl_log);
1169 70
        VTAILQ_INIT(&CTX.watch_reqhdr);
1170 70
        VTAILQ_INIT(&CTX.watch_resphdr);
1171 70
        VTAILQ_INIT(&CTX.watch_vsl);
1172 70
        CTX.vsb = VSB_new_auto();
1173 70
        AN(CTX.vsb);
1174 70
        VB64_init();
1175
1176 70
        while ((opt = getopt(argc, argv, vopt_spec.vopt_optstring)) != -1) {
1177 138
                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 6
                        CTX.b_opt = 1;
1185 6
                        break;
1186
                case 'c':
1187
                        /* client mode */
1188 6
                        CTX.c_opt = 1;
1189 6
                        break;
1190
                case 'F':
1191
                        /* Format string */
1192 46
                        if (format != NULL)
1193 0
                                free(format);
1194 46
                        format = strdup(optarg);
1195 46
                        AN(format);
1196 46
                        break;
1197
                case 'f':
1198
                        /* Format string from file */
1199 6
                        if (format != NULL)
1200 0
                                free(format);
1201 6
                        format = read_format(optarg);
1202 2
                        AN(format);
1203 2
                        break;
1204
                case 'h':
1205
                        /* Usage help */
1206 2
                        usage(0);
1207
                        break;
1208
                case 'w':
1209
                        /* Write to file */
1210 8
                        REPLACE(CTX.w_arg, optarg);
1211 8
                        break;
1212
                default:
1213 64
                        if (!VUT_Arg(vut, opt, optarg))
1214 0
                                usage(1);
1215
                }
1216
        }
1217
        /* default is client mode: */
1218 62
        if (!CTX.b_opt)
1219 56
                CTX.c_opt = 1;
1220
1221 62
        if (optind != argc)
1222 2
                usage(1);
1223
1224 60
        if (vut->D_opt && !CTX.w_arg)
1225 2
                VUT_Error(vut, 1, "Missing -w option");
1226
1227
        /* Check for valid grouping mode */
1228 58
        assert(vut->g_arg < VSL_g__MAX);
1229 58
        if (vut->g_arg != VSL_g_vxid && vut->g_arg != VSL_g_request)
1230 2
                VUT_Error(vut, 1, "Invalid grouping mode: %s",
1231 2
                    VSLQ_grouping[vut->g_arg]);
1232
1233
        /* Prepare output format */
1234 56
        parse_format(format);
1235 30
        free(format);
1236 30
        format = NULL;
1237
1238
        /* Setup output */
1239 30
        vut->dispatch_f = dispatch_f;
1240 30
        vut->dispatch_priv = NULL;
1241 30
        vut->sighup_f = sighup;
1242 30
        if (CTX.w_arg) {
1243 8
                openout(CTX.a_opt);
1244 6
                AN(CTX.fo);
1245 6
                if (vut->D_opt)
1246 2
                        vut->sighup_f = rotateout;
1247
        } else
1248 22
                CTX.fo = stdout;
1249 28
        vut->idle_f = flushout;
1250
1251 28
        VUT_Signal(vut_sighandler);
1252 28
        VUT_Setup(vut);
1253 28
        VUT_Main(vut);
1254 28
        VUT_Fini(&vut);
1255
1256 28
        exit(0);
1257
}