Fix how %m behaves in the log format

%m is supposed to mean the original state of errno as it was at the time
libdlog was called. But we used to perform syscalls that changed it.
Make sure that we immanentize the message first, before any syscalls,
so that %m uses the correct value of errno.

Change-Id: I5b594b28fa7dc8c2ec590231c5c0903de75eddee

diff --git a/src/libdlog/log.c b/src/libdlog/log.c
index 38f69c3..7119d49 100644 (file)
--- a/src/libdlog/log.c
+++ b/src/libdlog/log.c
@@ -463,31 +463,25 @@ static int dlog_check_limiter(log_id_t log_id, int prio, const char *tag)
        return DLOG_ERROR_NONE;
 }
 
-static int __write_to_log_critical_section(log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap, bool check_should_log)
+static int __write_to_log_critical_section(log_id_t log_id, int prio, const char *tag, size_t buf_size, char buf[static buf_size], int buf_len, bool check_should_log)
 {
        if ((check_should_log || limiter_apply_to_all_buffers) && (dlog_check_limiter(log_id, prio, tag) < 0))
                return DLOG_ERROR_NONE;
 
        log_id = get_log_id_from_sink(log_id);
 
-       char buf[LOG_MAX_PAYLOAD_SIZE];
-       int len = vsnprintf(buf, sizeof buf, fmt, ap);
-       if (len < 0)
-               return DLOG_ERROR_NONE;
-       else if (len >= sizeof buf)
-               len = sizeof buf - 1;
 
        // Temporary workaround, see temporary.c
-       prepend_container_tag_if_in_container(sizeof buf, buf, &len);
+       prepend_container_tag_if_in_container(buf_size, buf, &buf_len);
 
        struct timespec tp;
        int r;
        if (deduplicate_func && !clock_gettime(CLOCK_MONOTONIC, &tp)) {
-               dlog_deduplicate_e ret = deduplicate_func(buf, len, &tp);
+               dlog_deduplicate_e ret = deduplicate_func(buf, buf_len, &tp);
                if (ret == DLOG_DEDUPLICATE)
                        return DLOG_ERROR_NONE;
                else if (ret == DLOG_DO_NOT_DEDUPLICATE_BUT_WARN)
-                       deduplicate_warn(buf, sizeof buf, len);
+                       deduplicate_warn(buf, buf_size, buf_len);
                r = write_to_log(log_id, prio, tag, buf, &tp, get_cached_pid(), get_cached_tid());
        } else
                r = write_to_log(log_id, prio, tag, buf, NULL, get_cached_pid(), get_cached_tid());
@@ -500,6 +494,18 @@ static int __write_to_log_critical_section(log_id_t log_id, int prio, const char
 
 static int __write_to_log(log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap, bool check_should_log, bool secure_log)
 {
+       /* Write down the log first, before all other checks. This
+        * is because validity checks may involve syscalls, which
+        * could overwrite `errno` and ruin the `%m` specifier if
+        * the client specifies it in format. */
+       char buf[LOG_MAX_PAYLOAD_SIZE];
+       int len = vsnprintf(buf, sizeof buf, fmt, ap);
+       if (len < 0)
+               return DLOG_ERROR_NONE; // not really, but no better choice and not too realistic
+       else if (len >= sizeof buf)
+               len = sizeof buf - 1;
+
+
        int ret = dlog_check_validity(log_id, prio, tag, check_should_log);
        if (ret < 0)
                return ret;
@@ -528,7 +534,7 @@ static int __write_to_log(log_id_t log_id, int prio, const char *tag, const char
        else if (secure_log && !enable_secure_logs)
                ret = 0;
        else
-               ret = __write_to_log_critical_section(log_id, prio, tag, fmt, ap, check_should_log);
+               ret = __write_to_log_critical_section(log_id, prio, tag, sizeof buf, buf, len, check_should_log);
 
        if (should_disable_cancels)
                pthread_setcancelstate(old_cancel_state, NULL);