GCOV - Varnish Cache


/*-
 * Copyright (c) 2006 Verdens Gang AS
 * Copyright (c) 2006-2016 Varnish Software AS
 * All rights reserved.
 *
 * Author: Anders Berg <andersb@vgnett.no>
 * Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
 * Author: Tollef Fog Heen <tfheen@varnish-software.com>
 * Author: Martin Blix Grydeland <mbgrydeland@varnish-software.com>
 *
 * SPDX-License-Identifier: BSD-2-Clause
 *
 * Redistribution and use in source and binary forms, with or without
 * modification, are permitted provided that the following conditions
 * are met:
 * 1. Redistributions of source code must retain the above copyright
 *    notice, this list of conditions and the following disclaimer.
 * 2. Redistributions in binary form must reproduce the above copyright
 *    notice, this list of conditions and the following disclaimer in the
 *    documentation and/or other materials provided with the distribution.
 *
 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
 * ARE DISCLAIMED.  IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
 * SUCH DAMAGE.
 *
 * Obtain log data from the shared memory log, order it by session ID, and
 * display it in Apache / NCSA combined log format.
 *
 * See doc/sphinx/reference/varnishncsa.rst for the supported format
 * specifiers.
 *
 */

#include "config.h"

#include <stdlib.h>
#include <stdio.h>
#include <unistd.h>
#include <string.h>
#include <signal.h>
#include <stdarg.h>
#include <inttypes.h>
#include <limits.h>
#include <ctype.h>
#include <time.h>
#include <math.h>

#define VOPT_DEFINITION
#define VOPT_INC "varnishncsa_options.h"

#include "vdef.h"

#include "vapi/vsl.h"
#include "vapi/voptget.h"
#include "vas.h"
#include "venc.h"
#include "vsb.h"
#include "vut.h"
#include "vqueue.h"
#include "miniobj.h"

#define TIME_FMT "[%d/%b/%Y:%T %z]"
#define FORMAT "%h %l %u %t \"%r\" %s %b \"%{Referer}i\" \"%{User-agent}i\""

static struct VUT *vut;

struct format;

enum e_frag {
        F_H,                    /* %H Proto */
        F_U,                    /* %U URL path */
        F_q,                    /* %q Query string */
        F_b,                    /* %b Body bytes sent */
        F_h,                    /* %h Host name / IP Address */
        F_m,                    /* %m Method */
        F_s,                    /* %s Status */
        F_I,                    /* %I Bytes received */
        F_O,                    /* %O Bytes sent */
        F_tstart,               /* Time start */
        F_tend,                 /* Time end */
        F_ttfb,                 /* %{Varnish:time_firstbyte}x */
        F_host,                 /* Host header */
        F_auth,                 /* Authorization header */
        F__MAX,
};

struct fragment {
        uint64_t                gen;
        const char              *b, *e;
};

typedef int format_f(const struct format *format);

struct format {
        unsigned                magic;
#define FORMAT_MAGIC            0xC3119CDA

        char                    time_type;
        VTAILQ_ENTRY(format)    list;
        format_f                *func;
        struct fragment         *frag;
        char                    *string;
        const char *const       *strptr;
        char                    *time_fmt;
        int64_t                 *int64;
};

struct watch {
        unsigned                magic;
#define WATCH_MAGIC             0xA7D4005C

        VTAILQ_ENTRY(watch)     list;
        char                    *key;
        int                     keylen;
        struct fragment         frag;
};
VTAILQ_HEAD(watch_head, watch);

struct vsl_watch {
        unsigned                magic;
#define VSL_WATCH_MAGIC         0xE3E27D23

        VTAILQ_ENTRY(vsl_watch) list;
        enum VSL_tag_e          tag;
        int                     idx;
        char                    *prefix;
        int                     prefixlen;
        struct fragment         frag;
};
VTAILQ_HEAD(vsl_watch_head, vsl_watch);

static struct ctx {
        /* Options */
        int                     a_opt;
        char                    *w_arg;

        FILE                    *fo;
        struct vsb              *vsb;
        uint64_t                gen;
        VTAILQ_HEAD(,format)    format;
        int                     quote_how;
        char                    *missing_string;
        char                    *missing_int;

        /* State */
        struct watch_head       watch_vcl_log;
        struct watch_head       watch_reqhdr; /* also bereqhdr */
        struct watch_head       watch_resphdr; /* also beresphdr */
        struct vsl_watch_head   watch_vsl;
        struct fragment         frag[F__MAX];
        const char              *hitmiss;
        const char              *handling;
        const char              *side;
        int64_t                 vxid;
} CTX;

static void parse_format(const char *format);

static void
openout(int append)
{

        AN(CTX.w_arg);
        if (!strcmp(CTX.w_arg, "-"))
                CTX.fo = stdout;
        else
                CTX.fo = fopen(CTX.w_arg, append ? "a" : "w");
        if (CTX.fo == NULL)
                VUT_Error(vut, 1, "Can't open output file (%s)",
                    strerror(errno));
}

static int v_matchproto_(VUT_cb_f)
rotateout(struct VUT *v)
{

        assert(v == vut);
        AN(CTX.w_arg);
        AN(CTX.fo);
        (void)fclose(CTX.fo);
        openout(1);
        AN(CTX.fo);
        return (0);
}

static int v_matchproto_(VUT_cb_f)
flushout(struct VUT *v)
{

        assert(v == vut);
        AN(CTX.fo);
        if (fflush(CTX.fo))
                return (-5);
        return (0);
}

static inline int
vsb_fcat(struct vsb *vsb, const struct fragment *f, const char *dflt)
{
        if (f->gen == CTX.gen) {
                assert(f->b <= f->e);
                VSB_quote(vsb, f->b, f->e - f->b, CTX.quote_how);
        } else if (dflt)
                VSB_quote(vsb, dflt, -1, CTX.quote_how);
        else
                return (-1);
        return (0);
}

static int v_matchproto_(format_f)
format_string(const struct format *format)
{

        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
        AN(format->string);
        AZ(VSB_cat(CTX.vsb, format->string));
        return (1);
}

static int v_matchproto_(format_f)
format_strptr(const struct format *format)
{

        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
        AN(format->strptr);
        AN(*format->strptr);
        AZ(VSB_cat(CTX.vsb, *format->strptr));
        return (1);
}

static int v_matchproto_(format_f)
format_int64(const struct format *format)
{

        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
        VSB_printf(CTX.vsb, "%jd", (intmax_t)*format->int64);
        return (1);
}

