From 4f4e5957d816b849f8668eeac711ca0b0d50acac Mon Sep 17 00:00:00 2001
From: Nichamon Naksinehaboon <nichamon@opengridcomputing.com>
Date: Wed, 23 Oct 2024 13:09:44 -0500
Subject: [PATCH] Consolidate fprintf() calls in ldmsd_log() and ovis_log()
The majority of the code uses ldmsd_log(), but a few ldmsd plugins and
the authentication plugins use ovis_log(). This mixed use of logging
functions creates a possibility of message interleaving. ovis_log()
prints to stdout, and both functions write to the same FILE* stream as
ldmsd sets stdout to the log file.
Modified both functions to use a single fprintf() call per log message
instead of multiple calls. While this doesn't eliminate the possibility
of message interleaving between threads, consolidating to a single
fprintf() per message reduces the opportunities for interruption
compared to multiple fprintf() calls.
---
ldms/src/ldmsd/ldmsd.c | 17 ++++++++---------
lib/src/ovis_log/ovis_log.c | 27 ++++++++++++---------------
2 files changed, 20 insertions(+), 24 deletions(-)
diff --git a/ldms/src/ldmsd/ldmsd.c b/ldms/src/ldmsd/ldmsd.c
index decc26ec0..27b70281a 100644
--- a/ldms/src/ldmsd/ldmsd.c
+++ b/ldms/src/ldmsd/ldmsd.c
@@ -297,19 +297,17 @@ int __log(enum ldmsd_loglevel level, char *msg, struct timeval *tv, struct tm *t
return 0;
}
+ char log_time[200];
if (log_time_sec) {
- fprintf(log_fp, "%lu.%06lu: ", tv->tv_sec, tv->tv_usec);
+ snprintf(log_time, 199, "%lu.%06lu: ", tv->tv_sec, tv->tv_usec);
} else {
- char dtsz[200];
- if (strftime(dtsz, sizeof(dtsz), "%a %b %d %H:%M:%S %Y", tm))
- fprintf(log_fp, "%s: ", dtsz);
+ strftime(log_time, 199, "%a %b %d %H:%M:%S %Y", tm);
}
- if (level < LDMSD_LALL) {
- fprintf(log_fp, "%-10s: ", ldmsd_loglevel_names[level]);
- }
-
- fprintf(log_fp, "%s", msg);
+ fprintf(log_fp, "%s: %-10s: %s",
+ log_time,
+ ((level < LDMSD_LALL)?ldmsd_loglevel_names[level]:""),
+ msg);
return 0;
}
@@ -2300,6 +2298,7 @@ int main(int argc, char *argv[])
/* Initialize LDMS */
umask(0);
+ ovis_log_init(NULL, ovis_log_str_to_level("ERROR"), 0);
if (!auth_name)
auth_name = DEFAULT_AUTH_NAME;
if (-1 == banner)
diff --git a/lib/src/ovis_log/ovis_log.c b/lib/src/ovis_log/ovis_log.c
index 32f27a182..17e0e0bd5 100644
--- a/lib/src/ovis_log/ovis_log.c
+++ b/lib/src/ovis_log/ovis_log.c
@@ -651,30 +651,25 @@ static int __log(ovis_log_t log, int level, char *msg,
int rc;
FILE *f;
+ char log_time[200] = "";
+
if (!log_fp)
f = stdout;
else
f = log_fp;
+
if (default_modes & OVIS_LOG_M_TS) {
- rc = fprintf(f, "%lu.%06lu:", tv->tv_sec, tv->tv_usec);
+ snprintf(log_time, 199, "%lu.%06lu:", tv->tv_sec, tv->tv_usec);
} else if (default_modes & OVIS_LOG_M_DT) {
- char dtsz[200];
- if (strftime(dtsz, sizeof(dtsz), "%a %b %d %H:%M:%S %Y", tm))
- rc = fprintf(f, "%s:", dtsz);
- else
- rc = -EINVAL; /* not expected with gnu libc */
- } else {
- rc = 0;
+ strftime(log_time, 199, "%a %b %d %H:%M:%S %Y", tm);
}
- if (rc < 0)
- return rc;
/* Print the level name */
- rc = fprintf(f, "%9s:", ((level == OVIS_LALWAYS)?"":ovis_loglevel_names[level]));
- if (rc < 0)
- return rc;
-
- rc = fprintf(f, " %s: %s", log->name, msg);
+ rc = fprintf(f, "%s: %-10s: %s: %s",
+ log_time,
+ ((level == OVIS_LALWAYS)?"":ovis_loglevel_names[level]),
+ log->name,
+ msg);
if (rc < 0)
return rc;
return 0;
@@ -945,6 +940,8 @@ int ovis_vlog(ovis_log_t log, int level, const char *fmt, va_list ap)
/* No workers, so directly log to the file. */
rc = __log(log, level, msg, &tv, &tm);
free(msg);
+ if (log_fp != OVIS_LOG_SYSLOG)
+ fflush(log_fp);
goto out;
}