Create three groups of seven SHMlog tags:

	{Rx,Tx,Obj}{Request,Response,Status,URL,Protocol,Header,LostHeader}

And log http header munching accordingly.

git-svn-id: svn+ssh://projects.linpro.no/svn/varnish/trunk@580 d4fa192b-c00b-0410-8231-f00ffab90ce4

diff --git a/varnish-cache/bin/varnishd/cache.h b/varnish-cache/bin/varnishd/cache.h
index ec20ad7b0874ca3ec69e3c9673be98577f9e9316..84d6a4ed78c31801e7019b29fb15c89f9106bba4 100644 (file)
--- a/varnish-cache/bin/varnishd/cache.h
+++ b/varnish-cache/bin/varnishd/cache.h
@@ -67,7 +67,11 @@ struct http {
        char                    *e;             /* (E)nd of buffer */
 
        unsigned char           conds;          /* If-* headers present */
-       unsigned char           objlog;
+       enum httpwhence {
+               HTTP_Rx,
+               HTTP_Tx,
+               HTTP_Obj
+       }                       logtag;
 
        struct http_hdr         hd[MAX_HTTP_HDRS];
        unsigned                nhd;

diff --git a/varnish-cache/bin/varnishd/cache_fetch.c b/varnish-cache/bin/varnishd/cache_fetch.c
index b5964edb50daf23f2c66adcf54bb10a96f566fdd..27f05cac9a54c0e885d2c9e734fe988009a81f73 100644 (file)
--- a/varnish-cache/bin/varnishd/cache_fetch.c
+++ b/varnish-cache/bin/varnishd/cache_fetch.c
@@ -229,7 +229,7 @@ FetchBody(struct sess *sp)
         * cache_response.c
         */
        http_ClrHeader(sp->http);
-       sp->http->objlog = 1;   /* log as SLT_ObjHeader */
+       sp->http->logtag = HTTP_Obj;
        http_CopyResp(sp->fd, sp->http, vc->http);
        http_FilterHeader(sp->fd, sp->http, vc->http, HTTPH_A_INS);
        
@@ -244,7 +244,6 @@ FetchBody(struct sess *sp)
                    "Content-Length: %u", sp->obj->len);
        } else
                cls = 0;
-       sp->http->objlog = 0;
        http_CopyHttp(&sp->obj->http, sp->http);
 
        if (http_GetHdr(vc->http, H_Connection, &b) && !strcasecmp(b, "close"))
@@ -282,6 +281,8 @@ FetchHeaders(struct sess *sp)
        assert(vc != NULL);     /* XXX: handle this */
        VSL(SLT_Backend, sp->fd, "%d %s", vc->fd, sp->backend->vcl_name);
 
+       http_ClrHeader(vc->http);
+       vc->http->logtag = HTTP_Tx;
        http_GetReq(vc->fd, vc->http, sp->http);
        http_FilterHeader(vc->fd, vc->http, sp->http, HTTPH_R_FETCH);
        http_PrintfHeader(vc->fd, vc->http, "X-Varnish: %u", sp->xid);

diff --git a/varnish-cache/bin/varnishd/cache_http.c b/varnish-cache/bin/varnishd/cache_http.c
index f2a1d69aa7d42f6f2bcefcbb0218cea00eedeef2..949fe1bf5e1c08287431f43bf99fd3e62f84f999 100644 (file)
--- a/varnish-cache/bin/varnishd/cache_http.c
+++ b/varnish-cache/bin/varnishd/cache_http.c
@@ -19,11 +19,47 @@
 #include "http_headers.h"
 #undef HTTPH
 
