Critical logs: less fragile unit tests

Change-Id: I826970a7a13c89051ca2dd18689ea001e2722632
Signed-off-by: Michal Bloch <m.bloch@samsung.com>

diff --git a/Makefile.am b/Makefile.am
index 4fb6ec8..fea640b 100644 (file)
--- a/Makefile.am
+++ b/Makefile.am
@@ -425,7 +425,7 @@ src_tests_critical_log_SOURCES = src/tests/critical_log.c \
        src/shared/logconfig.c \
        src/shared/parsers.c
 src_tests_critical_log_CFLAGS = $(check_CFLAGS) -pthread
-src_tests_critical_log_LDFLAGS = $(AM_LDFLAGS) -lpthread -Wl,--wrap=getpid,--wrap=syscall,--wrap=execv,--wrap=fork,--wrap=clock_gettime
+src_tests_critical_log_LDFLAGS = $(AM_LDFLAGS) -lpthread -Wl,--wrap=execv,--wrap=clock_gettime
 
 src_tests_filters_SOURCES = src/tests/filters.c src/shared/ptrs_list.c src/shared/logcommon.c src/shared/logprint.c
 src_tests_filters_CFLAGS = $(check_CFLAGS)

diff --git a/src/libdlog/log.c b/src/libdlog/log.c
index f5f8390..4875a68 100644 (file)
--- a/src/libdlog/log.c
+++ b/src/libdlog/log.c
@@ -409,6 +409,9 @@ int __critical_log_build_msg(char *buf, size_t buflen, pid_t main_pid, pid_t mai
        return len;
 }
 
