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