-#define VSLH(ax, bx, cx, dx) \
-       VSLR((ax), (bx), (cx)->hd[(dx)].b, (cx)->hd[(dx)].e);
+enum httptag {
+       HTTP_T_Request,
+       HTTP_T_Response,
+       HTTP_T_Status,
+       HTTP_T_URL,
+       HTTP_T_Protocol,
+       HTTP_T_Header,
+       HTTP_T_LostHeader,
+};
+
+#define LOGMTX2(ax, bx)        \
+       [HTTP_T_##bx] = SLT_##ax##bx
+
+#define LOGMTX1(ax) {          \
+       LOGMTX2(ax, Request),   \
+       LOGMTX2(ax, Response),  \
+       LOGMTX2(ax, Status),    \
+       LOGMTX2(ax, URL),       \
+       LOGMTX2(ax, Protocol),  \
+       LOGMTX2(ax, Header),    \
+       LOGMTX2(ax, LostHeader) \
+       }
+
+static enum shmlogtag logmtx[3][7] = {
+       [HTTP_Rx] = LOGMTX1(Rx),
+       [HTTP_Tx] = LOGMTX1(Tx),
+       [HTTP_Obj] = LOGMTX1(Obj)
+};
+
+static enum shmlogtag
+T(struct http *hp, enum httptag t)
+{
+
+       CHECK_OBJ_NOTNULL(hp, HTTP_MAGIC);
+       assert(hp->logtag >= HTTP_Rx && hp->logtag <= HTTP_Obj);
+       assert(t >= HTTP_T_Request && t <= HTTP_T_LostHeader);
+       return (logmtx[hp->logtag][t]);
+}
 
-#define VSLHT(bx, cx, dx) \
-       VSLH((cx)->objlog ? SLT_ObjHeader : SLT_TxHeader, bx, cx, dx)
+#define VSLH(ax, bx, cx, dx) \
+       VSLR(T((cx), (ax)), (bx), (cx)->hd[(dx)].b, (cx)->hd[(dx)].e);
 
 /*--------------------------------------------------------------------*/
 
@@ -241,11 +277,11 @@ http_dissect_hdrs(struct http *hp, int fd, char *p)
                if (hp->nhd < MAX_HTTP_HDRS) {
                        hp->hd[hp->nhd].b = p;
                        hp->hd[hp->nhd].e = q;
-                       VSLH(SLT_RxHeader, fd, hp, hp->nhd);
+                       VSLH(HTTP_T_Header, fd, hp, hp->nhd);
                        hp->nhd++;
                } else {
                        VSL_stats->losthdr++;
-                       VSLR(SLT_LostHeader, fd, p, q);
+                       VSLR(T(hp, HTTP_T_LostHeader), fd, p, q);
                }
        }
        assert(hp->t <= hp->v);
@@ -263,6 +299,8 @@ http_DissectRequest(struct http *hp, int fd)
        assert(hp->t != NULL);
        assert(hp->s < hp->t);
        assert(hp->t <= hp->v);
+       hp->logtag = HTTP_Rx;
+
        for (p = hp->s ; isspace(*p); p++)
                continue;
 
@@ -271,7 +309,7 @@ http_DissectRequest(struct http *hp, int fd)
        for (; isalpha(*p); p++)
                ;
        hp->hd[HTTP_HDR_REQ].e = p;
-       VSLH(SLT_Request, fd, hp, HTTP_HDR_REQ);
+       VSLH(HTTP_T_Request, fd, hp, HTTP_HDR_REQ);
        *p++ = '\0';
 
        /* Next find the URI */
@@ -285,7 +323,7 @@ http_DissectRequest(struct http *hp, int fd)
        while (!isspace(*p))
                p++;
        hp->hd[HTTP_HDR_URL].e = p;
