Elukey has submitted this change and it was merged.
Change subject: Extend the %{format}t timestamp formatter with the 'end:' prefix
......................................................................
Extend the %{format}t timestamp formatter with the 'end:' prefix
The current code stores the time-format string configured for %{time-format}t
in tag->var; then it leverages TAG_F_NOVARMATCH to avoid any match
between each Varnish tag. This does not allow to match the various SLT_Timestamp
types (Start, Resp, etc..) with tag->var. To correct this, I implemented the
following
convention inspired by the Apache log format specifications:
http://httpd.apache.org/docs/current/mod/mod_log_config.html#formats
If the timestamp format starts with the 'end:' prefix then the SLT_Timestamp
'Resp'
will be chosen for each request, otherwise the default will be 'Start'.
The 'end' prefix will be removed from the output.
TAG_F_NOVARMATCH is also removed completely in favor of a more clean
TAG_F_TIMESTAMP flag.
Bug: T136314
Change-Id: Ib20b0cc6fa8ecc2fd6f1fe899d0c5d630681c373
---
M varnishkafka.c
M varnishkafka.conf.example
M varnishkafka.h
3 files changed, 124 insertions(+), 62 deletions(-)
Approvals:
Elukey: Verified; Looks good to me, approved
Ottomata: Looks good to me, but someone else must approve
BBlack: Looks good to me, but someone else must approve
diff --git a/varnishkafka.c b/varnishkafka.c
index b928bb3..1ab6980 100644
--- a/varnishkafka.c
+++ b/varnishkafka.c
@@ -318,7 +318,8 @@
/* Allocate initial space for escaped string.
- * The maximum expansion size per character is 5 (octal coding). */
+ * The maximum expansion size per character is 5 (octal coding).
+ */
const size_t in_len = *len;
char dst[in_len * 5];
char *d = dst;
@@ -554,18 +555,28 @@
const int timelen = 64;
size_t tlen;
- /* Use config-supplied time formatting */
- if (tag->var)
- timefmt = tag->var;
-
- if (tag->tag == SLT_BereqHeader) {
- if (unlikely(!strptime(strndupa(ptr, len),
- "%a, %d %b %Y %T", &tm)))
- return 0;
- } else {
- time_t t = strtoul(ptr, NULL, 10);
- localtime_r(&t, &tm);
+ /*
+ * The special format for tag->var "end:strftime" is used
+ * to force Varnishkafka to use the SLT_Timestamp 'Resp' instead
+ * of 'Start' for timestamp formatters. The prefix is removed
+ * from 'timefmt' accordingly.
+ */
+ if (tag->var){
+ const char *fmt_tmp = tag->var;
+ // Remove APACHE_LOG_END_PREFIX from the format string
+ if (tag->flags & TAG_F_TIMESTAMP_END) {
+ fmt_tmp += strlen(APACHE_LOG_END_PREFIX);
+ }
+ /* If the rest of the format string without the
+ * 'end:' prefix is not empty, use it
+ * in place of the default.
+ */
+ if (*fmt_tmp)
+ timefmt = fmt_tmp;
}
+
+ time_t t = strtoul(ptr, NULL, 10);
+ localtime_r(&t, &tm);
char dst[timelen];
@@ -741,7 +752,26 @@
*/
struct {
/* A formatter may be backed by multiple tags.
- * The first matching tag observed in the log will be used. */
+ * The first matching tag observed in the log will be used.
+ *
+ * Example:
+ * A formatter declared as following in 'map':
+ * ['x'] = { {
+ * { VSL_CLIENTMARKER, SLT_Timestamp,
+ * .var = "Process",
+ * .fmtvar = "Varnish:time_firstbyte", .col = 2
},
+ * { VSL_CLIENTMARKER, SLT_Begin,
+ * .fmtvar = "Varnish:xvid", .col = 2 }
+ * } },
+ *
+ * In this case, the struct below is replicated two
+ * times to match the 'x' formatter to multiple
+ * Varnish tags (establishing also a priority).
+ * Therefore, supposing that 'x' corresponds to 'map[42]',
+ * the following variables will be accessible:
+ * - map[42].f[0].var ==> "Process"
+ * - map[42].f[1].fmtvar ==> "Varnish:xvid"
+ */
struct {
/* VSL_CLIENTMARKER or VSL_BACKENDMARKER, or both */
int spec;
@@ -786,7 +816,6 @@
* (for perf reason the field passed is pointer to
* the start of the substring in the original payload
* plus its length, keep it in mind when writing a parser).
- *
*/
['b'] = { {
/* Size of response in bytes, with HTTP
headers. */
@@ -845,20 +874,10 @@
.tag_flags = TAG_F_LAST }
} },
['t'] = { {
- /* Time the request was received.
- * TAG_F_NOVARMATCH forces varnishkafka to avoid
- * any sort of var comparison so the .var field
is
- * not usable for this option. This flag is
needed
- * since 'var' in %{<strftime-format>}t gets
- * the '<strftime-format>' value, that is not
- * usable for tag match operations.
- * The only option available is:
- * - Start timestamp (TAG_F_NOVARMATCH needs to
be set)
- */
{ VSL_CLIENTMARKER, SLT_Timestamp,
.col = 2,
.parser = parse_t,
- .tag_flags = TAG_F_NOVARMATCH }
+ .tag_flags = TAG_F_TIMESTAMP }
} },
['U'] = { {
/* The URL path requested, not including any
query string. */
@@ -881,7 +900,6 @@
.parser = parse_vcl_handling },
{ VSL_CLIENTMARKER, SLT_VCL_Log,
.fmtvar = "VCL_Log:*" },
-
} },
['n'] = { {
{ VSL_CLIENTMARKER, VSL_TAG__ONCE,
@@ -1077,6 +1095,23 @@
for (i = 0 ; map[(int)*s].f[i].spec ; i++) {
if (map[(int)*s].f[i].tag == 0)
continue;
+
+ /* The %{format}t formatter handles SLT_Timestamp tags.
+ * Its format allows the use of a prefix like "end:"
+ * to specify what SLT_Timestamp tag to pick:
+ * - "end:" corresponds to Varnish "Resp" timestamp.
+ * - Anything else will default to Varnish "Start"
timestamp.
+ * This check is useful to find string prefixes in all
+ * the %{}t timestamp formatters and store the result
among its tags
+ * to avoid repeating the same operation at run time
for each
+ * request (wasting resources).
+ */
+ if ((map[(int)*s].f[i].tag_flags & TAG_F_TIMESTAMP) &&
var) {
+ if (strncmp(var, APACHE_LOG_END_PREFIX,
+ strlen(APACHE_LOG_END_PREFIX))
== 0) {
+ map[(int)*s].f[i].tag_flags |=
TAG_F_TIMESTAMP_END;
+ }
+ }
/* mapping has fmtvar specified, make sure it
* matches the format's variable. */
@@ -1481,33 +1516,14 @@
if (!(tag->spec & spec))
continue;
- /*
- * TAG_F_NOVARMATCH is a special flag used for format tags like
- * %{<strftime-format>}t because the related tag->var value
- * is not usable.
- * The only use case at the moment is represented by the
SLT_Timestamp
- * tag that occurs multiple times during the request processing.
- * The format is always the same, for example:
- * Start: 1464628135.916033 0.000885 0.000084
- * TAG_F_NOVARMATCH avoids the match between the tag 't' var
- * specified in format_parse and the content of ptr since 'var'
- * in %{<strftime-format>}t gets the '<strftime-format>' string
value
- * (not usable for comparison with the content of the ptr
payload).
- * This means that at the moment the only possible match for
't' is:
- * - Start timestamp (TAG_F_NOVARMATCH needs to be set).
- * This feature is not really flexible and it would need to be
improved
- * in the future to let the users to specify the desired
Timestamp in
- * their config files, rather than forcing it in the code.
- */
- if ((tag->var) && !(tag->flags & TAG_F_NOVARMATCH)) {
+ if ((tag->var) && !(tag->flags & TAG_F_TIMESTAMP)){
const char *t;
/* Get the occurence of ":" in ("Varname: value") */
if (!(t = strnchr(ptr, len, ':')))
continue;
- /*
- * Variable match ("Varname: value") checks:
+ /* Variable match ("Varname: value") checks:
* 1) the len of the substring before the ':' (Varname)
needs
* to match the len of the tag requested.
* 2) strncasecmp between ptr (up to tag->varlen chars)
and
@@ -1531,6 +1547,38 @@
ptr2 = NULL;
}
+ } else if (tag->flags & TAG_F_TIMESTAMP) {
+ /* The TAG_F_TIMESTAMP is related to the %{format}t
+ * output formatter available in the config.
+ * This formatter is special because tag->var gets
populared
+ * with a string like '%FT%T', that represents a
strftime
+ * compatible formatter, meanwhile there are multiple
+ * Varnish timestamp to choose (like Start, Resp,
etc..) that
+ * can't be easily be matched comparing the Varnish tag
read
+ * and tag->var. To add some flexibility, these are the
+ * allowed formats:
+ * 1) %{end:strftime_formatter}t
+ * 2) %{strftime_formatter}t
+ * The "end:" prefix will force Varnishkafka to pick the
+ * SLT_timestamp "Resp" timestamp, meanwhile the
default is to
+ * use the "Start" one.
+ * Help to read the if conditions: strncmp returns 0 if
the two
+ * strings are equal (up to some amount of chars) so
the not
+ * operator is needed.
+ */
+ if (!(tag->flags & TAG_F_TIMESTAMP_END)
+ && !strncmp(ptr, SLT_TIMESTAMP_START,
+ strlen(SLT_TIMESTAMP_START))) {
+ ptr2 = ptr;
+ len2 = len;
+ } else if ((tag->flags & TAG_F_TIMESTAMP_END)
+ && !strncmp(ptr, SLT_TIMESTAMP_RESP,
+
strlen(SLT_TIMESTAMP_RESP))) {
+ ptr2 = ptr;
+ len2 = len;
+ } else {
+ continue;
+ }
} else {
ptr2 = ptr;
len2 = len;
diff --git a/varnishkafka.conf.example b/varnishkafka.conf.example
index d854bab..d47dea5 100644
--- a/varnishkafka.conf.example
+++ b/varnishkafka.conf.example
@@ -67,6 +67,12 @@
# Additional formatter specials: #
# %{<strftime-format>}t - format timestamp according to supplied #
# strftime(3) compatible format string. #
+# If the format starts with 'end:' #
+# the SLT_Timestamp used is 'Resp' #
+# (end of the request processing), #
+# otherwise SLT_Timestamp 'Start' #
+# will be used. #
+# #
# %{Varnish:xid}x - transaction id of client request. #
# Same value as X-Varnish header #
# #
diff --git a/varnishkafka.h b/varnishkafka.h
index a838e73..e07d576 100644
--- a/varnishkafka.h
+++ b/varnishkafka.h
@@ -5,24 +5,24 @@
* Copyright (c) 2013 Magnus Edenhill <[email protected]>
*
* All rights reserved.
- *
+ *
* Redistribution and use in source and binary forms, with or without
- * modification, are permitted provided that the following conditions are met:
- *
+ * 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.
+ * 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.
- *
+ * and/or other materials provided with the distribution.
+ *
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS 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 THE COPYRIGHT OWNER 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
+ * 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 THE COPYRIGHT OWNER 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.
@@ -89,11 +89,19 @@
const char *ptr, size_t len);
int col;
int flags;
-#define TAG_F_NOVARMATCH 0x1 /* Dont attempt to match tag->var to input */
-#define TAG_F_LAST 0x2 /* If multiple, log last one not first one */
+#define TAG_F_TIMESTAMP 1 /* var is a SLT_Timestamp formatter */
+#define TAG_F_TIMESTAMP_END 1<<2 /* var contains the end prefix */
+#define TAG_F_LAST 1<<3 /* If multiple, log last one not first one
*/
};
/**
+ * String constants to be used to parse the %{format}t formatter.
+ */
+#define APACHE_LOG_END_PREFIX "end:"
+#define SLT_TIMESTAMP_START "Start"
+#define SLT_TIMESTAMP_RESP "Resp"
+
+/**
* Formatting from format
*/
struct fmt {
--
To view, visit https://gerrit.wikimedia.org/r/292172
To unsubscribe, visit https://gerrit.wikimedia.org/r/settings
Gerrit-MessageType: merged
Gerrit-Change-Id: Ib20b0cc6fa8ecc2fd6f1fe899d0c5d630681c373
Gerrit-PatchSet: 14
Gerrit-Project: operations/software/varnish/varnishkafka
Gerrit-Branch: master
Gerrit-Owner: Elukey <[email protected]>
Gerrit-Reviewer: BBlack <[email protected]>
Gerrit-Reviewer: Elukey <[email protected]>
Gerrit-Reviewer: Ema <[email protected]>
Gerrit-Reviewer: Ottomata <[email protected]>
_______________________________________________
MediaWiki-commits mailing list
[email protected]
https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits
