varnishevent: - added the {tag:Foo} formatter

              - fixed a bug parsing fields from data
              - now ignoring SessionClose and StatSess

bin/varnishevent/varnishevent.c

@@ -148,6 +148,11 @@ collect(struct logline_t *lp, enum VSL_tag_e tag, unsigned spec,
     char *dest;
     unsigned *llen;
 
+    /* These can come on a client connection after ReqEnd
+       XXX: ignore for now */
+    if (tag == SLT_SessionClose || tag == SLT_StatSess)
+        return;
+    
     if (spec & VSL_S_BACKEND || spec & VSL_S_CLIENT) {
         if (!lp->spec)
             lp->spec = spec;

bin/varnishevent/writer.c

@@ -84,7 +84,7 @@ static unsigned	wrt_nfree;
    reader can be limited to only read the needed tags. */
 static const char *cformat;
 static const char *bformat
-    = "%t dir=%d url=[%U] qs=[%q] rc=[%s] len=[%b] xid=[%{X-Varnish}i]";
+    = "%t dir=%d url=[%U] rc=[%s] len=[%b] xid=[%{X-Varnish}i] fetch_body=[%{tag:Fetch_Body}x]";
 
 
 static struct vsb *os;
@@ -134,14 +134,16 @@ get_hdr(const char *hdr, hdr_t *tbl)
 #define GET_HDR(ll, dir, hdr) get_hdr((hdr), &(ll)-> dir## _headers)
 
 static inline char *
-get_fld(char *s, int n)
+get_fld(record_t *rec, int n)
 {
-    char *ret = NULL, *str = s;
+    char *ret = NULL, *s, str[MAX_RECLEN];
     int i = 0;
 
+    strncpy(str, rec->data, rec->len);
+    s = str;
     do {
-        ret = strtok(str, " \t");
-        str = NULL;
+        ret = strtok(s, " \t");
+        s = NULL;
     } while (++i < n && ret != NULL);
     
     return ret;
@@ -149,13 +151,13 @@ get_fld(char *s, int n)
 
 static inline int
 get_tm(logline_t *ll, struct tm * t) {
-    char *ts = NULL, *date = NULL;
+    char *ts = NULL;
     record_t *date_rec = NULL;
     time_t tt = 0;
             
     if (C(ll)) {
         if (ll->tag[SLT_ReqEnd].len) {
-            ts = get_fld(ll->tag[SLT_ReqEnd].data, 2);
+            ts = get_fld(&ll->tag[SLT_ReqEnd], 2);
             tt = (time_t) atol(ts);
         }
         else
@@ -163,16 +165,14 @@ get_tm(logline_t *ll, struct tm * t) {
     }
     else {
         if (ll->tag[SLT_BackendReq].len) {
-            ts = get_fld(ll->tag[SLT_BackendReq].data, 2);
+            ts = get_fld(&ll->tag[SLT_BackendReq], 2);
             tt = (time_t) (atol(ts) + TIM_real_mono_diff);
         }
         else
             date_rec = GET_HDR(ll, tx, "Date");
     }
-    if (date_rec) {
-        date = &date_rec->data[strlen("Date: ")];
-        tt = TIM_parse(date);
-    }
+    if (date_rec)
+        tt = TIM_parse(&date_rec->data[strlen("Date: ")]);
     if (tt != 0) {
         localtime_r(&tt, t);
         return 1;
@@ -229,7 +229,7 @@ wrt_write_client(logline_t *ll)
             break;
             
         case 'h':
-            VSB_cat(os, get_fld(ll->tag[SLT_ReqStart].data, 0));
+            VSB_cat(os, get_fld(&ll->tag[SLT_ReqStart], 0));
             break;
             
         case 'l':
@@ -366,7 +366,7 @@ wrt_write_client(logline_t *ll)
             case 'x':
                 if (strcmp(fname, "Varnish:time_firstbyte") == 0) {
                     if (ll->tag[SLT_ReqEnd].len)
-                        VSB_cat(os, get_fld(ll->tag[SLT_ReqEnd].data, 5));
+                        VSB_cat(os, get_fld(&ll->tag[SLT_ReqEnd], 5));
                     p = tmp;
                     break;
                 }
@@ -395,6 +395,20 @@ wrt_write_client(logline_t *ll)
                     p = tmp;
                     break;
                 }
+                else if (strncmp(fname, "tag:", 4) == 0) {
+                    int t = 0;
+                    
+                    /* retrieve the tag contents from the log */
+                    if ((t = VSL_Name2Tag(fname+4, strlen(fname+4))) < 0) {
+                        fprintf(stderr, "Unknown or non-unique tag %s\n",
+                                fname+4);
+                        exit(1);
+                    }
+                    if (ll->tag[t].len)
+                        VSB_REC_CAT(os, ll->tag[t]);
+                    p = tmp;
+                    break;
+                }
             default:
                 /* XXX: logging */
                 fprintf(stderr, "Unknown format starting at: %s\n", --p);
@@ -457,7 +471,7 @@ wrt_write_backend(logline_t *ll)
             
         case 'h':
             if (ll->tag[SLT_BackendOpen].len)
-                VSB_cat(os, get_fld(ll->tag[SLT_BackendOpen].data, 0));
+                VSB_cat(os, get_fld(&ll->tag[SLT_BackendOpen], 0));
             else if (ll->tag[SLT_BackendReuse].len)
                 VSB_REC_CAT(os, ll->tag[SLT_BackendReuse]);
             else if (ll->tag[SLT_BackendClose].len)
@@ -603,12 +617,11 @@ wrt_write_backend(logline_t *ll)
                         char ttfb[12];
                         
                         errno = 0;
-                        req_end
-                            = strtod(get_fld(ll->tag[SLT_BackendReq].data, 2),
-                                     NULL);
+                        req_end = strtod(get_fld(&ll->tag[SLT_BackendReq], 2),
+                                         NULL);
                         AZ(errno);
                         fetch_start
-                            = strtod(get_fld(ll->tag[SLT_BackendReq].data, 2),
+                            = strtod(get_fld(&ll->tag[SLT_Fetch_Hdr], 2),
                                      NULL);
                         AZ(errno);
                         sprintf(ttfb, "%.9f", fetch_start - req_end);
@@ -642,6 +655,20 @@ wrt_write_backend(logline_t *ll)
                     p = tmp;
                     break;
                 }
+                else if (strncmp(fname, "tag:", 4) == 0) {
+                    int t = 0;
+                    
+                    /* retrieve the tag contents from the log */
+                    if ((t = VSL_Name2Tag(fname+4, strlen(fname+4))) < 0) {
+                        fprintf(stderr, "Unknown or non-unique tag %s\n",
+                                fname+4);
+                        exit(1);
+                    }
+                    if (ll->tag[t].len)
+                        VSB_REC_CAT(os, ll->tag[t]);
+                    p = tmp;
+                    break;
+                }
             default:
                 /* XXX: logging */
                 fprintf(stderr, "Unknown format starting at: %s\n", --p);