[make-initrd] ueventd: Rewrite logging function to make it more atomic

[Alexey Gladkov]

Signed-off-by: Alexey Gladkov <gladkov.alexey at gmail.com>
---
 datasrc/ueventd/logging.c | 107 +++++++++++++++++++++++++++++++++-----
 datasrc/ueventd/ueventd.h |  17 +++---
 2 files changed, 104 insertions(+), 20 deletions(-)

diff --git a/datasrc/ueventd/logging.c b/datasrc/ueventd/logging.c
index ac316aab..14539752 100644
--- a/datasrc/ueventd/logging.c
+++ b/datasrc/ueventd/logging.c
@@ -1,8 +1,9 @@
 /* SPDX-License-Identifier: GPL-2.0-or-later */
+#include <sys/uio.h>
 
 #include <stdio.h>
 #include <stdarg.h>
-#include <strings.h>
+#include <string.h>
 #include <errno.h>
 #include <time.h>
 
@@ -11,6 +12,7 @@
 int log_priority = LOG_INFO;
 int log_fd = STDERR_FILENO;
 const char *log_progname = NULL;
+size_t log_progname_len = 0;
 
 int rd_logging_level(const char *name)
 {
@@ -25,27 +27,108 @@ void rd_logging_init(int fd, int loglevel, const char *progname)
 {
 	log_priority = loglevel;
 	log_fd = fd;
-	log_progname = progname;
+	if (progname) {
+		log_progname = progname;
+		log_progname_len = strlen(progname);
+	}
 }
 
 void rd_logging_close(void)
 {
 }
 
-void rd_message(int priority, const char *fmt, ...)
+enum {
+	LOG_FMT_DATETIME,
+	LOG_FMT_DELIM_1,
+	LOG_FMT_PROGNAME,
+	LOG_FMT_DELIM_2,
+	LOG_FMT_MESSAGE,
+	LOG_FMT_EOL,
+	LOG_FMT_MAX,
+};
+
+void rd_vmessage(const char *fmt, va_list ap)
+{
+	char stack_date[38]; // "[1970-01-01 00:00:00]"
+	char stack_msg[80];
+	struct iovec iov[LOG_FMT_MAX];
+
+	memset(iov, 0, sizeof(iov));
+
+	int used;
+	struct tm t;
+	time_t now = time(NULL);
+
+	if (localtime_r(&now, &t) == &t) {
+		used = snprintf(stack_date, sizeof(stack_date),
+		                "[%04d-%02d-%02d %02d:%02d:%02d]",
+		                t.tm_year + 1900, t.tm_mon + 1, t.tm_mday,
+		                t.tm_hour, t.tm_min, t.tm_sec);
+
+		iov[LOG_FMT_DATETIME].iov_base = stack_date;
+		iov[LOG_FMT_DATETIME].iov_len = (size_t) used;
+
+		iov[LOG_FMT_DELIM_1].iov_base = (char *) " ";
+		iov[LOG_FMT_DELIM_1].iov_len = 1;
+	}
+
+	if (log_progname) {
+		iov[LOG_FMT_PROGNAME].iov_base = (char *) log_progname;
+		iov[LOG_FMT_PROGNAME].iov_len = log_progname_len;
+
+		iov[LOG_FMT_DELIM_2].iov_base = (char *) ": ";
+		iov[LOG_FMT_DELIM_2].iov_len = 2;
+	}
+
+	iov[LOG_FMT_EOL].iov_base = (char *) "\n";
+	iov[LOG_FMT_EOL].iov_len = 1;
+
+	va_list ap2;
+	size_t size;
+	char *buf = NULL;
+
+	va_copy(ap2, ap);
+	used = vsnprintf(NULL, 0, fmt, ap2);
+	va_end(ap2);
+
+	if (used >= (int) sizeof(stack_msg)) {
+		size = (size_t) used + 1;
+		buf = malloc(size);
+	}
+
+	if (!buf) {
+		size = sizeof(stack_msg);
+		buf = stack_msg;
+	}
+
+	va_copy(ap2, ap);
+	used = vsnprintf(buf, size, fmt, ap2);
+	va_end(ap2);
+
+	iov[LOG_FMT_MESSAGE].iov_base = buf;
+	iov[LOG_FMT_MESSAGE].iov_len = (size_t) used;
+
+	fsync(log_fd);
+	TEMP_FAILURE_RETRY(writev(log_fd, iov, LOG_FMT_MAX));
+
+	if (buf != stack_msg)
+		free(buf);
+
+	return;
+}
+
+void rd_log_vmessage(int priority, const char *fmt, va_list ap)
+{
+	if (priority <= log_priority)
+		rd_vmessage(fmt, ap);
+}
+
+void rd_log_message(int priority, const char *fmt, ...)
 {
 	va_list ap;
 	va_start(ap, fmt);
 	if (priority <= log_priority) {
-		time_t ts = time(NULL);
-		struct tm *t = localtime(&ts);
-		dprintf(log_fd, "[%04d-%02d-%02d %02d:%02d:%02d] ",
-		        t->tm_year + 1900, t->tm_mon + 1, t->tm_mday,
-		        t->tm_hour, t->tm_min, t->tm_sec);
-		if (log_progname)
-			dprintf(log_fd, "%s: ", log_progname);
-		vdprintf(log_fd, fmt, ap);
-		dprintf(log_fd, "\n");
+		rd_vmessage(fmt, ap);
 	}
 	va_end(ap);
 }
diff --git a/datasrc/ueventd/ueventd.h b/datasrc/ueventd/ueventd.h
index ddba98bf..732d0c61 100644
--- a/datasrc/ueventd/ueventd.h
+++ b/datasrc/ueventd/ueventd.h
@@ -55,22 +55,23 @@ extern  int is_dot_dir(struct dirent *ent) __attribute__((nonnull(1)));
 #include <unistd.h>
 #include <syslog.h>
 #include <stdlib.h>
+#include <stdarg.h>
 
 extern void rd_logging_init(int log_fd, int level, const char *progname);
 extern void rd_logging_close(void);
-extern int rd_logging_level(const char *lvl)               __attribute__((nonnull(1)));
-extern void rd_message(int priority, const char *fmt, ...) __attribute__((format(printf, 2, 3)));
-
-#define __rd_message(level, format, arg...) rd_message(level, format, ##arg)
+extern int rd_logging_level(const char *lvl)                           __attribute__((nonnull(1)));
+extern void rd_vmessage(const char *fmt, va_list ap)                   __attribute__((format(printf, 1, 0)));
+extern void rd_log_vmessage(int priority, const char *fmt, va_list ap) __attribute__((format(printf, 2, 0)));
+extern void rd_log_message(int priority, const char *fmt, ...)         __attribute__((format(printf, 2, 3)));
 
 #define rd_fatal(format, arg...)                    \
 	do {                                        \
-		rd_message(LOG_CRIT, "%s:%d: " format, __FILE__, __LINE__, ##arg); \
+		rd_log_message(LOG_CRIT, "%s:%d: " format, __FILE__, __LINE__, ##arg); \
 		_exit(EXIT_FAILURE);                \
 	} while (0)
 
-#define rd_err(format, arg...)  __rd_message(LOG_ERR,   format, ##arg)
-#define rd_info(format, arg...) __rd_message(LOG_INFO,  format, ##arg)
-#define rd_dbg(format, arg...)  __rd_message(LOG_DEBUG, format, ##arg)
+#define rd_err(format, arg...)  rd_log_message(LOG_ERR,   format, ##arg)
+#define rd_info(format, arg...) rd_log_message(LOG_INFO,  format, ##arg)
+#define rd_dbg(format, arg...)  rd_log_message(LOG_DEBUG, format, ##arg)
 
 #endif /* __UEVENTD_H__ */
-- 
2.33.7