static int v_matchproto_(format_f)
format_fragment(const struct format *format)
{

        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
        AN(format->frag);

        if (format->frag->gen != CTX.gen) {
                if (format->string == NULL)
                        return (-1);
                VSB_quote(CTX.vsb, format->string, -1, CTX.quote_how);
                return (0);
        }
        AZ(vsb_fcat(CTX.vsb, format->frag, NULL));
        return (1);
}

static int v_matchproto_(format_f)
format_time(const struct format *format)
{
        double t_start, t_end, d;
        char *p;
        char buf[64];
        time_t t;
        intmax_t l;
        struct tm tm;

        CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
        if (CTX.frag[F_tstart].gen == CTX.gen) {
                t_start = strtod(CTX.frag[F_tstart].b, &p);
                if (p != CTX.frag[F_tstart].e)
                        t_start = NAN;
        } else
                t_start = NAN;
        if (isnan(t_start)) {
                /* Missing t_start is a no go */
                if (format->string == NULL)
                        return (-1);
                AZ(VSB_cat(CTX.vsb, format->string));
                return (0);
        }

        /* Missing t_end defaults to t_start */
        if (CTX.frag[F_tend].gen == CTX.gen) {
                t_end = strtod(CTX.frag[F_tend].b, &p);
                if (p != CTX.frag[F_tend].e)
                        t_end = t_start;
        } else
                t_end = t_start;

        AN(format->time_fmt);

        switch (format->time_type) {
        case 't':
                t = (intmax_t)floor(t_start);
                (void)localtime_r(&t, &tm);
                AN(strftime(buf, sizeof buf, format->time_fmt, &tm));
                AZ(VSB_cat(CTX.vsb, buf));
                return (1);
        case '3':
                l = (intmax_t)(modf(t_start, &d) * 1e3);
                break;
        case '6':
                l = (intmax_t)(modf(t_start, &d) * 1e6);
                break;
        case 'S':
                l = (intmax_t)t_start;
                break;
        case 'M':
                l = (intmax_t)(t_start * 1e3);
                break;
        case 'U':
                l = (intmax_t)(t_start * 1e6);
                break;
        case 's':
                l = (intmax_t)(t_end - t_start);
                break;
        case 'm':
                l = (intmax_t)((t_end - t_start) * 1e3);
                break;
        case 'u':
                l = (intmax_t)((t_end - t_start) * 1e6);
                break;
        default:
                WRONG("Time format specifier");
        }

#ifdef __FreeBSD__
        assert(fmtcheck(format->time_fmt, "%jd") == format->time_fmt);
#endif
        AZ(VSB_printf(CTX.vsb, format->time_fmt, l));

        return (1);
}

static int v_matchproto_(format_f)
format_requestline(const struct format *format)
{

        (void)format;
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_m], "-"));
        AZ(VSB_putc(CTX.vsb, ' '));
        if (CTX.frag[F_host].gen == CTX.gen) {
                if (strncmp(CTX.frag[F_host].b, "http://", 7))
                        AZ(VSB_cat(CTX.vsb, "http://"));
                AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_host], NULL));
        } else
                AZ(VSB_cat(CTX.vsb, "http://localhost"));
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_U], ""));
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_q], ""));
        AZ(VSB_putc(CTX.vsb, ' '));
        AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_H], "HTTP/1.0"));
        return (1);
}

static int v_matchproto_(format_f)
format_auth(const struct format *format)
{
        struct vsb *vsb = VSB_new_auto();
        AN(vsb);
        char *q;

        if (CTX.frag[F_auth].gen != CTX.gen ||
            VENC_Decode_Base64(vsb, CTX.frag[F_auth].b, CTX.frag[F_auth].e)) {
                VSB_destroy(&vsb);
                if (format->string == NULL)
                        return (-1);
                VSB_quote(CTX.vsb, format->string, -1, CTX.quote_how);
                return (0);
        }
        AZ(VSB_finish(vsb));
        q = strchr(VSB_data(vsb), ':');
        if (q != NULL)
                *q = '\0';
        VSB_quote(CTX.vsb, VSB_data(vsb), -1, CTX.quote_how);
        VSB_destroy(&vsb);
        return (1);
}

static int
print(void)
{
        const struct format *f;
        int i, r = 1;

        VSB_clear(CTX.vsb);
        VTAILQ_FOREACH(f, &CTX.format, list) {
                CHECK_OBJ_NOTNULL(f, FORMAT_MAGIC);
                i = (f->func)(f);
                AZ(VSB_error(CTX.vsb));
                if (r > i)
                        r = i;
        }
        AZ(VSB_putc(CTX.vsb, '\n'));
        AZ(VSB_finish(CTX.vsb));
        if (r >= 0) {
                i = fwrite(VSB_data(CTX.vsb), 1, VSB_len(CTX.vsb), CTX.fo);
                if (i != VSB_len(CTX.vsb))
                        return (-5);
        }
        return (0);
}

