Commit 3ef1f864 authored by Geoff Simmons's avatar Geoff Simmons

add the %{pvxid}x formatter

parent 342756c9
...@@ -735,7 +735,6 @@ format_vxid(const tx_t *tx, const arg_t *args, char **s, size_t *len) ...@@ -735,7 +735,6 @@ format_vxid(const tx_t *tx, const arg_t *args, char **s, size_t *len)
*len = strlen(*s); *len = strlen(*s);
} }
#if 0
void void
format_pvxid(const tx_t *tx, const arg_t *args, char **s, size_t *len) format_pvxid(const tx_t *tx, const arg_t *args, char **s, size_t *len)
{ {
...@@ -744,7 +743,6 @@ format_pvxid(const tx_t *tx, const arg_t *args, char **s, size_t *len) ...@@ -744,7 +743,6 @@ format_pvxid(const tx_t *tx, const arg_t *args, char **s, size_t *len)
*s = scratch; *s = scratch;
*len = strlen(*s); *len = strlen(*s);
} }
#endif
static void static void
add_fmt(const compiled_fmt_t *fmt, struct vsb *os, unsigned n, add_fmt(const compiled_fmt_t *fmt, struct vsb *os, unsigned n,
...@@ -1138,6 +1136,9 @@ compile_fmt(char * const format, compiled_fmt_t * const fmt, ...@@ -1138,6 +1136,9 @@ compile_fmt(char * const format, compiled_fmt_t * const fmt,
else if (strncmp(fname, "vxid", 4) == 0) { else if (strncmp(fname, "vxid", 4) == 0) {
add_formatter(fmt, os, n, format_vxid); add_formatter(fmt, os, n, format_vxid);
} }
else if (strncmp(fname, "pvxid", 5) == 0) {
add_formatter(fmt, os, n, format_pvxid);
}
else { else {
sprintf(err, "Unknown format starting at: %s", fname); sprintf(err, "Unknown format starting at: %s", fname);
return 1; return 1;
......
...@@ -104,3 +104,4 @@ formatter_f format_VCL_Log; ...@@ -104,3 +104,4 @@ formatter_f format_VCL_Log;
formatter_f format_SLT; formatter_f format_SLT;
formatter_f format_vxid; formatter_f format_vxid;
formatter_f format_pvxid;
...@@ -12,7 +12,7 @@ rm -f $LOG $OUT ...@@ -12,7 +12,7 @@ rm -f $LOG $OUT
../varnishevent -f varnishevent.conf -r sw-doc.log -w $OUT -v ../varnishevent -f varnishevent.conf -r sw-doc.log -w $OUT -v
CKSUM=$( cksum $OUT ) CKSUM=$( cksum $OUT )
if [ "$CKSUM" != "481068350 22573437 $OUT" ]; then if [ "$CKSUM" != "1773971926 22636057 $OUT" ]; then
echo "ERROR: Regression test log output incorrect cksum: $CKSUM" echo "ERROR: Regression test log output incorrect cksum: $CKSUM"
exit 1 exit 1
fi fi
......
...@@ -1340,20 +1340,27 @@ static const char ...@@ -1340,20 +1340,27 @@ static const char
} }
static const char static const char
*test_format_vxid(void) *test_format_p_vxid(void)
{ {
tx_t tx; tx_t tx;
arg_t args; arg_t args;
char *str; char *str;
size_t len; size_t len;
printf("... testing format_vxid()\n"); printf("... testing format_vxid() and format_pvxid()\n");
tx.vxid = 4711; tx.vxid = 4711;
tx.pvxid = 1147;
format_vxid(&tx, &args, &str, &len); format_vxid(&tx, &args, &str, &len);
MASSERT(strncmp(str, "4711", 4) == 0); MASSERT(strncmp(str, "4711", 4) == 0);
MASSERT(len == 4); MASSERT(len == 4);
str = NULL;
len = 0;
format_pvxid(&tx, &args, &str, &len);
MASSERT(strncmp(str, "1147", 4) == 0);
MASSERT(len == 4);
return NULL; return NULL;
} }
...@@ -1392,6 +1399,7 @@ static const char ...@@ -1392,6 +1399,7 @@ static const char
tx.magic = TX_MAGIC; tx.magic = TX_MAGIC;
tx.occupied = 1; tx.occupied = 1;
tx.vxid = 4711; tx.vxid = 4711;
tx.pvxid = 1147;
VSTAILQ_INIT(&tx.lines); VSTAILQ_INIT(&tx.lines);
for (int i = 0; i < NRECS; i++) { for (int i = 0; i < NRECS; i++) {
recs[i] = (logline_t *) calloc(1, sizeof(logline_t)); recs[i] = (logline_t *) calloc(1, sizeof(logline_t));
...@@ -1452,7 +1460,7 @@ static const char ...@@ -1452,7 +1460,7 @@ static const char
"%t %T %{%F-%T.%i}t %U %u %{Varnish:time_firstbyte}x "\ "%t %T %{%F-%T.%i}t %U %u %{Varnish:time_firstbyte}x "\
"%{Varnish:hitmiss}x %{Varnish:handling}x %{VCL_Log:baz}x "\ "%{Varnish:hitmiss}x %{Varnish:handling}x %{VCL_Log:baz}x "\
"%{tag:VCL_acl}x %{tag:Debug}x %{tag:Timestamp:Req}x "\ "%{tag:VCL_acl}x %{tag:Debug}x %{tag:Timestamp:Req}x "\
"%{tag:ReqAcct[0]}x %{tag:Timestamp:Resp[2]}x %{vxid}x" "%{tag:ReqAcct[0]}x %{tag:Timestamp:Resp[2]}x %{vxid}x %{pvxid}x"
strcpy(config.cformat, FULL_CLIENT_FMT); strcpy(config.cformat, FULL_CLIENT_FMT);
status = FMT_Init(err); status = FMT_Init(err);
VMASSERT(status == 0, "FMT_Init: %s", err); VMASSERT(status == 0, "FMT_Init: %s", err);
...@@ -1499,7 +1507,7 @@ static const char ...@@ -1499,7 +1507,7 @@ static const char
"http://bazquux.com/foo?bar=baz&quux=wilco HTTP/1.1 200 "\ "http://bazquux.com/foo?bar=baz&quux=wilco HTTP/1.1 200 "\
"[%d/%b/%Y:%T %z] 0 %F-%T.529143 /foo varnish 0.000166 hit hit "\ "[%d/%b/%Y:%T %z] 0 %F-%T.529143 /foo varnish 0.000166 hit hit "\
"logload MATCH ACL \"10.0.0.0\"/8 \"foo\\0\\377 bar\" " \ "logload MATCH ACL \"10.0.0.0\"/8 \"foo\\0\\377 bar\" " \
"1429213569.602005 0.000000 0.000000 60 0.000125 4711\n" "1429213569.602005 0.000000 0.000000 60 0.000125 4711 1147\n"
tm = localtime(&t); tm = localtime(&t);
MAN(strftime(strftime_s, BUFSIZ, EXP_FULL_CLIENT_OUTPUT, tm)); MAN(strftime(strftime_s, BUFSIZ, EXP_FULL_CLIENT_OUTPUT, tm));
VMASSERT(strcmp(VSB_data(os), strftime_s) == 0, "'%s' != '%s'", VMASSERT(strcmp(VSB_data(os), strftime_s) == 0, "'%s' != '%s'",
...@@ -1512,7 +1520,7 @@ static const char ...@@ -1512,7 +1520,7 @@ static const char
#define FULL_BACKEND_FMT "%b %d %D %H %h %I %{Foo}i %{Bar}o %l %m %O %q %r %s "\ #define FULL_BACKEND_FMT "%b %d %D %H %h %I %{Foo}i %{Bar}o %l %m %O %q %r %s "\
"%t %T %{%F-%T.%i}t %U %u %{Varnish:time_firstbyte}x %{VCL_Log:baz}x "\ "%t %T %{%F-%T.%i}t %U %u %{Varnish:time_firstbyte}x %{VCL_Log:baz}x "\
"%{tag:Fetch_Body}x %{tag:Debug}x %{tag:Timestamp:Bereq}x "\ "%{tag:Fetch_Body}x %{tag:Debug}x %{tag:Timestamp:Bereq}x "\
"%{tag:BereqAcct[5]}x %{tag:Timestamp:Bereq[1]}x %{vxid}x" "%{tag:BereqAcct[5]}x %{tag:Timestamp:Bereq[1]}x %{vxid}x %{pvxid}x"
strcpy(config.bformat, FULL_BACKEND_FMT); strcpy(config.bformat, FULL_BACKEND_FMT);
config.cformat[0] = '\0'; config.cformat[0] = '\0';
status = FMT_Init(err); status = FMT_Init(err);
...@@ -1565,7 +1573,7 @@ static const char ...@@ -1565,7 +1573,7 @@ static const char
"http://bazquux.com/foo?bar=baz&quux=wilco HTTP/1.1 200 "\ "http://bazquux.com/foo?bar=baz&quux=wilco HTTP/1.1 200 "\
"[%d/%b/%Y:%T %z] 0 %F-%T.529143 /foo varnish 0.002837 logload "\ "[%d/%b/%Y:%T %z] 0 %F-%T.529143 /foo varnish 0.002837 logload "\
"2 chunked stream \"foo\\0\\377 bar\" "\ "2 chunked stream \"foo\\0\\377 bar\" "\
"1429210777.728290 0.000048 0.000048 283 0.000048 4711\n" "1429210777.728290 0.000048 0.000048 283 0.000048 4711 1147\n"
tm = localtime(&t); tm = localtime(&t);
MAN(strftime(strftime_s, BUFSIZ, EXP_FULL_BACKEND_OUTPUT, tm)); MAN(strftime(strftime_s, BUFSIZ, EXP_FULL_BACKEND_OUTPUT, tm));
VMASSERT(strcmp(VSB_data(os), strftime_s) == 0, "'%s' != '%s'", VMASSERT(strcmp(VSB_data(os), strftime_s) == 0, "'%s' != '%s'",
...@@ -1673,7 +1681,7 @@ static const char ...@@ -1673,7 +1681,7 @@ static const char
mu_run_test(test_format_VCL_disp); mu_run_test(test_format_VCL_disp);
mu_run_test(test_format_VCL_Log); mu_run_test(test_format_VCL_Log);
mu_run_test(test_format_SLT); mu_run_test(test_format_SLT);
mu_run_test(test_format_vxid); mu_run_test(test_format_p_vxid);
mu_run_test(test_FMT_Fini); mu_run_test(test_FMT_Fini);
mu_run_test(test_FMT_interface); mu_run_test(test_FMT_interface);
......
...@@ -2,8 +2,8 @@ ...@@ -2,8 +2,8 @@
monitor.interval = 0 monitor.interval = 0
cformat=%b %d %D %H %h %I %{Host}i %{Connection}i %{User-Agent}i %{X-Forwarded-For}i %{Accept-Ranges}o %{Age}o %{Connection}o %{Content-Encoding}o %{Content-Length}o %{Content-Type}o %{Date}o %{Last-Modified}o %{Server}o %{Transfer-Encoding}o %{Via}o %{X-Varnish}o %l %m %O %q %r %s %t %{%F-%T}t %U %u %{Varnish:time_firstbyte}x %{Varnish:hitmiss}x %{Varnish:handling}x %{tag:Begin}x %{tag:Debug}x %{tag:End}x %{tag:Gzip}x %{tag:Hit}x %{tag:Length}x %{tag:Link}x %{tag:ReqAcct}x %{tag:ReqStart}x %{tag:RespProtocol}x %{tag:ReqMethod}x %{tag:ReqURL}x %{tag:ReqProtocol}x %{tag:RespReason}x %{tag:RespStatus}x %{tag:Timestamp:Req}x %{tag:ReqAcct[5]}x %{tag:Timestamp:Req[2]}x %{vxid}x cformat=%b %d %D %H %h %I %{Host}i %{Connection}i %{User-Agent}i %{X-Forwarded-For}i %{Accept-Ranges}o %{Age}o %{Connection}o %{Content-Encoding}o %{Content-Length}o %{Content-Type}o %{Date}o %{Last-Modified}o %{Server}o %{Transfer-Encoding}o %{Via}o %{X-Varnish}o %l %m %O %q %r %s %t %{%F-%T}t %U %u %{Varnish:time_firstbyte}x %{Varnish:hitmiss}x %{Varnish:handling}x %{tag:Begin}x %{tag:Debug}x %{tag:End}x %{tag:Gzip}x %{tag:Hit}x %{tag:Length}x %{tag:Link}x %{tag:ReqAcct}x %{tag:ReqStart}x %{tag:RespProtocol}x %{tag:ReqMethod}x %{tag:ReqURL}x %{tag:ReqProtocol}x %{tag:RespReason}x %{tag:RespStatus}x %{tag:Timestamp:Req}x %{tag:ReqAcct[5]}x %{tag:Timestamp:Req[2]}x %{vxid}x %{pvxid}x
bformat=%b %d %D %H %h %I %{Accept-Encoding}i %{Host}i %{User-Agent}i %{X-Forwarded-For}i %{X-Varnish}i %{Accept-Ranges}o %{Connection}o %{Content-Encoding}o %{Content-Length}o %{Content-Type}o %{Date}o %{ETag}o %{Last-Modified}o %{Server}o %{Transfer-Encoding}o %{Vary}o %l %m %O %q %r %s %t %{%F-%T}t %U %u %{Varnish:time_firstbyte}x %{tag:Backend}x %{tag:BackendOpen}x %{tag:BackendClose}x %{tag:BackendReuse}x %{tag:Begin}x %{tag:BereqAcct}x %{tag:Length}x %{tag:BerespProtocol}x %{tag:BerespReason}x %{tag:BerespStatus}x %{tag:BereqProtocol}x %{tag:BereqMethod}x %{tag:BereqURL}x %{tag:Debug}x %{tag:End}x %{tag:Timestamp:Bereq}x %{tag:BereqAcct[5]}x %{tag:Timestamp:Bereq[2]}x %{vxid}x bformat=%b %d %D %H %h %I %{Accept-Encoding}i %{Host}i %{User-Agent}i %{X-Forwarded-For}i %{X-Varnish}i %{Accept-Ranges}o %{Connection}o %{Content-Encoding}o %{Content-Length}o %{Content-Type}o %{Date}o %{ETag}o %{Last-Modified}o %{Server}o %{Transfer-Encoding}o %{Vary}o %l %m %O %q %r %s %t %{%F-%T}t %U %u %{Varnish:time_firstbyte}x %{tag:Backend}x %{tag:BackendOpen}x %{tag:BackendClose}x %{tag:BackendReuse}x %{tag:Begin}x %{tag:BereqAcct}x %{tag:Length}x %{tag:BerespProtocol}x %{tag:BerespReason}x %{tag:BerespStatus}x %{tag:BereqProtocol}x %{tag:BereqMethod}x %{tag:BereqURL}x %{tag:Debug}x %{tag:End}x %{tag:Timestamp:Bereq}x %{tag:BereqAcct[5]}x %{tag:Timestamp:Bereq[2]}x %{vxid}x %{pvxid}x
log.file = test.log log.file = test.log
...@@ -11,7 +11,7 @@ echo "... -g vxid" ...@@ -11,7 +11,7 @@ echo "... -g vxid"
CKSUM=$( ../varnishevent -g vxid -r sw-doc.log -f varnishevent.conf | cksum) CKSUM=$( ../varnishevent -g vxid -r sw-doc.log -f varnishevent.conf | cksum)
# Same as default (no -g arg) # Same as default (no -g arg)
if [ "$CKSUM" != '1569412425 22573475' ]; then if [ "$CKSUM" != '1162093504 22636095' ]; then
echo "ERROR: -g vxid unexpected cksum: $CKSUM" echo "ERROR: -g vxid unexpected cksum: $CKSUM"
exit 1 exit 1
fi fi
...@@ -19,7 +19,7 @@ fi ...@@ -19,7 +19,7 @@ fi
echo "... -g request" echo "... -g request"
CKSUM=$( ../varnishevent -g request -r sw-doc.log -f varnishevent.conf | cksum) CKSUM=$( ../varnishevent -g request -r sw-doc.log -f varnishevent.conf | cksum)
if [ "$CKSUM" != '157371635 22573475' ]; then if [ "$CKSUM" != '2524911127 22637823' ]; then
echo "ERROR: -g request unexpected cksum: $CKSUM" echo "ERROR: -g request unexpected cksum: $CKSUM"
exit 1 exit 1
fi fi
......
...@@ -256,6 +256,7 @@ event(struct VSL_data *vsl, struct VSL_transaction * const pt[], void *priv) ...@@ -256,6 +256,7 @@ event(struct VSL_data *vsl, struct VSL_transaction * const pt[], void *priv)
assert(VSTAILQ_EMPTY(&tx->lines)); assert(VSTAILQ_EMPTY(&tx->lines));
tx->type = t->type; tx->type = t->type;
tx->vxid = t->vxid; tx->vxid = t->vxid;
tx->pvxid = t->vxid_parent;
if (tx->type == VSL_t_raw) if (tx->type == VSL_t_raw)
tx->t = VTIM_real(); tx->t = VTIM_real();
......
...@@ -107,6 +107,7 @@ typedef struct tx_t { ...@@ -107,6 +107,7 @@ typedef struct tx_t {
unsigned magic; unsigned magic;
#define TX_MAGIC 0xff463e42 #define TX_MAGIC 0xff463e42
int32_t vxid; int32_t vxid;
int32_t pvxid;
linehead_t lines; linehead_t lines;
VSTAILQ_ENTRY(tx_t) freelist; VSTAILQ_ENTRY(tx_t) freelist;
VSTAILQ_ENTRY(tx_t) spscq; VSTAILQ_ENTRY(tx_t) spscq;
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment