[PATCH v3 2/3] syslogd: Unify messages with client timestamps when both PRECISE and UTC are enabled.

[Grant Erickson]

This unifies the handling of messages with a client-generated
timestamps when both ENABLE_FEATURE_SYSLOGD_PRECISE_TIMESTAMPS and
ENABLE_FEATURE_SYSLOGD_UTC are asserted.

In particular, to support the intermix of client-generated and
server-generated timestamps, the former are zero-padded such that the
timestamp "column" of a log file is consistent in format.

Signed-off-by: Grant Erickson <gerickson at nuovations.com>
---
 sysklogd/syslogd.c | 123 +++++++++++++++++++++++++++++----------------
 1 file changed, 81 insertions(+), 42 deletions(-)

diff --git a/sysklogd/syslogd.c b/sysklogd/syslogd.c
index b231990b7f6e..0894693c4580 100644
--- a/sysklogd/syslogd.c
+++ b/sysklogd/syslogd.c
@@ -833,25 +833,47 @@ static void parse_fac_prio_20(int pri, char *res20)
 	snprintf(res20, 20, "<%d>", pri);
 }
 
-static char *timestamp_from_time(const time_t *time)
+static void get_time(struct timeval *tvp)
 {
-	char *timestamp = NULL;
+	if (tvp) {
+#if ENABLE_FEATURE_SYSLOGD_PRECISE_TIMESTAMPS || ENABLE_FEATURE_SYSLOGD_ISO8601FMT
+		xgettimeofday(tvp);
+#else
+		time(&tvp->tv_sec);
+#endif
+	}
+}
+
+static struct tm * decompose_time(struct timeval *tvp, struct tm *tmp)
+{
+	struct tm *tm;
 
-	if (time) {
 #if ENABLE_FEATURE_SYSLOGD_UTC
-		if (option_mask32 & OPT_utc)
-			timestamp = asctime(gmtime(time));
-		else
-			timestamp = asctime(localtime(time));
+	if (option_mask32 & OPT_utc)
+		tm = gmtime_r(&tvp->tv_sec, tmp);
+	else
+		tm = localtime_r(&tvp->tv_sec, tmp);
 #else
-		timestamp = ctime(time);
+	tm = localtime_r(&tvp->tv_sec, tmp);
 #endif
-		timestamp += 4; /* skip day of week */
+
+	return tm;
+}
+
+static struct tm * generate_time(struct timeval *tvp, struct tm *tmp)
+{
+	struct tm *tm = NULL;
+
+	if (tvp && tmp) {
+		get_time(tvp);
+
+		tm = decompose_time(tvp, tmp);
 	}
 
-	return timestamp;
+	return tm;
 }
 
+
 /* len parameter is used only for "is there a timestamp?" check.
  * NB: some callers cheat and supply len==0 when they know
  * that there is no timestamp, short-circuiting the test. */
@@ -863,56 +885,73 @@ static void timestamp_and_log(int pri, char *msg, int len)
 		msg[ 3] == ' ' && msg[ 6] == ' ' &&
 		msg[ 9] == ':' && msg[12] == ':' &&
 		msg[15] == ' ');
+	const char *format="%h %e %T";
 	char *timestamp = NULL;