static void
addf_string(const char *str)
{
        struct format *f;

        AN(str);
        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_string;
        f->string = strdup(str);
        AN(f->string);
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_strptr(const char *const *strptr)
{
        struct format *f;

        AN(strptr);
        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_strptr;
        f->strptr = strptr;
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_fragment(struct fragment *frag, const char *str)
{
        struct format *f;

        AN(frag);
        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_fragment;
        f->frag = frag;
        if (str != NULL) {
                f->string = strdup(str);
                AN(f->string);
        }
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_int64(int64_t *i)
{
        struct format *f;

        AN(i);
        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_int64;
        f->int64 = i;
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_time(char type, const char *fmt)
{
        struct format *f;

        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        AN(fmt);
        f->func = format_time;
        f->time_type = type;
        f->time_fmt = strdup(fmt);

        if (f->time_type == 'T') {
                if (!strcmp(fmt, "s"))
                        f->time_type = 's';
                else if (!strcmp(fmt, "ms"))
                        f->time_type = 'm';
                else if (!strcmp(fmt, "us"))
                        f->time_type = 'u';
                else
                        VUT_Error(vut, 1, "Unknown specifier: %%{%s}T",
                            fmt);
                REPLACE(f->time_fmt, "%jd");
        } else if (f->time_type == 't') {
                if (!strcmp(fmt, "sec")) {
                        f->time_type = 'S';
                        REPLACE(f->time_fmt, "%jd");
                } else if (!strncmp(fmt, "msec", 4)) {
                        fmt += 4;
                        if (!strcmp(fmt, "_frac")) {
                                f->time_type = '3';
                                REPLACE(f->time_fmt, "%03jd");
                        } else if (*fmt == '\0') {
                                f->time_type = 'M';
                                REPLACE(f->time_fmt, "%jd");
                        }
                } else if (!strncmp(fmt, "usec", 4)) {
                        fmt += 4;
                        if (!strcmp(fmt, "_frac")) {
                                f->time_type = '6';
                                REPLACE(f->time_fmt, "%06jd");
                        } else if (*fmt == '\0') {
                                f->time_type = 'U';
                                REPLACE(f->time_fmt, "%jd");
                        }
                }
        }

        AN(f->time_fmt);
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_requestline(void)
{
        struct format *f;

        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_requestline;
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_vcl_log(const char *key)
{
        struct watch *w;
        struct format *f;

        AN(key);
        ALLOC_OBJ(w, WATCH_MAGIC);
        AN(w);
        w->keylen = asprintf(&w->key, "%s:", key);
        assert(w->keylen > 0);
        VTAILQ_INSERT_TAIL(&CTX.watch_vcl_log, w, list);

        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_fragment;
        f->frag = &w->frag;
        f->string = strdup("");
        AN(f->string);
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_hdr(struct watch_head *head, const char *key)
{
        struct watch *w;
        struct format *f;

        AN(head);
        AN(key);
        ALLOC_OBJ(w, WATCH_MAGIC);
        AN(w);
        w->keylen = asprintf(&w->key, "%s:", key);
        assert(w->keylen > 0);
        VTAILQ_INSERT_TAIL(head, w, list);

        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_fragment;
        f->frag = &w->frag;
        f->string = strdup(CTX.missing_string);
        AN(f->string);
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
addf_vsl(enum VSL_tag_e tag, long i, const char *prefix)
{
        struct vsl_watch *w;

        ALLOC_OBJ(w, VSL_WATCH_MAGIC);
        AN(w);
        if (VSL_tagflags[tag] && CTX.quote_how != VSB_QUOTE_JSON)
                VUT_Error(vut, 1, "Tag %s can contain control characters",
                    VSL_tags[tag]);
        w->tag = tag;
        assert(i <= INT_MAX);
        w->idx = i;
        if (prefix != NULL) {
                w->prefixlen = asprintf(&w->prefix, "%s:", prefix);
                assert(w->prefixlen > 0);
        }
        VTAILQ_INSERT_TAIL(&CTX.watch_vsl, w, list);
        addf_fragment(&w->frag, CTX.missing_string);
}

static void
addf_auth(void)
{
        struct format *f;

        ALLOC_OBJ(f, FORMAT_MAGIC);
        AN(f);
        f->func = format_auth;
        f->string = strdup("-");
        AN(f->string);
        VTAILQ_INSERT_TAIL(&CTX.format, f, list);
}

static void
parse_x_format(char *buf)
{
        char *e, *r, *s;
        long lval;
        int slt;

        if (!strcmp(buf, "Varnish:time_firstbyte")) {
                addf_fragment(&CTX.frag[F_ttfb], CTX.missing_int);
                return;
        }
        if (!strcmp(buf, "Varnish:hitmiss")) {
                addf_strptr(&CTX.hitmiss);
                return;
        }
        if (!strcmp(buf, "Varnish:handling")) {
                addf_strptr(&CTX.handling);
                return;
        }
        if (!strcmp(buf, "Varnish:side")) {
                addf_strptr(&CTX.side);
                return;
        }
        if (!strcmp(buf, "Varnish:vxid")) {
                addf_int64(&CTX.vxid);
                return;
        }
        if (!strncmp(buf, "VCL_Log:", 8)) {
                addf_vcl_log(buf + 8);
                return;
        }
        if (!strncmp(buf, "VSL:", 4)) {
                buf += 4;
                e = buf;
                while (*e != '\0')
                        e++;
                if (e == buf)
                        VUT_Error(vut, 1, "Missing tag in VSL:");
                if (e[-1] == ']') {
                        r = e - 1;
                        while (r > buf && *r != '[')
                                r--;
                        if (r == buf || r[1] == ']')
                                VUT_Error(vut, 1, "Syntax error: VSL:%s", buf);
                        e[-1] = '\0';
                        lval = strtol(r + 1, &s, 10);
                        if (s != e - 1)
                                VUT_Error(vut, 1, "Syntax error: VSL:%s]", buf);
                        if (lval <= 0 || lval > 255) {
                                VUT_Error(vut, 1,
                                    "Syntax error. Field specifier must be"
                                    " between 1 and 255: %s]",
                                    buf);
                        }
                        *r = '\0';
                } else
                        lval = 0;
                r = buf;
                while (r < e && *r != ':')
                        r++;
                if (r != e) {
                        slt = VSL_Name2Tag(buf, r - buf);
                        r++;
                } else {
                        slt = VSL_Name2Tag(buf, -1);
                        r = NULL;
                }
                if (slt == -2)
                        VUT_Error(vut, 1, "Tag not unique: %s", buf);
                if (slt == -1)
                        VUT_Error(vut, 1, "Unknown log tag: %s", buf);
                assert(slt >= 0);

                addf_vsl((enum VSL_tag_e)slt, lval, r);
                return;
        }
        if (!strcmp(buf, "Varnish:default_format")) {
                parse_format(FORMAT);
                return;
        }
        VUT_Error(vut, 1, "Unknown formatting extension: %s", buf);
}

static void
parse_format(const char *format)
{
        const char *p, *q;
        struct vsb *vsb;
        char buf[256];
        int b;

        if (format == NULL)
                format = FORMAT;

        vsb = VSB_new_auto();
        AN(vsb);

        for (p = format; *p != '\0'; p++) {

                /* Allow the most essential escape sequences in format */
                if (*p == '\\' && p[1] != '\0') {
                        if (*++p == 't')
                                AZ(VSB_putc(vsb, '\t'));
                        else if (*p == 'n')
                                AZ(VSB_putc(vsb, '\n'));
                        else
                                AZ(VSB_putc(vsb, *p));
                        continue;
                }

                if (*p != '%') {
                        AZ(VSB_putc(vsb, *p));
                        continue;
                }

                if (VSB_len(vsb) > 0) {
                        AZ(VSB_finish(vsb));
                        addf_string(VSB_data(vsb));
                        VSB_clear(vsb);
                }

                p++;
                switch (*p) {
                case 'b':       /* Body bytes sent */
                        addf_fragment(&CTX.frag[F_b], CTX.missing_int);
                        break;
                case 'D':       /* Float request time */
                        addf_time('T', "us");
                        break;
                case 'h':       /* Client host name / IP Address */
                        addf_fragment(&CTX.frag[F_h], CTX.missing_string);
                        break;
                case 'H':       /* Protocol */
                        addf_fragment(&CTX.frag[F_H], "HTTP/1.0");
                        break;
                case 'I':       /* Bytes received */
                        addf_fragment(&CTX.frag[F_I], CTX.missing_int);
                        break;
                case 'l':       /* Client user ID (identd) always '-' */
                        AZ(VSB_putc(vsb, '-'));
                        break;
                case 'm':       /* Method */
                        addf_fragment(&CTX.frag[F_m], CTX.missing_string);
                        break;
                case 'O':       /* Bytes sent */
                        addf_fragment(&CTX.frag[F_O], CTX.missing_int);
                        break;
                case 'q':       /* Query string */
                        addf_fragment(&CTX.frag[F_q], "");
                        break;
                case 'r':       /* Request line */
                        addf_requestline();
                        break;
                case 's':       /* Status code */
                        addf_fragment(&CTX.frag[F_s], CTX.missing_int);
                        break;
                case 't':       /* strftime */
                        addf_time(*p, TIME_FMT);
                        break;
                case 'T':       /* Int request time */
                        addf_time(*p, "s");
                        break;
                case 'u':       /* Remote user from auth */
                        addf_auth();
                        break;
                case 'U':       /* URL */
                        addf_fragment(&CTX.frag[F_U], CTX.missing_string);
                        break;
                case '{':
                        p++;
                        q = p;
                        b = 1;
                        while (*q) {
                                if (*q == '{')
                                        b++;
                                else if (*q == '}')
                                        if (--b == 0)
                                                break;
                                q++;
                        }
                        if (b > 0)
                                VUT_Error(vut, 1, "Unmatched bracket at: %s",
                                    p - 2);
                        assert((unsigned)(q - p) < sizeof buf - 1);
                        strncpy(buf, p, q - p);
                        buf[q - p] = '\0';
                        q++;
                        switch (*q) {
                        case 'i':
                                addf_hdr(&CTX.watch_reqhdr, buf);
                                break;
                        case 'o':
                                addf_hdr(&CTX.watch_resphdr, buf);
                                break;
                        case 't':
                                addf_time(*q, buf);
                                break;
                        case 'T':
                                addf_time(*q, buf);
                                break;
                        case 'x':
                                parse_x_format(buf);
                                break;
                        default:
                                VUT_Error(vut, 1,
                                    "Unknown format specifier at: %s",
                                    p - 2);
                        }
                        p = q;
                        break;
                default:
                        VUT_Error(vut, 1, "Unknown format specifier at: %s",
                            p - 1);
                }
        }

        if (VSB_len(vsb) > 0) {
                /* Add any remaining static */
                AZ(VSB_finish(vsb));
                addf_string(VSB_data(vsb));
                VSB_clear(vsb);
        }

        VSB_destroy(&vsb);
}

static int
isprefix(const char *prefix, size_t len, const char *b,
    const char *e, const char **next)
{
        assert(len > 0);
        if (e < b + len || strncasecmp(b, prefix, len))
                return (0);
        b += len;
        if (next) {
                while (b < e && *b == ' ')
                        b++;
                *next = b;
        }
        return (1);
}

static void
frag_fields(int force, const char *b, const char *e, ...)
{
        va_list ap;
        const char *p, *q;
        int n, field;
        struct fragment *frag;

        AN(b);
        AN(e);
        va_start(ap, e);

        n = 0;
        while (1) {
                field = va_arg(ap, int);
                frag = va_arg(ap, struct fragment *);
                if (field == 0) {
                        AZ(frag);
                        break;
                }
                p = q = NULL;
                while (n < field) {
                        while (b < e && isspace(*b))
                                b++;
                        p = b;
                        while (b < e && !isspace(*b))
                                b++;
                        q = b;
                        n++;
                }
                assert(p != NULL && q != NULL);
                if (p >= e || q <= p)
                        continue;
                if (frag->gen != CTX.gen || force) {
                        /* We only grab the same matching field once */
                        frag->gen = CTX.gen;
                        frag->b = p;
                        frag->e = q;
                }
        }
        va_end(ap);
}

static void
frag_line(int force, const char *b, const char *e, struct fragment *f)
{

        if (f->gen == CTX.gen && !force)
                /* We only grab the same matching record once */
                return;

        /* Skip leading space */
        while (b < e && isspace(*b))
                ++b;

        /* Skip trailing space */
        while (e > b && isspace(e[-1]))
                --e;

        f->gen = CTX.gen;
        f->b = b;
        f->e = e;
}

static void
process_hdr(const struct watch_head *head, const char *b, const char *e)
{
        struct watch *w;
        const char *p;

        VTAILQ_FOREACH(w, head, list) {
                CHECK_OBJ_NOTNULL(w, WATCH_MAGIC);
                if (!isprefix(w->key, w->keylen, b, e, &p))
                        continue;
                frag_line(1, p, e, &w->frag);
        }
}

static void
process_vsl(const struct vsl_watch_head *head, enum VSL_tag_e tag,
    const char *b, const char *e)
{
        struct vsl_watch *w;
        const char *p;
        VTAILQ_FOREACH(w, head, list) {
                CHECK_OBJ_NOTNULL(w, VSL_WATCH_MAGIC);
                if (tag != w->tag)
                        continue;
                p = b;
                if (w->prefixlen > 0 &&
                    !isprefix(w->prefix, w->prefixlen, b, e, &p))
                        continue;
                if (w->idx == 0)
                        frag_line(0, p, e, &w->frag);
                else
                        frag_fields(0, p, e, w->idx, &w->frag, 0, NULL);
        }
}

static int v_matchproto_(VSLQ_dispatch_f)
dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
    void *priv)
{
        struct VSL_transaction *t;
        enum VSL_tag_e tag;
        const char *b, *e, *p;
        struct watch *w;
        int i, skip;

        (void)vsl;
        (void)priv;

        for (t = pt[0]; t != NULL; t = *++pt) {
                CTX.gen++;

                if (t->type == VSL_t_req) {
                        CTX.side = "c";
                } else if (t->type == VSL_t_bereq) {
                        CTX.side = "b";
                } else
                        continue;

                CTX.hitmiss = "-";
                CTX.handling = "-";
                CTX.vxid = t->vxid;
                skip = 0;
                while (skip == 0 && 1 == VSL_Next(t->c)) {
                        tag = VSL_TAG(t->c->rec.ptr);
                        if (VSL_tagflags[tag] &&
                            CTX.quote_how != VSB_QUOTE_JSON)
                                continue;

                        b = VSL_CDATA(t->c->rec.ptr);
                        e = b + VSL_LEN(t->c->rec.ptr);
                        if (!VSL_tagflags[tag]) {
                                while (e > b && e[-1] == '\0')
                                        e--;
                        }

                        switch (tag) {
                        case SLT_HttpGarbage:
                                skip = 1;
                                break;
                        case SLT_PipeAcct:
                                frag_fields(0, b, e,
                                    3, &CTX.frag[F_I],
                                    4, &CTX.frag[F_O],
                                    0, NULL);
                                break;
                        case SLT_BackendOpen:
                                frag_fields(1, b, e,
                                    3, &CTX.frag[F_h],
                                    0, NULL);
                                break;
                        case SLT_ReqStart:
                                frag_fields(0, b, e,
                                    1, &CTX.frag[F_h],
                                    0, NULL);
                                break;
                        case SLT_BereqMethod:
                        case SLT_ReqMethod:
                                frag_line(0, b, e, &CTX.frag[F_m]);
                                break;
                        case SLT_BereqURL:
                        case SLT_ReqURL:
                                p = memchr(b, '?', e - b);
                                if (p == NULL)
                                        p = e;
                                frag_line(0, b, p, &CTX.frag[F_U]);
                                frag_line(0, p, e, &CTX.frag[F_q]);
                                break;
                        case SLT_BereqProtocol:
                        case SLT_ReqProtocol:
                                frag_line(0, b, e, &CTX.frag[F_H]);
                                break;
                        case SLT_BerespStatus:
                        case SLT_RespStatus:
                                frag_line(1, b, e, &CTX.frag[F_s]);
                                break;
                        case SLT_BereqAcct:
                        case SLT_ReqAcct:
                                frag_fields(0, b, e,
                                    3, &CTX.frag[F_I],
                                    5, &CTX.frag[F_b],
                                    6, &CTX.frag[F_O],
                                    0, NULL);
                                break;
                        case SLT_Timestamp:
#define ISPREFIX(a, b, c, d)    isprefix(a, strlen(a), b, c, d)
                                if (ISPREFIX("Start:", b, e, &p)) {
                                        frag_fields(0, p, e, 1,
                                            &CTX.frag[F_tstart], 0, NULL);

                                } else if (ISPREFIX("Resp:", b, e, &p) ||
                                    ISPREFIX("PipeSess:", b, e, &p) ||
                                    ISPREFIX("BerespBody:", b, e, &p)) {
                                        frag_fields(0, p, e, 1,
                                            &CTX.frag[F_tend], 0, NULL);

                                } else if (ISPREFIX("Process:", b, e, &p) ||
                                    ISPREFIX("Pipe:", b, e, &p) ||
                                    ISPREFIX("Beresp:", b, e, &p)) {
                                        frag_fields(0, p, e, 2,
                                            &CTX.frag[F_ttfb], 0, NULL);
                                }
                                break;
                        case SLT_BereqHeader:
                        case SLT_ReqHeader:
                                process_hdr(&CTX.watch_reqhdr, b, e);
                                if (ISPREFIX("Authorization:", b, e, &p) &&
                                    ISPREFIX("basic ", p, e, &p))
                                        frag_line(0, p, e,
                                            &CTX.frag[F_auth]);
                                else if (ISPREFIX("Host:", b, e, &p))
                                        frag_line(0, p, e,
                                            &CTX.frag[F_host]);
#undef ISPREFIX
                                break;
                        case SLT_BerespHeader:
                        case SLT_RespHeader:
                                process_hdr(&CTX.watch_resphdr, b, e);
                                break;
                        case SLT_VCL_call:
                                if (!strcasecmp(b, "recv")) {
                                        CTX.hitmiss = "-";
                                        CTX.handling = "-";
                                } else if (!strcasecmp(b, "hit")) {
                                        CTX.hitmiss = "hit";
                                        CTX.handling = "hit";
                                } else if (!strcasecmp(b, "miss")) {
                                        CTX.hitmiss = "miss";
                                        CTX.handling = "miss";
                                } else if (!strcasecmp(b, "pass")) {
                                        CTX.hitmiss = "miss";
                                        CTX.handling = "pass";
                                } else if (!strcasecmp(b, "synth")) {
                                        /* Arguably, synth isn't a hit or
                                           a miss, but miss is less
                                           wrong */
                                        CTX.hitmiss = "miss";
                                        CTX.handling = "synth";
                                }
                                break;
                        case SLT_VCL_return:
                                if (!strcasecmp(b, "pipe")) {
                                        CTX.hitmiss = "miss";
                                        CTX.handling = "pipe";
                                } else if (!strcasecmp(b, "restart"))
                                        skip = 1;
                                break;
                        case SLT_VCL_Log:
                                VTAILQ_FOREACH(w, &CTX.watch_vcl_log, list) {
                                        CHECK_OBJ_NOTNULL(w, WATCH_MAGIC);
                                        if (e - b < w->keylen ||
                                            strncmp(b, w->key, w->keylen))
                                                continue;
                                        p = b + w->keylen;
                                        frag_line(0, p, e, &w->frag);
                                }
                                break;
                        default:
                                break;
                        }

                        process_vsl(&CTX.watch_vsl, tag, b, e);
                }
                if (skip)
                        continue;
                i = print();
                if (i)
                        return (i);
        }

        return (0);
}

static char *
read_format(const char *formatfile)
{
        FILE *fmtfile;
        size_t len = 0;
        int fmtlen;
        char *fmt = NULL;

        fmtfile = fopen(formatfile, "r");
        if (fmtfile == NULL)
                VUT_Error(vut, 1, "Can't open format file (%s)",
                    strerror(errno));
        AN(fmtfile);
        fmtlen = getline(&fmt, &len, fmtfile);
        if (fmtlen == -1) {
                free(fmt);
                if (feof(fmtfile))
                        VUT_Error(vut, 1, "Empty format file");
                VUT_Error(vut, 1, "Can't read format from file (%s)",
                    strerror(errno));
        }
        AZ(fclose(fmtfile));
        if (fmt[fmtlen - 1] == '\n')
                fmt[fmtlen - 1] = '\0';
        return (fmt);
}

int
main(int argc, char * const *argv)
{
        signed char opt;
        char *format = NULL;
        int mode_opt = 0;

        vut = VUT_InitProg(argc, argv, &vopt_spec);
        AN(vut);
        memset(&CTX, 0, sizeof CTX);
        VTAILQ_INIT(&CTX.format);
        VTAILQ_INIT(&CTX.watch_vcl_log);
        VTAILQ_INIT(&CTX.watch_reqhdr);
        VTAILQ_INIT(&CTX.watch_resphdr);
        VTAILQ_INIT(&CTX.watch_vsl);
        CTX.vsb = VSB_new_auto();
        AN(CTX.vsb);
        CTX.quote_how = VSB_QUOTE_ESCHEX;
        REPLACE(CTX.missing_string, "-");
        REPLACE(CTX.missing_int, "-");

        tzset();                // We use localtime_r(3)

        while ((opt = getopt(argc, argv, vopt_spec.vopt_optstring)) != -1) {
                switch (opt) {
                case 'a':
                        /* Append to file */
                        CTX.a_opt = 1;
                        break;
                case 'b': /* backend mode */
                case 'c': /* client mode */
                case 'E': /* show ESI */
                        AN(VUT_Arg(vut, opt, NULL));
                        mode_opt = 1;
                        break;
                case 'F':
                        if (format != NULL)
                                VUT_Error(vut, 1, "Format already set");
                        REPLACE(format, optarg);
                        break;
                case 'f':
                        if (format != NULL)
                                VUT_Error(vut, 1, "Format already set");
                        /* Format string from file */
                        format = read_format(optarg);
                        AN(format);
                        break;
                case 'h':
                        /* Usage help */
                        VUT_Usage(vut, &vopt_spec, 0);
                        break;
                case 'j':
                        REPLACE(CTX.missing_string, "");
                        REPLACE(CTX.missing_int, "0");
                        CTX.quote_how = VSB_QUOTE_JSON;
                        break;
                case 'w':
                        /* Write to file */
                        REPLACE(CTX.w_arg, optarg);
                        break;
                default:
                        if (!VUT_Arg(vut, opt, optarg))
                                VUT_Usage(vut, &vopt_spec, 1);
                }
        }

        /* default is client mode: */
        if (!mode_opt)
                AN(VUT_Arg(vut, 'c', NULL));

        if (optind != argc)
                VUT_Usage(vut, &vopt_spec, 1);

        if (vut->D_opt && !CTX.w_arg)
                VUT_Error(vut, 1, "Missing -w option");

        if (vut->D_opt && !strcmp(CTX.w_arg, "-"))
                VUT_Error(vut, 1, "Daemon cannot write to stdout");

        /* Check for valid grouping mode */
        assert(vut->g_arg < VSL_g__MAX);
        if (vut->g_arg != VSL_g_vxid && vut->g_arg != VSL_g_request)
                VUT_Error(vut, 1, "Invalid grouping mode: %s",
                    VSLQ_grouping[vut->g_arg]);

        /* Prepare output format */
        parse_format(format);
        REPLACE(format, NULL);

        /* Setup output */
        vut->dispatch_f = dispatch_f;
        vut->dispatch_priv = NULL;
        if (CTX.w_arg) {
                openout(CTX.a_opt);
                AN(CTX.fo);
                if (vut->D_opt)
                        vut->sighup_f = rotateout;
        } else
                CTX.fo = stdout;
        vut->idle_f = flushout;

        VUT_Setup(vut);
        (void)VUT_Main(vut);
        VUT_Fini(&vut);

        exit(0);
}

		varnish-cache/bin/varnishncsa/varnishncsa.c
0		/*-
1		* Copyright (c) 2006 Verdens Gang AS
2		* Copyright (c) 2006-2016 Varnish Software AS
3		* All rights reserved.
4		*
5		* Author: Anders Berg <andersb@vgnett.no>
6		* Author: Poul-Henning Kamp <phk@phk.freebsd.dk>
7		* Author: Tollef Fog Heen <tfheen@varnish-software.com>
8		* Author: Martin Blix Grydeland <mbgrydeland@varnish-software.com>
9		*
10		* SPDX-License-Identifier: BSD-2-Clause
11		*
12		* Redistribution and use in source and binary forms, with or without
13		* modification, are permitted provided that the following conditions
14		* are met:
15		* 1. Redistributions of source code must retain the above copyright
16		* notice, this list of conditions and the following disclaimer.
17		* 2. Redistributions in binary form must reproduce the above copyright
18		* notice, this list of conditions and the following disclaimer in the
19		* documentation and/or other materials provided with the distribution.
20		*
21		* THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
22		* ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
23		* IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
24		* ARE DISCLAIMED. IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
25		* FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
26		* DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
27		* OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
28		* HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
29		* LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
30		* OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
31		* SUCH DAMAGE.
32		*
33		* Obtain log data from the shared memory log, order it by session ID, and
34		* display it in Apache / NCSA combined log format.
35		*
36		* See doc/sphinx/reference/varnishncsa.rst for the supported format
37		* specifiers.
38		*
39		*/
40
41		#include "config.h"
42
43		#include <stdlib.h>
44		#include <stdio.h>
45		#include <unistd.h>
46		#include <string.h>
47		#include <signal.h>
48		#include <stdarg.h>
49		#include <inttypes.h>
50		#include <limits.h>
51		#include <ctype.h>
52		#include <time.h>
53		#include <math.h>
54
55		#define VOPT_DEFINITION
56		#define VOPT_INC "varnishncsa_options.h"
57
58		#include "vdef.h"
59
60		#include "vapi/vsl.h"
61		#include "vapi/voptget.h"
62		#include "vas.h"
63		#include "venc.h"
64		#include "vsb.h"
65		#include "vut.h"
66		#include "vqueue.h"
67		#include "miniobj.h"
68
69		#define TIME_FMT "[%d/%b/%Y:%T %z]"
70		#define FORMAT "%h %l %u %t \"%r\" %s %b \"%{Referer}i\" \"%{User-agent}i\""
71
72		static struct VUT *vut;
73
74		struct format;
75
76		enum e_frag {
77		F_H, /* %H Proto */
78		F_U, /* %U URL path */
79		F_q, /* %q Query string */
80		F_b, /* %b Body bytes sent */
81		F_h, /* %h Host name / IP Address */
82		F_m, /* %m Method */
83		F_s, /* %s Status */
84		F_I, /* %I Bytes received */
85		F_O, /* %O Bytes sent */
86		F_tstart, /* Time start */
87		F_tend, /* Time end */
88		F_ttfb, /* %{Varnish:time_firstbyte}x */
89		F_host, /* Host header */
90		F_auth, /* Authorization header */
91		F__MAX,
92		};
93
94		struct fragment {
95		uint64_t gen;
96		const char b, e;
97		};
98
99		typedef int format_f(const struct format *format);
100
101		struct format {
102		unsigned magic;
103		#define FORMAT_MAGIC 0xC3119CDA
104
105		char time_type;
106		VTAILQ_ENTRY(format) list;
107		format_f *func;
108		struct fragment *frag;
109		char *string;
110		const char const strptr;
111		char *time_fmt;
112		int64_t *int64;
113		};
114
115		struct watch {
116		unsigned magic;
117		#define WATCH_MAGIC 0xA7D4005C
118
119		VTAILQ_ENTRY(watch) list;
120		char *key;
121		int keylen;
122		struct fragment frag;
123		};
124		VTAILQ_HEAD(watch_head, watch);
125
126		struct vsl_watch {
127		unsigned magic;
128		#define VSL_WATCH_MAGIC 0xE3E27D23
129
130		VTAILQ_ENTRY(vsl_watch) list;
131		enum VSL_tag_e tag;
132		int idx;
133		char *prefix;
134		int prefixlen;
135		struct fragment frag;
136		};
137		VTAILQ_HEAD(vsl_watch_head, vsl_watch);
138
139		static struct ctx {
140		/* Options */
141		int a_opt;
142		char *w_arg;
143
144		FILE *fo;
145		struct vsb *vsb;
146		uint64_t gen;
147		VTAILQ_HEAD(,format) format;
148		int quote_how;
149		char *missing_string;
150		char *missing_int;
151
152		/* State */
153		struct watch_head watch_vcl_log;
154		struct watch_head watch_reqhdr; /* also bereqhdr */
155		struct watch_head watch_resphdr; /* also beresphdr */
156		struct vsl_watch_head watch_vsl;
157		struct fragment frag[F__MAX];
158		const char *hitmiss;
159		const char *handling;
160		const char *side;
161		int64_t vxid;
162		} CTX;
163
164		static void parse_format(const char *format);
165
166		static void
167	200	openout(int append)
168		{
169
170	200	AN(CTX.w_arg);
171	200	if (!strcmp(CTX.w_arg, "-"))
172	0	CTX.fo = stdout;
173		else
174	200	CTX.fo = fopen(CTX.w_arg, append ? "a" : "w");
175	200	if (CTX.fo == NULL)
176	80	VUT_Error(vut, 1, "Can't open output file (%s)",
177	40	strerror(errno));
178	160	}
179
180		static int v_matchproto_(VUT_cb_f)
181	40	rotateout(struct VUT *v)
182		{
183
184	40	assert(v == vut);
185	40	AN(CTX.w_arg);
186	40	AN(CTX.fo);
187	40	(void)fclose(CTX.fo);
188	40	openout(1);
189	40	AN(CTX.fo);
190	40	return (0);
191		}
192
193		static int v_matchproto_(VUT_cb_f)
194	34128	flushout(struct VUT *v)
195		{
196
197	34128	assert(v == vut);
198	34128	AN(CTX.fo);
199	34128	if (fflush(CTX.fo))
200	0	return (-5);
201	34128	return (0);
202	34128	}
203
204		static inline int
205	8360	vsb_fcat(struct vsb vsb, const struct fragment f, const char *dflt)
206		{
207	8360	if (f->gen == CTX.gen) {
208	8200	assert(f->b <= f->e);
209	8200	VSB_quote(vsb, f->b, f->e - f->b, CTX.quote_how);
210	8360	} else if (dflt)
211	160	VSB_quote(vsb, dflt, -1, CTX.quote_how);
212		else
213	0	return (-1);
214	8360	return (0);
215	8360	}
216
217		static int v_matchproto_(format_f)
218	11040	format_string(const struct format *format)
219		{
220
221	11040	CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
222	11040	AN(format->string);
223	11040	AZ(VSB_cat(CTX.vsb, format->string));
224	11040	return (1);
225		}
226
227		static int v_matchproto_(format_f)
228	1080	format_strptr(const struct format *format)
229		{
230
231	1080	CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
232	1080	AN(format->strptr);
233	1080	AN(*format->strptr);
234	1080	AZ(VSB_cat(CTX.vsb, *format->strptr));
235	1080	return (1);
236		}
237
238		static int v_matchproto_(format_f)
239	840	format_int64(const struct format *format)
240		{
241
242	840	CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
243	840	VSB_printf(CTX.vsb, "%jd", (intmax_t)*format->int64);
244	840	return (1);
245		}
246
247		static int v_matchproto_(format_f)
248	7280	format_fragment(const struct format *format)
249		{
250
251	7280	CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
252	7280	AN(format->frag);
253
254	7280	if (format->frag->gen != CTX.gen) {
255	1840	if (format->string == NULL)
256	0	return (-1);
257	1840	VSB_quote(CTX.vsb, format->string, -1, CTX.quote_how);
258	1840	return (0);
259		}
260	5440	AZ(vsb_fcat(CTX.vsb, format->frag, NULL));
261	5440	return (1);
262	7280	}
263
264		static int v_matchproto_(format_f)
265	2400	format_time(const struct format *format)
266		{
267		double t_start, t_end, d;
268		char *p;
269		char buf[64];
270		time_t t;
271		intmax_t l;
272		struct tm tm;
273
274	2400	CHECK_OBJ_NOTNULL(format, FORMAT_MAGIC);
275	2400	if (CTX.frag[F_tstart].gen == CTX.gen) {
276	2400	t_start = strtod(CTX.frag[F_tstart].b, &p);
277	2400	if (p != CTX.frag[F_tstart].e)
278	0	t_start = NAN;
279	2400	} else
280	0	t_start = NAN;
281	2400	if (isnan(t_start)) {
282		/* Missing t_start is a no go */
283	0	if (format->string == NULL)
284	0	return (-1);
285	0	AZ(VSB_cat(CTX.vsb, format->string));
286	0	return (0);
287		}
288
289		/* Missing t_end defaults to t_start */
290	2400	if (CTX.frag[F_tend].gen == CTX.gen) {
291	2360	t_end = strtod(CTX.frag[F_tend].b, &p);
292	2360	if (p != CTX.frag[F_tend].e)
293	0	t_end = t_start;
294	2360	} else
295	40	t_end = t_start;
296
297	2400	AN(format->time_fmt);
298
299	2400	switch (format->time_type) {
300		case 't':
301	1200	t = (intmax_t)floor(t_start);
302	1200	(void)localtime_r(&t, &tm);
303	1200	AN(strftime(buf, sizeof buf, format->time_fmt, &tm));
304	1200	AZ(VSB_cat(CTX.vsb, buf));
305	1200	return (1);
306		case '3':
307	120	l = (intmax_t)(modf(t_start, &d) * 1e3);
308	120	break;
309		case '6':
310	120	l = (intmax_t)(modf(t_start, &d) * 1e6);
311	120	break;
312		case 'S':
313	120	l = (intmax_t)t_start;
314	120	break;
315		case 'M':
316	120	l = (intmax_t)(t_start * 1e3);
317	120	break;
318		case 'U':
319	120	l = (intmax_t)(t_start * 1e6);
320	120	break;
321		case 's':
322	240	l = (intmax_t)(t_end - t_start);
323	240	break;
324		case 'm':
325	120	l = (intmax_t)((t_end - t_start) * 1e3);
326	120	break;
327		case 'u':
328	240	l = (intmax_t)((t_end - t_start) * 1e6);
329	240	break;
330		default:
331	0	WRONG("Time format specifier");
332	0	}
333
334		#ifdef __FreeBSD__
335	1200	assert(fmtcheck(format->time_fmt, "%jd") == format->time_fmt);
336		#endif
337	1200	AZ(VSB_printf(CTX.vsb, format->time_fmt, l));
338
339	1200	return (1);
340	2400	}
341
342		static int v_matchproto_(format_f)
343	600	format_requestline(const struct format *format)
344		{
345
346	600	(void)format;
347	600	AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_m], "-"));
348	600	AZ(VSB_putc(CTX.vsb, ' '));
349	600	if (CTX.frag[F_host].gen == CTX.gen) {
350	520	if (strncmp(CTX.frag[F_host].b, "http://", 7))
351	520	AZ(VSB_cat(CTX.vsb, "http://"));
352	520	AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_host], NULL));
353	520	} else
354	80	AZ(VSB_cat(CTX.vsb, "http://localhost"));
355	600	AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_U], ""));
356	600	AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_q], ""));
357	600	AZ(VSB_putc(CTX.vsb, ' '));
358	600	AZ(vsb_fcat(CTX.vsb, &CTX.frag[F_H], "HTTP/1.0"));
359	600	return (1);
360		}
361
362		static int v_matchproto_(format_f)
363	640	format_auth(const struct format *format)
364		{
365	640	struct vsb *vsb = VSB_new_auto();
366	640	AN(vsb);
367		char *q;
368
369	640	if (CTX.frag[F_auth].gen != CTX.gen \|\|
370	240	VENC_Decode_Base64(vsb, CTX.frag[F_auth].b, CTX.frag[F_auth].e)) {
371	400	VSB_destroy(&vsb);
372	400	if (format->string == NULL)
373	0	return (-1);
374	400	VSB_quote(CTX.vsb, format->string, -1, CTX.quote_how);
375	400	return (0);
376		}
377	240	AZ(VSB_finish(vsb));
378	240	q = strchr(VSB_data(vsb), ':');
379	240	if (q != NULL)
380	240	*q = '\0';
381	240	VSB_quote(CTX.vsb, VSB_data(vsb), -1, CTX.quote_how);
382	240	VSB_destroy(&vsb);
383	240	return (1);
384	640	}
385
386		static int
387	3280	print(void)
388		{
389		const struct format *f;
390	3280	int i, r = 1;
391
392	3280	VSB_clear(CTX.vsb);
393	27160	VTAILQ_FOREACH(f, &CTX.format, list) {
394	23880	CHECK_OBJ_NOTNULL(f, FORMAT_MAGIC);
395	23880	i = (f->func)(f);
396	23880	AZ(VSB_error(CTX.vsb));
397	23880	if (r > i)
398	960	r = i;
399	23880	}
400	3280	AZ(VSB_putc(CTX.vsb, '\n'));
401	3280	AZ(VSB_finish(CTX.vsb));
402	3280	if (r >= 0) {
403	3280	i = fwrite(VSB_data(CTX.vsb), 1, VSB_len(CTX.vsb), CTX.fo);
404	3280	if (i != VSB_len(CTX.vsb))
405	0	return (-5);
406	3280	}
407	3280	return (0);
408	3280	}
409
410		static void
411	8240	addf_string(const char *str)
412		{
413		struct format *f;
414
415	8240	AN(str);
416	8240	ALLOC_OBJ(f, FORMAT_MAGIC);
417	8240	AN(f);
418	8240	f->func = format_string;
419	8240	f->string = strdup(str);
420	8240	AN(f->string);
421	8240	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
422	8240	}
423
424		static void
425	280	addf_strptr(const char const strptr)
426		{
427		struct format *f;
428
429	280	AN(strptr);
430	280	ALLOC_OBJ(f, FORMAT_MAGIC);
431	280	AN(f);
432	280	f->func = format_strptr;
433	280	f->strptr = strptr;
434	280	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
435	280	}
436
437		static void
438	3520	addf_fragment(struct fragment frag, const char str)
439		{
440		struct format *f;
441
442	3520	AN(frag);
443	3520	ALLOC_OBJ(f, FORMAT_MAGIC);
444	3520	AN(f);
445	3520	f->func = format_fragment;
446	3520	f->frag = frag;
447	3520	if (str != NULL) {
448	3520	f->string = strdup(str);
449	3520	AN(f->string);
450	3520	}
451	3520	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
452	3520	}
453
454		static void
455	200	addf_int64(int64_t *i)
456		{
457		struct format *f;
458
459	200	AN(i);
460	200	ALLOC_OBJ(f, FORMAT_MAGIC);
461	200	AN(f);
462	200	f->func = format_int64;
463	200	f->int64 = i;
464	200	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
465	200	}
466
467		static void
468	1280	addf_time(char type, const char *fmt)
469		{
470		struct format *f;
471
472	1280	ALLOC_OBJ(f, FORMAT_MAGIC);
473	1280	AN(f);
474	1280	AN(fmt);
475	1280	f->func = format_time;
476	1280	f->time_type = type;
477	1280	f->time_fmt = strdup(fmt);
478
479	1280	if (f->time_type == 'T') {
480	200	if (!strcmp(fmt, "s"))
481	80	f->time_type = 's';
482	120	else if (!strcmp(fmt, "ms"))
483	40	f->time_type = 'm';
484	80	else if (!strcmp(fmt, "us"))
485	80	f->time_type = 'u';
486		else
487	0	VUT_Error(vut, 1, "Unknown specifier: %%{%s}T",
488	0	fmt);
489	200	REPLACE(f->time_fmt, "%jd");
490	1280	} else if (f->time_type == 't') {
491	1080	if (!strcmp(fmt, "sec")) {
492	40	f->time_type = 'S';
493	40	REPLACE(f->time_fmt, "%jd");
494	1080	} else if (!strncmp(fmt, "msec", 4)) {
495	120	fmt += 4;
496	120	if (!strcmp(fmt, "_frac")) {
497	40	f->time_type = '3';
498	40	REPLACE(f->time_fmt, "%03jd");
499	120	} else if (*fmt == '\0') {