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