[PATCH v2 4/4] log: Avoid duplicate calls to logtime()

[David Gibson <david@gibson.dropbear.id.au>]

We use logtime() to get a timestamp for the log in two places:
  - in vlogmsg(), which is used only for debug_print messages
  - in logfile_write() which is only used messages to the log file

These cases are mutually exclusive, so we don't ever print the same message
with different timestamps, but that's not particularly obvious to see.
It's possible future tweaks to logging logic could mean we log to two
different places with different timestamps, which would be confusing.

Refactor to have a single logtime() call in vlogmsg() and use it for all
the places we need it.

Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
---
 log.c | 17 ++++++++---------
 1 file changed, 8 insertions(+), 9 deletions(-)

diff --git a/log.c b/log.c
index 9f4cb7fc..f3799224 100644
--- a/log.c
+++ b/log.c
@@ -225,18 +225,16 @@ static int logfile_rotate(int fd, const struct timespec *now)
  * logfile_write() - Write entry to log file, trigger rotation if full
  * @newline:	Append newline at the end of the message, if missing
  * @pri:	Facility and level map, same as priority for vsyslog()
+ * @now:	Timestamp
  * @format:	Same as vsyslog() format
  * @ap:		Same as vsyslog() ap
  */
-static void logfile_write(bool newline, int pri, const char *format, va_list ap)
+static void logfile_write(bool newline, int pri, const struct timespec *now,
+			  const char *format, va_list ap)
 {
-	const struct timespec *now;
-	struct timespec ts;
 	char buf[BUFSIZ];
 	int n;
 
-	now = logtime(&ts);
-
 	n  = logtime_fmt(buf, BUFSIZ, now);
 	n += snprintf(buf + n, BUFSIZ - n, ": %s", logfile_prefix[pri]);
 
@@ -262,13 +260,14 @@ static void logfile_write(bool newline, int pri, const char *format, va_list ap)
 void vlogmsg(bool newline, int pri, const char *format, va_list ap)
 {
 	bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
+	const struct timespec *now;
+	struct timespec ts;
+
+	now = logtime(&ts);
 
 	if (debug_print) {
 		char timestr[LOGTIME_STRLEN];
-		const struct timespec *now;
-		struct timespec ts;
 
-		now = logtime(&ts);
 		logtime_fmt(timestr, sizeof(timestr), now);
 		fprintf(stderr, "%s: ", timestr);
 	}
@@ -278,7 +277,7 @@ void vlogmsg(bool newline, int pri, const char *format, va_list ap)
 
 		va_copy(ap2, ap); /* Don't clobber ap, we need it again */
 		if (log_file != -1)
-			logfile_write(newline, pri, format, ap2);
+			logfile_write(newline, pri, now, format, ap2);
 		else if (!(log_mask & LOG_MASK(LOG_DEBUG)))
 			passt_vsyslog(newline, pri, format, ap2);
 
-- 
@@ -225,18 +225,16 @@ static int logfile_rotate(int fd, const struct timespec *now)
  * logfile_write() - Write entry to log file, trigger rotation if full
  * @newline:	Append newline at the end of the message, if missing
  * @pri:	Facility and level map, same as priority for vsyslog()
+ * @now:	Timestamp
  * @format:	Same as vsyslog() format
  * @ap:		Same as vsyslog() ap
  */
-static void logfile_write(bool newline, int pri, const char *format, va_list ap)
+static void logfile_write(bool newline, int pri, const struct timespec *now,
+			  const char *format, va_list ap)
 {
-	const struct timespec *now;
-	struct timespec ts;
 	char buf[BUFSIZ];
 	int n;
 
-	now = logtime(&ts);
-
 	n  = logtime_fmt(buf, BUFSIZ, now);
 	n += snprintf(buf + n, BUFSIZ - n, ": %s", logfile_prefix[pri]);
 
@@ -262,13 +260,14 @@ static void logfile_write(bool newline, int pri, const char *format, va_list ap)
 void vlogmsg(bool newline, int pri, const char *format, va_list ap)
 {
 	bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
+	const struct timespec *now;
+	struct timespec ts;
+
+	now = logtime(&ts);
 
 	if (debug_print) {
 		char timestr[LOGTIME_STRLEN];
-		const struct timespec *now;
-		struct timespec ts;
 
-		now = logtime(&ts);
 		logtime_fmt(timestr, sizeof(timestr), now);
 		fprintf(stderr, "%s: ", timestr);
 	}
@@ -278,7 +277,7 @@ void vlogmsg(bool newline, int pri, const char *format, va_list ap)
 
 		va_copy(ap2, ap); /* Don't clobber ap, we need it again */
 		if (log_file != -1)
-			logfile_write(newline, pri, format, ap2);
+			logfile_write(newline, pri, now, format, ap2);
 		else if (!(log_mask & LOG_MASK(LOG_DEBUG)))
 			passt_vsyslog(newline, pri, format, ap2);
 
-- 
2.45.2