[master] f84d3edbc varnishncsa: Add %{sec, msec, usec, msec_frac, usec_frac}t specification

[Nils Goroll]

commit f84d3edbc8476cf847976b6bfe2e7b6bcaa56f25
Author: Nils Goroll <nils.goroll at uplex.de>
Date:   Mon Apr 26 13:35:59 2021 +0200

    varnishncsa: Add %{sec,msec,usec,msec_frac,usec_frac}t specification
    
    ... following the example of Apache HTTP Server, see
    http://httpd.apache.org/docs/current/mod/mod_log_config.html

diff --git a/bin/varnishncsa/varnishncsa.c b/bin/varnishncsa/varnishncsa.c
index ba01a98d5..32a6943dc 100644
--- a/bin/varnishncsa/varnishncsa.c
+++ b/bin/varnishncsa/varnishncsa.c
@@ -257,7 +257,7 @@ format_fragment(const struct format *format)
 static int v_matchproto_(format_f)
 format_time(const struct format *format)
 {
-	double t_start, t_end;
+	double t_start, t_end, d;
 	char *p;
 	char buf[64];
 	time_t t;
@@ -295,6 +295,21 @@ format_time(const struct format *format)
 		AN(strftime(buf, sizeof buf, format->time_fmt, &tm));
 		AZ(VSB_cat(CTX.vsb, buf));
 		return (1);
+	case '3':
+		l = (long)(modf(t_start, &d) * 1e3);
+		break;
+	case '6':
+		l = (long)(modf(t_start, &d) * 1e6);
+		break;
+	case 'S':
+		l = (long)t_start;
+		break;
+	case 'M':
+		l = (long)(t_start * 1e3);
+		break;
+	case 'U':
+		l = (long)(t_start * 1e6);
+		break;
 	case 's':
 		l = (long)(t_end - t_start);
 		break;
@@ -450,16 +465,39 @@ addf_time(char type, const char *fmt)
 	AN(f->time_fmt);
 
 	if (f->time_type == 'T') {
-		if (!strcmp(f->time_fmt, "s"))
+		if (!strcmp(fmt, "s"))
 			f->time_type = 's';
-		else if (!strcmp(f->time_fmt, "ms"))
+		else if (!strcmp(fmt, "ms"))
 			f->time_type = 'm';
-		else if (!strcmp(f->time_fmt, "us"))
+		else if (!strcmp(fmt, "us"))
 			f->time_type = 'u';
 		else
 			VUT_Error(vut, 1, "Unknown specifier: %%{%s}T",
-			    f->time_fmt);
+			    fmt);
 		REPLACE(f->time_fmt, "%ld");
+	} else if (f->time_type == 't') {
+		if (!strcmp(fmt, "sec")) {
+			f->time_type = 'S';
+			REPLACE(f->time_fmt, "%ld");
+		} else if (!strncmp(fmt, "msec", 4)) {
+			fmt += 4;
+			if (!strcmp(fmt, "_frac")) {
+				f->time_type = '3';
+				REPLACE(f->time_fmt, "%03ld");
+			} else if (*fmt == '\0') {
+				f->time_type = 'M';
+				REPLACE(f->time_fmt, "%ld");
+			}
+		} else if (!strncmp(fmt, "usec", 4)) {
+			fmt += 4;
+			if (!strcmp(fmt, "_frac")) {
+				f->time_type = '6';
+				REPLACE(f->time_fmt, "%06ld");
+			} else if (*fmt == '\0') {
+				f->time_type = 'U';
+				REPLACE(f->time_fmt, "%ld");
+			}
+		}
 	}
 
 	VTAILQ_INSERT_TAIL(&CTX.format, f, list);
diff --git a/bin/varnishtest/tests/u00003.vtc b/bin/varnishtest/tests/u00003.vtc
index ee598b1e6..3cfa187de 100644
--- a/bin/varnishtest/tests/u00003.vtc
+++ b/bin/varnishtest/tests/u00003.vtc
@@ -150,9 +150,10 @@ req (\d+) rxreq \5 - - - -$} \
 %{VSL:Timestamp:Resp[2]}x %{VSL:Timestamp:foo}x %{VSL:ReqURL[2]}x"}
 
 # times
-shell -match {^\{\d{4}-\d{2}-\d{2}\}T\{\d{2}:\d{2}:\d{2}\} \{\{\d{4}-\d{2}-\d{2}\T\d{2}:\d{2}:\d{2}\}\} \d+ \d+ \d+} \
+shell -match {^\{\d{4}-\d{2}-\d{2}\}T\{\d{2}:\d{2}:\d{2}\} \{\{\d{4}-\d{2}-\d{2}\T\d{2}:\d{2}:\d{2}\}\} \d+ \d+ \d+ \d{10,} \d{13,} \d{16,} \d{3} \d{6} usecx msecy} \
 	{varnishncsa -n ${v1_name} -d -F "%{{%F}T{%T}}t %{{{%FT%T}}}t \
-%{s}T %{ms}T %{us}T"}
+%{s}T %{ms}T %{us}T %{sec}t %{msec}t %{usec}t %{msec_frac}t %{usec_frac}t \
+%{usecx}t %{msecy}t"}
 
 process p1 -stop -screen-dump
 process p1 -expect-text 1 0 {/1?foo=bar HTTP/1.1" 200 100 "-" "-"}
diff --git a/doc/sphinx/reference/varnishncsa.rst b/doc/sphinx/reference/varnishncsa.rst
index 489690866..ceb115b5e 100644
--- a/doc/sphinx/reference/varnishncsa.rst
+++ b/doc/sphinx/reference/varnishncsa.rst
@@ -138,7 +138,17 @@ Supported formatters are:
 %{X}t
   In client mode, time when the request was received, in the format
   specified by X.  In backend mode, time when the request was sent.
-  The time specification format is the same as for strftime(3).
+  The time specification format is the same as for strftime(3) with
+  these extensions:
+
+  * ``%{sec}``: number of seconds since the Epoch
+  * ``%{msec}``: number of milliseconds since the Epoch
+  * ``%{usec}``: number of milliseconds since the Epoch
+  * ``%{msec_frac}``: millisecond fraction
+  * ``%{usec_frac}``: microsecond fraction
+
+  The extensions can not be combined with each other or strftime(3) in
+  the same specification. Use multiple ``%{X}t`` specifications instead.
 
 %T
   In client mode, time taken to serve the request, in seconds.  In