-       VSLH(SLT_URL, fd, hp, HTTP_HDR_URL);
+       VSLH(HTTP_T_URL, fd, hp, HTTP_HDR_URL);
        if (*p == '\n') {
                VSLR(SLT_HttpGarbage, fd, hp->s, hp->v);
                return (400);
@@ -303,7 +341,7 @@ http_DissectRequest(struct http *hp, int fd)
        while (!isspace(*p))
                p++;
        hp->hd[HTTP_HDR_PROTO].e = p;
-       VSLH(SLT_Protocol, fd, hp, HTTP_HDR_PROTO);
+       VSLH(HTTP_T_Protocol, fd, hp, HTTP_HDR_PROTO);
        if (*p != '\n')
                *p++ = '\0';
        while (isspace(*p) && *p != '\n')
@@ -327,6 +365,8 @@ http_DissectResponse(struct http *hp, int fd)
        assert(hp->t != NULL);
        assert(hp->s < hp->t);
        assert(hp->t <= hp->v);
+       hp->logtag = HTTP_Rx;
+
        for (p = hp->s ; isspace(*p); p++)
                continue;
 
@@ -335,7 +375,7 @@ http_DissectResponse(struct http *hp, int fd)
        while (!isspace(*p))
                p++;
        hp->hd[HTTP_HDR_PROTO].e = p;
-       VSLH(SLT_Protocol, fd, hp, HTTP_HDR_PROTO);
+       VSLH(HTTP_T_Protocol, fd, hp, HTTP_HDR_PROTO);
        *p++ = '\0';
 
        /* Next find the status */
@@ -345,7 +385,7 @@ http_DissectResponse(struct http *hp, int fd)
        while (!isspace(*p))
                p++;
        hp->hd[HTTP_HDR_STATUS].e = p;
-       VSLH(SLT_Status, fd, hp, HTTP_HDR_STATUS);
+       VSLH(HTTP_T_Status, fd, hp, HTTP_HDR_STATUS);
        *p++ = '\0';
 
        /* Next find the response */
@@ -359,7 +399,7 @@ http_DissectResponse(struct http *hp, int fd)
                continue;
        *q = '\0';
        hp->hd[HTTP_HDR_RESPONSE].e = q;
-       VSLH(SLT_Response, fd, hp, HTTP_HDR_RESPONSE);
+       VSLH(HTTP_T_Response, fd, hp, HTTP_HDR_RESPONSE);
        p++;
 
        return (http_dissect_hdrs(hp, fd, p));
@@ -526,17 +566,17 @@ http_CopyHttp(struct http *to, struct http *fm)
 /*--------------------------------------------------------------------*/
 
 static void
-http_seth(int fd, struct http *to, unsigned n, enum shmlogtag tag, const char *fm)
+http_seth(int fd, struct http *to, unsigned n, enum httptag tag, const char *fm)
 {
        assert(n < MAX_HTTP_HDRS);
        assert(fm != NULL);
        to->hd[n].b = (void*)(uintptr_t)fm;
-       to->hd[n].e = strchr(fm, '\0');
+       to->hd[n].e = (void*)(uintptr_t)strchr(fm, '\0');
        VSLH(tag, fd, to, n);
 }
 
 static void
-http_copyh(int fd, struct http *to, struct http *fm, unsigned n, enum shmlogtag tag)
+http_copyh(int fd, struct http *to, struct http *fm, unsigned n, enum httptag tag)
 {
 
        assert(n < MAX_HTTP_HDRS);
@@ -552,9 +592,9 @@ http_GetReq(int fd, struct http *to, struct http *fm)
 
        CHECK_OBJ_NOTNULL(fm, HTTP_MAGIC);
        CHECK_OBJ_NOTNULL(to, HTTP_MAGIC);
-       http_seth(fd, to, HTTP_HDR_REQ, SLT_Request, "GET");
-       http_copyh(fd, to, fm, HTTP_HDR_URL, SLT_URL);
-       http_seth(fd, to, HTTP_HDR_PROTO, SLT_Protocol, "HTTP/1.1");
+       http_seth(fd, to, HTTP_HDR_REQ, HTTP_T_Request, "GET");
+       http_copyh(fd, to, fm, HTTP_HDR_URL, HTTP_T_URL);
+       http_seth(fd, to, HTTP_HDR_PROTO, HTTP_T_Protocol, "HTTP/1.1");
 }
 
 void
@@ -563,9 +603,9 @@ http_CopyReq(int fd, struct http *to, struct http *fm)
 
        CHECK_OBJ_NOTNULL(fm, HTTP_MAGIC);
        CHECK_OBJ_NOTNULL(to, HTTP_MAGIC);
-       http_copyh(fd, to, fm, HTTP_HDR_REQ, SLT_Request);
-       http_copyh(fd, to, fm, HTTP_HDR_URL, SLT_URL);
-       http_copyh(fd, to, fm, HTTP_HDR_PROTO, SLT_Protocol);
+       http_copyh(fd, to, fm, HTTP_HDR_REQ, HTTP_T_Request);
+       http_copyh(fd, to, fm, HTTP_HDR_URL, HTTP_T_URL);
+       http_copyh(fd, to, fm, HTTP_HDR_PROTO, HTTP_T_Protocol);
 }
 
 
