Fix how %m behaves in the log format
[platform/core/system/dlog.git] / src / libdlog / log.c
index 035c63b..7119d49 100644 (file)
 #include <tizen.h>
 
 // DLog
+#include <buffer_traits.h>
 #include "deduplicate.h"
 #include <dynamic_config.h>
+#include "extra_sinks.h"
 #include <libdlog.h>
-#include <logcommon.h>
 #include "logconfig.h"
 #include "loglimiter.h"
 
 #define DEFAULT_CONFIG_DEBUGMODE 0
 #define DEFAULT_CONFIG_LIMITER_APPLY_TO_ALL_BUFFERS 0
 
+
+/* A pseudo-backend that does nothing. Useful for removing the overhead of dlog
+ * for debugging and measurement purposes, also it simplifies some checking as
+ * the `write_to_log` pointer below never needs to be NULL. Note that features
+ * independent of the backend (such as limiter or dynamic config) are controlled
+ * separately if dlog is to be disabled completely and that minimal overhead is
+ * always present (e.g. building the message via vprintf). */
+static int write_to_log_null (log_id_t log_id, log_priority prio, const char *tag, const char *msg, struct timespec *tp_mono, int32_t pid, int32_t tid)
+{
+       return DLOG_ERROR_NONE;
+}
+
 /**
  * @brief Points to a function which writes a log message
  * @details The function pointed to depends on the backend used
@@ -57,7 +70,7 @@
  * @return Returns the number of bytes written on success and a negative error value on error.
  * @see __dlog_init_backend
  */
-int (*write_to_log)(log_id_t log_id, log_priority prio, const char *tag, const char *msg, struct timespec *tp_mono, int32_t pid, int32_t tid) = NULL;
+int (*write_to_log)(log_id_t log_id, log_priority prio, const char *tag, const char *msg, struct timespec *tp_mono, int32_t pid, int32_t tid) = write_to_log_null;
 void (*destroy_backend)(void);
 
 int (*stash_failed_log)(log_id_t log_id, log_priority prio, const char *tag, const char *msg) = NULL;
@@ -78,8 +91,8 @@ extern void prepend_container_tag_if_in_container(size_t buf_size, char buf[stat
 bool limiter;
 struct limiter_data *limiter_data;
 static bool dynamic_config;
-static bool plog[LOG_ID_MAX];
-static bool plog_default_values[LOG_ID_MAX];
+static bool plog[SINKS_MAX];
+static bool plog_default_values[SINKS_MAX];
 static bool enable_secure_logs = true;
 static bool enable_critical = true;
 
@@ -90,14 +103,15 @@ static int fatal_assert;
 static int limiter_apply_to_all_buffers;
 static _Atomic log_priority priority_filter_level = DLOG_VERBOSE;
 
-/* Cache pid and tid to avoid up to two syscalls per log. The update function
- * is registered to happen when new threads are made (including a full fork). */
+/* Cache pid and tid to avoid up to two syscalls per log.
+ * PID is reset at fork() via pthread_atfork().
+ * TID is reset by being a thread local var. */
 static int32_t cached_pid = 0;
 _Thread_local int32_t cached_tid = 0;
 
 static inline int32_t get_cached_pid()
 {
-       return (cached_pid = cached_pid ?: getpid());
+       return cached_pid;
 }
 
 static inline int32_t get_cached_tid()
@@ -105,10 +119,10 @@ static inline int32_t get_cached_tid()
        return (cached_tid = cached_tid ?: gettid());
 }
 
-static void update_thread_local_ids(void)
+static void update_cached_pid()
 {
-       cached_pid = 0;
-       cached_tid = 0;
+       cached_pid = getpid();
+       // tid is reset passively (to 0) by virtue of being thread-local
 }
 
 /* Here, static_config is the original config from /etc/dlog.conf{,.d} which can be overriden,
@@ -148,6 +162,8 @@ static int __configure_backend(struct log_config *config)
                __dlog_init_android(config);
        else if (!strcmp(backend, "zero-copy"))
                __dlog_init_zero_copy(config);
+       else if (!strcmp(backend, "null"))
+               ; // already the default
        else
                return 0;
 
@@ -164,10 +180,12 @@ static void __initialize_plog(const struct log_config *config)
 {
        assert(config);
 
+       /* plog stands for "platform logging", which is why
+        * non-platform (i.e. application) buffers ignore it */
        const bool plog_default = log_config_get_boolean(config, "plog", DEFAULT_CONFIG_PLOG);
        for (size_t i = 0; i < NELEMS(plog); ++i)
-               plog[i] = plog_default;
-       plog[LOG_ID_APPS] = true; // the default does not apply here for backward compatibility reasons.
+               plog[i] = is_platform_buffer(i) ? plog_default : true;
+
        __set_plog_default_values();
 }
 
@@ -243,6 +261,8 @@ bool __configure(void)
        __attribute__((cleanup(log_config_free))) struct log_config static_config = {};
        __attribute__((cleanup(log_config_free))) struct log_config both_config = {};
 
+       cached_pid = getpid();
+
        if (log_config_read(&static_config) < 0)
                return false;
        log_config_copy(&both_config, &static_config);
@@ -260,9 +280,7 @@ bool __configure(void)
        __configure_deduplicate(&both_config);
        __configure_limiter(&static_config, &both_config);
 
