[master] c4860b99d This is an ugly but relevant optimization of VSL timestamp production, so we apply it only where it makes most difference.

[Poul-Henning Kamp]

commit c4860b99d96990df3d13d24c7a4c96c898a910f0
Author: Poul-Henning Kamp <phk at FreeBSD.org>
Date:   Mon Jun 17 07:30:28 2019 +0000

    This is an ugly but relevant optimization of VSL timestamp production,
    so we apply it only where it makes most difference.
    
    The hard work done by:  slink
    
    Closes: 2792

diff --git a/bin/varnishd/cache/cache_shmlog.c b/bin/varnishd/cache/cache_shmlog.c
index 3465bd2de..836b53966 100644
--- a/bin/varnishd/cache/cache_shmlog.c
+++ b/bin/varnishd/cache/cache_shmlog.c
@@ -371,19 +371,26 @@ VSLb(struct vsl_log *vsl, enum VSL_tag_e tag, const char *fmt, ...)
 	va_end(ap);
 }
 
+#define Tf6 "%ju.%06u"
+#define Ta6(t) (uintmax_t)floor((t)), (uint32_t)floor((t) * 1e6) % 1000000U
+
 void
 VSLb_ts(struct vsl_log *vsl, const char *event, vtim_real first,
     vtim_real *pprev, vtim_real now)
 {
 
-	/* XXX: Make an option to turn off some unnecessary timestamp
-	   logging. This must be done carefully because some functions
-	   (e.g. V1L_Open) takes the last timestamp as its initial
-	   value for timeout calculation. */
+	/*
+	 * XXX: Make an option to turn off some unnecessary timestamp
+	 * logging. This must be done carefully because some functions
+	 * (e.g. V1L_Open) takes the last timestamp as its initial
+	 * value for timeout calculation.
+	 */
 	vsl_sanity(vsl);
+	AN(event);
+	AN(pprev);
 	assert(!isnan(now) && now != 0.);
-	VSLb(vsl, SLT_Timestamp, "%s: %.6f %.6f %.6f",
-	    event, now, now - first, now - *pprev);
+	VSLb(vsl, SLT_Timestamp, "%s: " Tf6 " " Tf6 " " Tf6,
+	    event, Ta6(now), Ta6(now - first), Ta6(now - *pprev));
 	*pprev = now;
 }