@@ -575,18 +615,18 @@ http_CopyResp(int fd, struct http *to, struct http *fm)
 
        CHECK_OBJ_NOTNULL(fm, HTTP_MAGIC);
        CHECK_OBJ_NOTNULL(to, HTTP_MAGIC);
-       http_copyh(fd, to, fm, HTTP_HDR_PROTO, SLT_Protocol);
-       http_copyh(fd, to, fm, HTTP_HDR_STATUS, SLT_Status);
-       http_copyh(fd, to, fm, HTTP_HDR_RESPONSE, SLT_Response);
+       http_copyh(fd, to, fm, HTTP_HDR_PROTO, HTTP_T_Protocol);
+       http_copyh(fd, to, fm, HTTP_HDR_STATUS, HTTP_T_Status);
+       http_copyh(fd, to, fm, HTTP_HDR_RESPONSE, HTTP_T_Response);
 }
 
 void
 http_SetResp(int fd, struct http *to, const char *proto, const char *status, const char *response)
 {
        CHECK_OBJ_NOTNULL(to, HTTP_MAGIC);
-       http_seth(fd, to, HTTP_HDR_PROTO, SLT_Protocol, proto);
-       http_seth(fd, to, HTTP_HDR_STATUS, SLT_Status, status);
-       http_seth(fd, to, HTTP_HDR_RESPONSE, SLT_Response, response);
+       http_seth(fd, to, HTTP_HDR_PROTO, HTTP_T_Protocol, proto);
+       http_seth(fd, to, HTTP_HDR_STATUS, HTTP_T_Status, status);
+       http_seth(fd, to, HTTP_HDR_RESPONSE, HTTP_T_Response, response);
 }
 
 static void
@@ -600,11 +640,11 @@ http_copyheader(int fd, struct http *to, struct http *fm, unsigned n)
        if (to->nhd < MAX_HTTP_HDRS) {
                to->hd[to->nhd].b = fm->hd[n].b;
                to->hd[to->nhd].e = fm->hd[n].e;
-               VSLHT(fd, to, to->nhd);
+               VSLH(HTTP_T_Header, fd, to, to->nhd);
                to->nhd++;
        } else  {
                VSL_stats->losthdr++;
-               VSLH(SLT_LostHeader, fd, fm, n);
+               VSLH(HTTP_T_LostHeader, fd, fm, n);
        }
 }
 
@@ -645,11 +685,12 @@ http_SetHeader(int fd, struct http *to, const char *hdr)
 {
 
        CHECK_OBJ_NOTNULL(to, HTTP_MAGIC);
-       to->hd[to->nhd].b = (void*)(uintptr_t)hdr;
-       to->hd[to->nhd].e = strchr(hdr, '\0');
-       assert(to->hd[to->nhd].e != NULL);
-       VSLHT(fd, to, to->nhd);
-       to->nhd++;
+       if (to->nhd >= MAX_HTTP_HDRS) {
+               VSL_stats->losthdr++;
+               VSL(T(to, HTTP_T_LostHeader), fd, "%s", hdr);
+               return;
+       }
+       http_seth(fd, to, to->nhd++, HTTP_T_Header, hdr);
 }
 
 /*--------------------------------------------------------------------*/
@@ -666,13 +707,13 @@ http_PrintfHeader(int fd, struct http *to, const char *fmt, ...)
        n = vsnprintf(to->f, l, fmt, ap);
        if (n + 1 > l || to->nhd >= MAX_HTTP_HDRS) {
                VSL_stats->losthdr++;
-               VSL(SLT_LostHeader, fd, "%s", to->f);
+               VSL(T(to, HTTP_T_LostHeader), fd, "%s", to->f);
        } else {
                assert(to->f < to->e);
                to->hd[to->nhd].b = to->f;
                to->hd[to->nhd].e = to->f + n;
                to->f += n + 1;
-               VSLHT(fd, to, to->nhd);
+               VSLH(HTTP_T_Header, fd, to, to->nhd);
                to->nhd++;
        }
        va_end(ap);