-	time_t now;
+	char timestampbuf[20];
+	/* MMM DD hh:mm:ss default */
+	/* 0123456789012345                 - 16 */
+	/* MMM DD hh:mm:ss.mmm ENABLE_FEATURE_SYSLOGD_PRECISE_TIMESTAMPS */
+	/* 01234567890123456789             - 20 */
+	struct timeval tvnow;
+#if ENABLE_FEATURE_SYSLOGD_PRECISE_TIMESTAMPS || ENABLE_FEATURE_SYSLOGD_UTC
+	struct tm parsed;
+#endif
+	struct tm tmnow, *tmp = NULL;
+	size_t n = 0;
 
 	if (msg_has_timestamp) {
 		if (!(option_mask32 & OPT_timestamp)) {
 			/* use message timestamp */
+#if ENABLE_FEATURE_SYSLOGD_PRECISE_TIMESTAMPS || ENABLE_FEATURE_SYSLOGD_UTC
+			struct tm local;
+			get_time(&tvnow);
+			localtime_r(&tvnow.tv_sec, &local);
+			if (strptime(msg, format, &parsed) != NULL) {
+				parsed.tm_gmtoff    = local.tm_gmtoff;
+				parsed.tm_zone      = local.tm_zone;
+				parsed.tm_year      = local.tm_year;
+				parsed.tm_isdst     = local.tm_isdst;
+
+				tvnow.tv_sec  = mktime(&parsed);
+				tvnow.tv_usec = 0;
+
 #if ENABLE_FEATURE_SYSLOGD_UTC
-			if (option_mask32 & OPT_utc) {
-				struct tm parsed, local;
-				now = time(NULL);
-				localtime_r(&now, &local);
-				if (strptime(msg, "%h %e %T", &parsed) != NULL) {
-					parsed.tm_gmtoff	= local.tm_gmtoff;
-					parsed.tm_zone		= local.tm_zone;
-					parsed.tm_year		= local.tm_year;
-					parsed.tm_isdst		= local.tm_isdst;
-					now = mktime(&parsed);
-					timestamp = asctime(gmtime(&now)) + 4;
+				if (option_mask32 & OPT_utc) {
+					tmp = gmtime_r(&tvnow.tv_sec, &tmnow);
 				} else {
-					timestamp = msg;
+					tmp = &parsed;
 				}
+#else
+				tmp = &parsed;
+#endif /* ENABLE_FEATURE_SYSLOGD_UTC */
 			} else {
-				timestamp = msg;
-				now = 0;
+				tmp = decompose_time(&tvnow, &tmnow);
 			}
 #else
 			timestamp = msg;
-			now = 0;
-#endif
+			timestamp[15] = '\0';
+			tvnow.tv_sec  = 0;
+			tvnow.tv_usec = 0;
+#endif /* ENABLE_FEATURE_SYSLOGD_UTC */
 		}
 		msg += 16;
 	}
 
+	if (!tmp) {
+		tmp = generate_time(&tvnow, &tmnow);
+	}
+
 #if ENABLE_FEATURE_SYSLOGD_PRECISE_TIMESTAMPS
-	if (!timestamp) {
-		struct timeval tv;
-		xgettimeofday(&tv);
-		now = tv.tv_sec;
-		timestamp = timestamp_from_time(&now);
-		/* overwrite year by milliseconds, zero terminate */
-		sprintf(timestamp + 15, ".%03u", (unsigned)tv.tv_usec / 1000u);
-	} else {
-		timestamp[15] = '\0';
+	if (tmp && !timestamp) {
+		n = strftime(timestampbuf + n, sizeof(timestampbuf) - n, format, tmp);
+		snprintf(timestampbuf + n, sizeof(timestampbuf) - n, ".%03lu", tvnow.tv_usec / 1000u);
+		timestamp = timestampbuf;
 	}
 #else
-	if (!timestamp) {
-		time(&now);
-		timestamp = timestamp_from_time(&now);
+	if (tmp && !timestamp) {
+		strftime(timestampbuf + n, sizeof(timestampbuf) - n, format, tmp);
+		timestamp = timestampbuf;
 	}
-	timestamp[15] = '\0';
 #endif
 
 	if (option_mask32 & OPT_kmsg) {
@@ -938,7 +977,7 @@ static void timestamp_and_log(int pri, char *msg, int len)
 
 		for (rule = G.log_rules; rule; rule = rule->next) {
 			if (rule->enabled_facility_priomap[facility] & prio_bit) {
-				log_locally(now, G.printbuf, rule->file);
+				log_locally(tvnow.tv_sec, G.printbuf, rule->file);
 				match = 1;
 			}
 		}
@@ -953,7 +992,7 @@ static void timestamp_and_log(int pri, char *msg, int len)
 			return;
 		}
 #endif
-		log_locally(now, G.printbuf, &G.logFile);
+		log_locally(tvnow.tv_sec, G.printbuf, &G.logFile);
 	}
 }
 
-- 
2.45.0