+#ifndef UNIT_TEST
+__attribute__ ((noreturn))
+#endif
 void __critical_log_child(pid_t main_pid, pid_t main_tid, log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap)
 {
        char buf[LOG_MAX_PAYLOAD_SIZE + 128]; // extra space for some metadata
@@ -420,16 +423,19 @@ void __critical_log_child(pid_t main_pid, pid_t main_tid, log_id_t log_id, int p
        execl(path, path /* argv[0] convention */, buf, (char *) NULL);
 
 #ifndef UNIT_TEST
-       /* Compilers are sometimes smart enough to recognize `_exit`
-        * and can put some code behind the call that makes absolutely
-        * sure the program dies. This seems to happen even in case
-        * `_exit` is replaced with something that doesn't actually
-        * abort the program, so we can't use `_exit` in tests. */
+       /* Compilers are sometimes smart enough to recognize _exit's
+        * noreturn attribute, even if we wrap it with something that
+        * returns. This causes it to behave in unexpected ways, for
+        * example it can blow up the program regardless or it can
+        * optimize some conditionals out (and incorrectly enter them
+        * after the exit call fails to actually exit). This makes it
+        * unsuitable for tests. */
 
        _exit(1); // not the regular `exit` so as not to trigger any `atexit` handlers prematurely
 #endif
 }
 
+#ifndef UNIT_TEST // contains forks and exits, these don't work well with wrapping (see above)
 void __critical_log(log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap)
 {
        /* Critical log functionality is mostly done in a separate binary
@@ -450,6 +456,22 @@ 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);
 }
 
+int __dlog_critical_print(log_id_t log_id, int prio, const char *tag, const char *fmt, ...)
+{
+       va_list ap;
+
+       va_start(ap, fmt);
+       __critical_log(log_id, prio, tag, fmt, ap);
+       va_end(ap);
+
+       va_start(ap, fmt);
+       int ret = __dlog_vprint(log_id, prio, tag, fmt, ap);
+       va_end(ap);
+
+       return ret;
+}
+#endif
+
 /**
  * @brief Print log
  * @details Print a log line
@@ -508,21 +530,6 @@ int __dlog_sec_print(log_id_t log_id, int prio, const char *tag, const char *fmt
        return ret;
 }
 
-int __dlog_critical_print(log_id_t log_id, int prio, const char *tag, const char *fmt, ...)
-{
-       va_list ap;
-
-       va_start(ap, fmt);
-       __critical_log(log_id, prio, tag, fmt, ap);
-       va_end(ap);
-
-       va_start(ap, fmt);
-       int ret = __dlog_vprint(log_id, prio, tag, fmt, ap);
-       va_end(ap);
-
-       return ret;
-}
-
 int dlog_vprint(log_priority prio, const char *tag, const char *fmt, va_list ap)
 {
        return __write_to_log(LOG_ID_APPS, prio, tag, fmt, ap, false);

diff --git a/src/tests/critical_log.c b/src/tests/critical_log.c
index 5360f5a..f69213a 100644 (file)
--- a/src/tests/critical_log.c
+++ b/src/tests/critical_log.c
@@ -11,14 +11,6 @@
 #include <assert.h>
 #include <string.h>
 
-bool fake_fork = false;
-pid_t fork_ret;
-pid_t __real_fork(void);
-pid_t __wrap_fork(void)
-{
-       return fake_fork ? fork_ret : __real_fork();
-}
-
 void __dlog_init_pipe(const struct log_config *conf) { }
 void __dlog_init_android(const struct log_config *conf) { }
 
@@ -48,18 +40,6 @@ int __wrap_execv(const char *filename, char *const argv[], char *const envp[])
        return 0;
 }
 
-long __wrap_syscall(long number, long arg)
-{
-       assert(number == SYS_gettid);
-       return 2077;
-}
-
-pid_t __real_getpid();
-pid_t __wrap_getpid()
-{
-       return 1729;
-}
-
 int __wrap_clock_gettime(clockid_t clk_id, struct timespec *tp)
 {
        if (clk_id == CLOCK_REALTIME) {
@@ -72,6 +52,17 @@ int __wrap_clock_gettime(clockid_t clk_id, struct timespec *tp)
        return 0;
 }
 
+// the real version does forks/exits plus regular logging, these are wonky when wrapped so we skip them
+void __critical_log_child(pid_t main_pid, pid_t main_tid, log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap);
+int __dlog_critical_print_emulated(log_id_t log_id, int prio, const char *tag, const char *fmt, ...)
+{
+       va_list ap;
+       va_start(ap, fmt);
+       __critical_log_child(1729, 2077, log_id, prio, tag, fmt, ap);
+       va_end(ap);
+       return 0;
+}
+
 bool called_atexit;
 void atexit_f(void)
 {
@@ -80,21 +71,11 @@ void atexit_f(void)
 
 int main()
 {
-       fake_fork = true;
        called_atexit = false;
        assert(!atexit(atexit_f));
 
-       fork_ret = -1;
-       __dlog_critical_print(LOG_ID_MAIN, DLOG_ERROR, "TAG", "%s", "YOU'RE IT");
-       assert(!executed);
-
-       fork_ret = 17;
-       __dlog_critical_print(LOG_ID_MAIN, DLOG_ERROR, "MONTAG", "%s%d", "F", 451);
-       assert(!executed);
-
-       fork_ret = 0;
        message_ok = false;
-       __dlog_critical_print(LOG_ID_MAIN, DLOG_ERROR, "FHTAG", "PHNGLUI MGLW'NAFH");
+       __dlog_critical_print_emulated(LOG_ID_MAIN, DLOG_ERROR, "FHTAG", "PHNGLUI MGLW'NAFH");
        assert(executed);
        assert(message_ok);
 
@@ -104,13 +85,12 @@ int main()
 
        // No content checks needed, it just needs not to explode
        executed = false;
-       __dlog_critical_print(LOG_ID_MAIN, DLOG_ERROR, big_str, "stuff");
+       __dlog_critical_print_emulated(LOG_ID_MAIN, DLOG_ERROR, big_str, "stuff");
        assert(executed);
        executed = false;
-       __dlog_critical_print(LOG_ID_MAIN, DLOG_ERROR, "stuff", big_str);
+       __dlog_critical_print_emulated(LOG_ID_MAIN, DLOG_ERROR, "stuff", big_str);
        assert(executed);
 
        assert(!called_atexit);
-       fake_fork = false;
        return 0;
 }