log: add an "error" parameter to all low-level logging calls and intrdouce log_error_errno() as log calls that take error numbers

This change has two benefits:

- The format string %m will now resolve to the specified error (or to
  errno if the specified error is 0. This allows getting rid of a ton of
  strerror() invocations, a function that is not thread-safe.

- The specified error can be passed to the journal in the ERRNO= field.

Now of course, we just need somebody to convert all cases of this:

        log_error("Something happened: %s", strerror(-r));

into thus:

        log_error_errno(-r, "Something happened: %m");

Signed-off-by: Anthony G. Basile <blueness@gentoo.org>

3 files changed, 97 insertions, 102 deletions

diff --git a/src/shared/log.c b/src/shared/log.c
index d19103a1e2..6ed18e36da 100644
--- a/src/shared/log.c
+++ b/src/shared/log.c
@@ -102,8 +102,8 @@ void log_close_syslog(void) {
 }
 
 static int create_log_socket(int type) {
-        int fd;
         struct timeval tv;
+        int fd;
 
         fd = socket(AF_UNIX, type|SOCK_CLOEXEC, 0);
         if (fd < 0)
@@ -118,18 +118,20 @@ static int create_log_socket(int type) {
                 timeval_store(&tv, 10 * USEC_PER_MSEC);
         else
                 timeval_store(&tv, 10 * USEC_PER_SEC);
-        (void)setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv));
+        (void) setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv));
 
         return fd;
 }
 
 static int log_open_syslog(void) {
-        int r;
-        union sockaddr_union sa = {
+
+        static const union sockaddr_union sa = {
                 .un.sun_family = AF_UNIX,
                 .un.sun_path = "/dev/log",
         };
 
+        int r;
+
         if (syslog_fd >= 0)
                 return 0;
 
@@ -240,10 +242,11 @@ void log_set_max_level(int level) {
 
 static int write_to_console(
                 int level,
-                const char*file,
+                int error,
+                const char *file,
                 int line,
                 const char *func,
-                const char *object_name,
+                const char *object_field,
                 const char *object,
                 const char *buffer) {
 
@@ -294,15 +297,16 @@ static int write_to_console(
 }
 
 static int write_to_syslog(
-        int level,
-        const char*file,
-        int line,
-        const char *func,
-        const char *object_name,
-        const char *object,
-        const char *buffer) {
+                int level,
+                int error,
+                const char *file,
+                int line,
+                const char *func,
+                const char *object_field,
+                const char *object,
+                const char *buffer) {
 
-        char header_priority[16], header_time[64], header_pid[16];
+        char header_priority[1 + DECIMAL_STR_MAX(int) + 2], header_time[64], header_pid[1 + DECIMAL_STR_MAX(pid_t) + 4];
         struct iovec iovec[5] = {};
         struct msghdr msghdr = {
                 .msg_iov = iovec,
@@ -356,15 +360,16 @@ static int write_to_syslog(
 }
 
 static int write_to_kmsg(
-        int level,
-        const char*file,
-        int line,
-        const char *func,
-        const char *object_name,
-        const char *object,
-        const char *buffer) {
+                int level,
+                int error,
+                const char*file,
+                int line,
+                const char *func,
+                const char *object_field,
+                const char *object,
+                const char *buffer) {
 
-        char header_priority[16], header_pid[16];
+        char header_priority[1 + DECIMAL_STR_MAX(int) + 2], header_pid[1 + DECIMAL_STR_MAX(pid_t) + 4];
         struct iovec iovec[5] = {};
 
         if (kmsg_fd < 0)
@@ -388,45 +393,15 @@ static int write_to_kmsg(
         return 1;
 }
 
-static int log_do_header(char *header, size_t size,
-                         int level,
-                         const char *file, int line, const char *func,
-                         const char *object_name, const char *object) {
-        snprintf(header, size,
-                 "PRIORITY=%i\n"
-                 "SYSLOG_FACILITY=%i\n"
-                 "%s%.*s%s"
-                 "%s%.*i%s"
-                 "%s%.*s%s"
-                 "%s%.*s%s"
-                 "SYSLOG_IDENTIFIER=%s\n",
-                 LOG_PRI(level),
-                 LOG_FAC(level),
-                 file ? "CODE_FILE=" : "",
-                 file ? LINE_MAX : 0, file, /* %.0s means no output */
-                 file ? "\n" : "",
-                 line ? "CODE_LINE=" : "",
-                 line ? 1 : 0, line, /* %.0d means no output too, special case for 0 */
-                 line ? "\n" : "",
-                 func ? "CODE_FUNCTION=" : "",
-                 func ? LINE_MAX : 0, func,
-                 func ? "\n" : "",
-                 object ? object_name : "",
-                 object ? LINE_MAX : 0, object, /* %.0s means no output */
-                 object ? "\n" : "",
-                 program_invocation_short_name);
-        header[size - 1] = '\0';
-        return 0;
-}
-
 static int log_dispatch(
-        int level,
-        const char*file,
-        int line,
-        const char *func,
-        const char *object_name,
-        const char *object,
-        char *buffer) {
+                int level,
+                int error,
+                const char*file,
+                int line,
+                const char *func,
+                const char *object_field,
+                const char *object,
+                char *buffer) {
 
         int r = 0;
 
@@ -455,8 +430,7 @@ static int log_dispatch(
                 if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
                     log_target == LOG_TARGET_SYSLOG) {
 
-                        k = write_to_syslog(level, file, line, func,
-                                            object_name, object, buffer);
+                        k = write_to_syslog(level, error, file, line, func, object_field, object, buffer);
                         if (k < 0) {
                                 if (k != -EAGAIN)
                                         log_close_syslog();
@@ -471,8 +445,7 @@ static int log_dispatch(
                      log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
                      log_target == LOG_TARGET_KMSG)) {
 
-                        k = write_to_kmsg(level, file, line, func,
-                                          object_name, object, buffer);
+                        k = write_to_kmsg(level, error, file, line, func, object_field, object, buffer);
                         if (k < 0) {
                                 log_close_kmsg();
                                 log_open_console();
@@ -481,8 +454,7 @@ static int log_dispatch(
                 }
 
                 if (k <= 0) {
-                        k = write_to_console(level, file, line, func,
-                                             object_name, object, buffer);
+                        k = write_to_console(level, error, file, line, func, object_field, object, buffer);
                         if (k < 0)
                                 return k;
                 }
@@ -495,6 +467,7 @@ static int log_dispatch(
 
 int log_metav(
         int level,
+        int error,
         const char*file,
         int line,
         const char *func,
@@ -510,27 +483,34 @@ int log_metav(
         vsnprintf(buffer, sizeof(buffer), format, ap);
         char_array_0(buffer);
 
-        return log_dispatch(level, file, line, func, NULL, NULL, buffer);
+        return log_dispatch(level, error, file, line, func, NULL, NULL, buffer);
 }
 
 int log_meta(
-        int level,
-        const char*file,
-        int line,
-        const char *func,
-        const char *format, ...) {
+                int level,
+                int error,
+                const char*file,
+                int line,
+                const char *func,
+                const char *format, ...) {
 
         int r;
         va_list ap;
 
         va_start(ap, format);
-        r = log_metav(level, file, line, func, format, ap);
+        r = log_metav(level, error, file, line, func, format, ap);
         va_end(ap);
 
         return r;
 }
 
-static void log_assert(int level, const char *text, const char *file, int line, const char *func, const char *format) {
+static void log_assert(
+                int level,
+                const char *text,
+                const char *file,
+                int line,
+                const char *func,
+                const char *format) {
         static char buffer[LINE_MAX];
 
         if (_likely_(LOG_PRI(level) > log_max_level))
@@ -543,7 +523,7 @@ static void log_assert(int level, const char *text, const char *file, int line,
         char_array_0(buffer);
         log_abort_msg = buffer;
 
-        log_dispatch(level, file, line, func, NULL, NULL, buffer);
+        log_dispatch(level, 0, file, line, func, NULL, NULL, buffer);
 }
 
 noreturn void log_assert_failed(const char *text, const char *file, int line, const char *func) {
@@ -557,7 +537,7 @@ noreturn void log_assert_failed_unreachable(const char *text, const char *file,
 }
 
 int log_oom_internal(const char *file, int line, const char *func) {
-        log_meta(LOG_ERR, file, line, func, "Out of memory.");
+        log_meta(LOG_ERR, ENOMEM, file, line, func, "Out of memory.");
         return -ENOMEM;
 }
 
diff --git a/src/shared/log.h b/src/shared/log.h
index 30f0cacb65..7d65aec055 100644
--- a/src/shared/log.h
+++ b/src/shared/log.h
@@ -54,24 +54,27 @@ void log_close_console(void);
 
 int log_meta(
                 int level,
+                int error,
                 const char*file,
                 int line,
                 const char *func,
-                const char *format, ...) _printf_(5,6);
+                const char *format, ...) _printf_(6,7);
 
 int log_metav(
                 int level,
+                int error,
                 const char*file,
                 int line,
                 const char *func,
                 const char *format,
-                va_list ap) _printf_(5,0);
+                va_list ap) _printf_(6,0);
 
 int log_oom_internal(
                 const char *file,
                 int line,
                 const char *func);
 
+/* Logging for various assertions */
 noreturn void log_assert_failed(
                 const char *text,
                 const char *file,
@@ -85,17 +88,30 @@ noreturn void log_assert_failed_unreachable(
                 const char *func);
 
 
-#define log_full(level, ...) \
-do { \
-        if (log_get_max_level() >= (level)) \
-                log_meta((level), __FILE__, __LINE__, __func__, __VA_ARGS__); \
-} while (0)
+/* Logging with level */
+#define log_full_errno(level, error, ...)                               \
+        do {                                                            \
+                if (log_get_max_level() >= (level))                     \
+                        log_meta((level), error, __FILE__, __LINE__, __func__, __VA_ARGS__); \
+        } while (false)
 
-#define log_debug(...)   log_full(LOG_DEBUG,   __VA_ARGS__)
-#define log_info(...)    log_full(LOG_INFO,    __VA_ARGS__)
-#define log_notice(...)  log_full(LOG_NOTICE,  __VA_ARGS__)
-#define log_warning(...) log_full(LOG_WARNING, __VA_ARGS__)
-#define log_error(...)   log_full(LOG_ERR,     __VA_ARGS__)
+#define log_full(level, ...) log_full_errno(level, 0, __VA_ARGS__)
+
+/* Normal logging */
+#define log_debug(...)     log_full(LOG_DEBUG,   __VA_ARGS__)
+#define log_info(...)      log_full(LOG_INFO,    __VA_ARGS__)
+#define log_notice(...)    log_full(LOG_NOTICE,  __VA_ARGS__)
+#define log_warning(...)   log_full(LOG_WARNING, __VA_ARGS__)
+#define log_error(...)     log_full(LOG_ERR,     __VA_ARGS__)
+#define log_emergency(...) log_full(getpid() == 1 ? LOG_EMERG : LOG_ERR, __VA_ARGS__)
+
+/* Logging triggered by an errno-like error */
+#define log_debug_errno(error, ...)     log_full_errno(LOG_DEBUG,   error, __VA_ARGS__)
+#define log_info_errno(error, ...)      log_full_errno(LOG_INFO,    error, __VA_ARGS__)
+#define log_notice_errno(error, ...)    log_full_errno(LOG_NOTICE,  error, __VA_ARGS__)
+#define log_warning_errno(error, ...)   log_full_errno(LOG_WARNING, error, __VA_ARGS__)
+#define log_error_errno(error, ...)     log_full_errno(LOG_ERR,     error, __VA_ARGS__)
+#define log_emergency_errno(error, ...) log_full_errno(getpid() == 1 ? LOG_EMERG : LOG_ERR, error, __VA_ARGS__)
 
 #ifdef LOG_TRACE
 #  define log_trace(...) log_debug(__VA_ARGS__)
@@ -103,7 +119,8 @@ do { \
 #  define log_trace(...) do {} while(0)
 #endif
 
-#define log_struct(level, ...) log_struct_internal(level, __FILE__, __LINE__, __func__, __VA_ARGS__)
+/* This modifies the buffer passed! */
+//#define log_dump(level, buffer) log_dump_internal(level, 0, __FILE__, __LINE__, __func__, buffer)
 
 #define log_oom() log_oom_internal(__FILE__, __LINE__, __func__)
 
diff --git a/src/udev/udev-builtin-kmod.c b/src/udev/udev-builtin-kmod.c
index 5c50f7856d..0d9c9d9c1a 100644
--- a/src/udev/udev-builtin-kmod.c
+++ b/src/udev/udev-builtin-kmod.c
@@ -34,7 +34,7 @@
 
 #include "udev.h"
 
-static struct kmod_ctx *ctx;
+static struct kmod_ctx *ctx = NULL;
 
 static int load_module(struct udev *udev, const char *alias) {
         int err;
@@ -47,18 +47,18 @@ static int load_module(struct udev *udev, const char *alias) {
                 return err;
 
         if (list == NULL)
-                log_debug("no module matches '%s'", alias);
+                log_debug("No module matches '%s'", alias);
 
         kmod_list_foreach(l, list) {
                 struct kmod_module *mod = kmod_module_get_module(l);
 
                 err = kmod_module_probe_insert_module(mod, KMOD_PROBE_APPLY_BLACKLIST, NULL, NULL, NULL, NULL);
                 if (err == KMOD_PROBE_APPLY_BLACKLIST)
-                        log_debug("module '%s' is blacklisted", kmod_module_get_name(mod));
+                        log_debug("Module '%s' is blacklisted", kmod_module_get_name(mod));
                 else if (err == 0)
-                        log_debug("inserted '%s'", kmod_module_get_name(mod));
+                        log_debug("Inserted '%s'", kmod_module_get_name(mod));
                 else
-                        log_debug("failed to insert '%s'", kmod_module_get_name(mod));
+                        log_debug("Failed to insert '%s'", kmod_module_get_name(mod));
 
                 kmod_module_unref(mod);
         }
@@ -85,10 +85,8 @@ static int load_module(struct udev *udev, const char *alias) {
         return err;
 }
 
-_printf_(6,0)
-static void udev_kmod_log(void *data, int priority, const char *file, int line,
-                          const char *fn, const char *format, va_list args) {
-        log_metav(priority, file, line, fn, format, args);
+_printf_(6,0) static void udev_kmod_log(void *data, int priority, const char *file, int line, const char *fn, const char *format, va_list args) {
+        log_metav(priority, 0, file, line, fn, format, args);
 }
 
 static int builtin_kmod(struct udev_device *dev, int argc, char *argv[], bool test) {
@@ -106,7 +104,7 @@ static int builtin_kmod(struct udev_device *dev, int argc, char *argv[], bool te
         }
 
         for (i = 2; argv[i]; i++) {
-                log_debug("execute '%s' '%s'", argv[1], argv[i]);
+                log_debug("Execute '%s' '%s'", argv[1], argv[i]);
                 load_module(udev, argv[i]);
         }
 
@@ -123,7 +121,7 @@ static int builtin_kmod_init(struct udev *udev) {
         if (!ctx)
                 return -ENOMEM;
 
-        log_debug("load module index");
+        log_debug("Load module index");
         kmod_set_log_fn(ctx, udev_kmod_log, udev);
         kmod_load_resources(ctx);
 #endif
@@ -133,7 +131,7 @@ static int builtin_kmod_init(struct udev *udev) {
 /* called on udev shutdown and reload request */
 static void builtin_kmod_exit(struct udev *udev) {
 #ifdef HAVE_LIBKMOD
-        log_debug("unload module index");
+        log_debug("Unload module index");
         ctx = kmod_unref(ctx);
 #endif
 }
@@ -141,7 +139,7 @@ static void builtin_kmod_exit(struct udev *udev) {
 #ifdef HAVE_LIBKMOD
 /* called every couple of seconds during event activity; 'true' if config has changed */
 static bool builtin_kmod_validate(struct udev *udev) {
-        log_debug("validate module index");
+        log_debug("Validate module index");
         if (!ctx)
                 return false;
         return (kmod_validate_resources(ctx) != KMOD_RESOURCES_OK);