-       /* The fork handler also runs when a new thread is made (not just
-        * when the whole process forks), so we can cache both pid and tid. */
-       pthread_atfork(NULL, NULL, update_thread_local_ids);
+       pthread_atfork(NULL, NULL, update_cached_pid);
 
        return true;
 }
@@ -358,16 +376,26 @@ static void __dlog_fatal_assert(int prio)
  * @param[in] log_id The target buffer ID
  * @param[in] prio The log's priority
  * @param[in] tag The log's tag
+ * @param[in] only_core Whether non-core buffers are rejected
  * @return DLOG_ERROR_NONE on success, else an error code.
  * @retval DLOG_ERROR_INVALID_PARAMETER Invalid parameter
  */
-static int dlog_check_validity(log_id_t log_id, int prio, const char *tag)
+static int dlog_check_validity(log_id_t log_id, int prio, const char *tag, bool only_core)
 {
        (void) prio;
        if (!tag)
                return DLOG_ERROR_INVALID_PARAMETER;
 
-       if (log_id <= LOG_ID_INVALID || LOG_ID_MAX <= log_id)
+       if (!is_buffer_valid(log_id))
+               return DLOG_ERROR_INVALID_PARAMETER;
+
+       /* The interface here is a bit confused. `__dlog_print` is nominally
+        * for platform logging and is not necessarily supposed to use the
+        * APPS buffer (which is a core buffer, but not a platform buffer),
+        * yet the internal interface (dlog-internal.h) exposes macros for
+        * platform programs to log into APPS. The design is probably too
+        * ossified to change at this point though. */
+       if (only_core && !is_core_buffer(log_id))
                return DLOG_ERROR_INVALID_PARAMETER;
 
        return DLOG_ERROR_NONE;
@@ -435,29 +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;
 
-       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;
+       log_id = get_log_id_from_sink(log_id);
+
 
        // 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());
@@ -470,7 +494,19 @@ 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)
 {
-       int ret = dlog_check_validity(log_id, prio, tag);
+       /* 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;
 
@@ -492,18 +528,13 @@ static int __write_to_log(log_id_t log_id, int prio, const char *tag, const char
        if (should_disable_cancels)
                pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &old_cancel_state);
 
-       /* The only thing that needs to be protected here is `write_to_log` since
-        * all other resources already have their own specific locks (and even the
-        * pointer could be made to point at a null handler instead of a true NULL)
-        * but giving this guarantee makes everything a lot simpler as it removes
-        * the risk of something suddenly becoming NULL during processing. */
-       if (!initialize() || !write_to_log)
+       if (!initialize())
                // TODO: We could consider stashing the failed log here
                ret = DLOG_ERROR_NOT_PERMITTED;
        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);
@@ -666,6 +697,7 @@ void __critical_log(log_id_t log_id, int prio, const char *tag, const char *fmt,
        __critical_log_child(main_pid, main_tid, log_id, prio, tag, fmt, ap);
 }
 
+// LCOV_EXCL_START : stashing is essentially error handling.
 static void stash_critical_inner(log_id_t log_id, log_priority prio, const char *tag, const char *fmt, ...)
 {
        va_list ap;
@@ -680,6 +712,7 @@ static int stash_critical(log_id_t log_id, log_priority prio, const char *tag, c
        stash_critical_inner(log_id, prio, tag, "FAILED TO LOG: %s", msg);
        return 0;
 }
+// LCOV_EXCL_STOP
 
 EXPORT_API int __dlog_critical_print(log_id_t log_id, int prio, const char *tag, const char *fmt, ...)
 {
@@ -784,6 +817,40 @@ EXPORT_API int dlog_print(log_priority prio, const char *tag, const char *fmt, .
        return ret;
 }
 
+EXPORT_API int dlog_vprint_dotnet(log_priority prio, const char *tag, const char *fmt, va_list ap)
+{
+       return __write_to_log(SINK_DOTNET, prio, tag, fmt, ap, false, false);
+}
+
+EXPORT_API int dlog_print_dotnet(log_priority prio, const char *tag, const char *fmt, ...)
+{
+       va_list ap;
+
+       va_start(ap, fmt);
+       int ret = dlog_vprint_dotnet(prio, tag, fmt, ap);
+       va_end(ap);
+
+       return ret;
+}
+
+EXPORT_API int dlog_vprint_native(log_priority prio, const char *tag, const char *fmt, va_list ap)
+{
+       return __write_to_log(SINK_NATIVE, prio, tag, fmt, ap, false, false);
+}
+
+EXPORT_API int dlog_print_native(log_priority prio, const char *tag, const char *fmt, ...)
+{
+       va_list ap;
+
+       va_start(ap, fmt);
+       int ret = dlog_vprint_native(prio, tag, fmt, ap);
+       va_end(ap);
+
+       return ret;
+}
+
+// LCOV_EXCL_START : for internal use only, not accessible via public API
+
 /**
  * @brief Finalize DLog
  * @details Finalizes and deallocates the library
@@ -795,7 +862,7 @@ void __dlog_fini(void)
                destroy_backend();
                destroy_backend = NULL;
        }
-       write_to_log = NULL;
+       write_to_log = write_to_log_null;
        stash_failed_log = NULL;
        is_initialized = false;
        first = true;
@@ -808,3 +875,5 @@ void __dlog_fini(void)
        __dynamic_config_destroy();
        should_disable_cancels = false;
 }
+
+// LCOV_EXCL_STOP