log: Avoid duplicate calls to logtime()

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>
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
This commit is contained in:
David Gibson 2024-08-06 16:18:39 +10:00 committed by Stefano Brivio
parent 2c7558dc43
commit a628cb93a7

17
log.c
View file

@ -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;
if (debug_print) {
char timestr[LOGTIME_STRLEN];
const struct timespec *now;
struct timespec ts;
now = logtime(&ts);
if (debug_print) {
char timestr[LOGTIME_STRLEN];
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);