diff --git a/varnish-cache/bin/varnishd/cache_response.c b/varnish-cache/bin/varnishd/cache_response.c
index 7b64b6f50eddb5af72dd6f6c09a09338a848a4f5..78f9c4c7a692ce3aed5ea205d9ce456cba857a1c 100644 (file)
--- a/varnish-cache/bin/varnishd/cache_response.c
+++ b/varnish-cache/bin/varnishd/cache_response.c
@@ -82,6 +82,7 @@ res_do_304(struct sess *sp, char *p)
        VSL(SLT_Length, sp->fd, "%u", 0);
 
        http_ClrHeader(sp->http);
+       sp->http->logtag = HTTP_Tx;
        http_SetResp(sp->fd, sp->http, "HTTP/1.1", "304", "Not Modified");
        http_SetHeader(sp->fd, sp->http, "Via: 1.1 varnish");
        http_PrintfHeader(sp->fd, sp->http, "X-Varnish: %u", sp->xid);
@@ -134,6 +135,7 @@ RES_WriteObj(struct sess *sp)
        VSL(SLT_Length, sp->fd, "%u", sp->obj->len);
 
        http_ClrHeader(sp->http);
+       sp->http->logtag = HTTP_Tx;
        http_CopyResp(sp->fd, sp->http, &sp->obj->http);
        http_FilterHeader(sp->fd, sp->http, &sp->obj->http, HTTPH_A_DELIVER);
        if (sp->xid != sp->obj->xid)

diff --git a/varnish-cache/bin/varnishlog/varnishlog.c b/varnish-cache/bin/varnishlog/varnishlog.c
index 459d99cde9bb35b60c0be290e20b03367fcf276a..b59337405d175302fe23cd01a5c6486b8f40d5ac 100644 (file)
--- a/varnish-cache/bin/varnishlog/varnishlog.c
+++ b/varnish-cache/bin/varnishlog/varnishlog.c
@@ -126,7 +126,7 @@ order(unsigned char *p, int h_opt)
                else
                        v = 1;
                break;
-       case SLT_Request:
+       case SLT_RxRequest:
                if (h_opt && p[1] == 3 && !memcmp(p + 4, "GET", 3))
                        hc[u]++;
                if (h_opt && p[1] == 4 && !memcmp(p + 4, "HEAD", 4))
@@ -137,7 +137,7 @@ order(unsigned char *p, int h_opt)
                xrf[u] = atoi(p + 4);
                v = 1;
                break;
-       case SLT_Status:
+       case SLT_RxStatus:
                if (h_opt && p[1] == 3 && !memcmp(p + 4, "200", 3))
                        hc[u]++;
                v = 1;

diff --git a/varnish-cache/include/shmlog_tags.h b/varnish-cache/include/shmlog_tags.h
index 2a0f83410aa71ca9c51eb61e3b97a22fb7feef56..e7437cda7c28f952dd203188cbb2d78c2b6ddaf3 100644 (file)
--- a/varnish-cache/include/shmlog_tags.h
+++ b/varnish-cache/include/shmlog_tags.h
@@ -24,16 +24,32 @@ SLTM(HttpError)
 SLTM(HttpGarbage)
 SLTM(ClientAddr)
 SLTM(Backend)
-SLTM(Request)
-SLTM(Response)
 SLTM(Length)
-SLTM(Status)
-SLTM(URL)
-SLTM(Protocol)
+
+SLTM(RxRequest)
+SLTM(RxResponse)
+SLTM(RxStatus)
+SLTM(RxURL)
+SLTM(RxProtocol)
 SLTM(RxHeader)
+SLTM(RxLostHeader)
+
+SLTM(TxRequest)
+SLTM(TxResponse)
+SLTM(TxStatus)
+SLTM(TxURL)
+SLTM(TxProtocol)
 SLTM(TxHeader)
+SLTM(TxLostHeader)
+
+SLTM(ObjRequest)
+SLTM(ObjResponse)
+SLTM(ObjStatus)
+SLTM(ObjURL)
+SLTM(ObjProtocol)
 SLTM(ObjHeader)
-SLTM(LostHeader)
+SLTM(ObjLostHeader)
+
 SLTM(TTL)
 SLTM(VCL_acl)
 SLTM(VCL_call)