From: Michal Bloch Date: Fri, 7 Dec 2018 12:23:00 +0000 (+0100) Subject: tests: add libdlog-pipe unit tests X-Git-Tag: submit/tizen/20181213.113859~9 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=refs%2Fchanges%2F66%2F194866%2F4;p=platform%2Fcore%2Fsystem%2Fdlog.git tests: add libdlog-pipe unit tests Change-Id: I7f25900125ba5901a527c6a1268a39e3d68c3710 Signed-off-by: Michal Bloch --- diff --git a/Makefile.am b/Makefile.am index ef1a8e4..1fcddbf 100644 --- a/Makefile.am +++ b/Makefile.am @@ -187,6 +187,7 @@ check_PROGRAMS = \ src/tests/test_common \ src/tests/limiter \ src/tests/dynamic_config \ + src/tests/libdlog_pipe \ src/tests/filters check_CFLAGS = $(AM_CFLAGS) -O0 -fprofile-arcs -ftest-coverage @@ -214,6 +215,10 @@ src_tests_dynamic_config_SOURCES = src/tests/dynamic_config.c src/libdlog/dynami src_tests_dynamic_config_CFLAGS = $(check_CFLAGS) -pthread src_tests_dynamic_config_LDFLAGS = $(AM_LDFLAGS) -pthread -Wl,--wrap=read,--wrap=syslog_critical_failure,--wrap=inotify_init1,--wrap=inotify_add_watch,--wrap=log_config_read_file +src_tests_libdlog_pipe_SOURCES = src/tests/libdlog_pipe.c src/libdlog/log_pipe.c src/shared/logcommon.c src/shared/logconfig.c src/shared/queued_entry.c src/shared/translate_syslog.c src/shared/parsers.c +src_tests_libdlog_pipe_CFLAGS = $(check_CFLAGS) +src_tests_libdlog_pipe_LDFLAGS = $(AM_LDFLAGS) -Wl,--wrap=syslog_critical_failure,--wrap=connect,--wrap=write,--wrap=recv_pipe,--wrap=dup2 + src_tests_config_SOURCES = src/tests/config.c src/shared/logconfig.c src/shared/logcommon.c src_tests_config_CFLAGS = $(check_CFLAGS) src_tests_config_LDFLAGS = $(AM_LDFLAGS) diff --git a/src/libdlog/log_pipe.c b/src/libdlog/log_pipe.c index a036c5c..fe9c6de 100644 --- a/src/libdlog/log_pipe.c +++ b/src/libdlog/log_pipe.c @@ -37,14 +37,14 @@ static int connect_pipe(const char * path) r = connect(fd, (struct sockaddr *) &sa, sizeof(sa)); if (r < 0) { - close(fd); // LCOV_EXCL_LINE - return -errno; // LCOV_EXCL_LINE + close(fd); + return -errno; } r = write(fd, &ctrl_msg, ctrl_msg.length); if (r < 0) { - close(fd); // LCOV_EXCL_LINE - return -errno; // LCOV_EXCL_LINE + close(fd); + return -errno; } int ret = recv_pipe(fd, wait_pipe_ms); @@ -69,12 +69,12 @@ static int __reconnect_pipe(log_id_t log_id) /* if connnecting fails consequently assume dlog_logger is broken and reduce the timeout to allow dlog clients to run normally */ - wait_pipe_ms /= 2; // LCOV_EXCL_LINE - if (wait_pipe_ms < MIN_WAIT_PIPE_MS) // LCOV_EXCL_LINE - wait_pipe_ms = MIN_WAIT_PIPE_MS; // LCOV_EXCL_LINE + wait_pipe_ms /= 2; + if (wait_pipe_ms < MIN_WAIT_PIPE_MS) + wait_pipe_ms = MIN_WAIT_PIPE_MS; - pthread_mutex_unlock(&log_init_lock); // LCOV_EXCL_LINE - return 0; // LCOV_EXCL_LINE + pthread_mutex_unlock(&log_init_lock); + return 0; } old_fd = pipe_fd[log_id]; @@ -87,12 +87,12 @@ static int __reconnect_pipe(log_id_t log_id) sigfillset(&all_set); sigprocmask(SIG_BLOCK, &all_set, ¤t_set); #endif - r = dup2(new_fd, old_fd); // LCOV_EXCL_LINE - assert(r >= 0); // LCOV_EXCL_LINE + r = dup2(new_fd, old_fd); + assert(r >= 0); #ifdef __PARANOIC sigprocmask(SIG_SETMASK, ¤t_set, NULL); #endif - close(new_fd); // LCOV_EXCL_LINE + close(new_fd); } pthread_mutex_unlock(&log_init_lock); @@ -115,7 +115,7 @@ static int __write_to_log_pipe(log_id_t log_id, log_priority prio, const char *t struct pipe_logger_entry* ple = (struct pipe_logger_entry *)buf; if (!tag) - tag = ""; // LCOV_EXCL_LINE + tag = ""; if (log_id >= LOG_ID_MAX || log_id < 0 || @@ -139,13 +139,13 @@ static int __write_to_log_pipe(log_id_t log_id, log_priority prio, const char *t * (application preloader) closing all file descriptors explicitly * (including libdlog's file descriptors) but still trying to log. */ - int was_ebadf = (errno == EBADF); // LCOV_EXCL_LINE - if (!__reconnect_pipe(log_id)) // LCOV_EXCL_LINE + int was_ebadf = (errno == EBADF); + if (!__reconnect_pipe(log_id)) return -1; - ret = write(pipe_fd[log_id], buf, ple->len); // LCOV_EXCL_LINE - if (was_ebadf) { // LCOV_EXCL_LINE - create_pipe_message(buf, DLOG_FATAL, "LIBDLOG", "libdlog's internal state has been destroyed! The user application closed libdlog's file descriptor."); // LCOV_EXCL_LINE - ret = write(pipe_fd[log_id], buf, ple->len); // LCOV_EXCL_LINE + ret = write(pipe_fd[log_id], buf, ple->len); + if (was_ebadf) { + create_pipe_message(buf, DLOG_FATAL, "LIBDLOG", "libdlog's internal state has been destroyed! The user application closed libdlog's file descriptor."); + ret = write(pipe_fd[log_id], buf, ple->len); } } return ret; @@ -171,8 +171,8 @@ void __dlog_init_pipe(const struct log_config *conf) snprintf(conf_key, sizeof(conf_key), "%s_write_sock", log_name_by_id(i)); const char * conf_val = log_config_get(conf, conf_key); if (!conf_val) { - syslog_critical_failure("DLOG CRITICAL FAILURE: DLog config lacks the \"%s\" entry!", conf_key); // LCOV_EXCL_LINE - return; // LCOV_EXCL_LINE + syslog_critical_failure("DLOG CRITICAL FAILURE: DLog config lacks the \"%s\" entry!", conf_key); + return; } if (conf_val[0] != '/') { diff --git a/src/tests/libdlog_pipe.c b/src/tests/libdlog_pipe.c new file mode 100644 index 0000000..85e3f1b --- /dev/null +++ b/src/tests/libdlog_pipe.c @@ -0,0 +1,164 @@ +#include +#include +#include + +#include +#include +#include + +#include +#include +#include + +int (*write_to_log)(log_id_t, log_priority, const char *tag, const char *msg) = NULL; +pthread_mutex_t log_init_lock = PTHREAD_MUTEX_INITIALIZER; +extern void __dlog_init_pipe(const struct log_config *conf); + +int errno_to_set; + +static bool critical_failure_detected = false; +void __wrap_syslog_critical_failure(const char *message, ...) +{ + critical_failure_detected = true; +} + +int __wrap_dup2(int oldfd, int newfd) +{ + assert(oldfd == 1337); + assert(newfd == 1337); + return 123; +} + +static int fail_write; +static size_t called_write; +ssize_t __wrap_write(int fd, const void *buf, size_t count) +{ + ++called_write; + errno = errno_to_set; + const ssize_t retval = (fail_write & 1) ? -1 : (300 + called_write); + fail_write >>= 1; + return retval; +} + +static int fail_connect; +static size_t called_connect; +int __wrap_connect(int sockfd, const struct sockaddr *addr, socklen_t addrlen) +{ + ++called_connect; + errno = errno_to_set; + const int retval = (fail_connect & 1) ? -1 : (100 + called_connect); + fail_connect >>= 1; + return retval; +} + +static int fail_recv_pipe; +static size_t called_recv_pipe; +static int expected_timeout = DEFAULT_WAIT_PIPE_MS; +int __wrap_recv_pipe(int sockfd, int timeout_ms) +{ + assert(timeout_ms == expected_timeout); + expected_timeout /= 2; + if (expected_timeout < MIN_WAIT_PIPE_MS) + expected_timeout = MIN_WAIT_PIPE_MS; + + ++called_recv_pipe; + errno = errno_to_set; + const int retval = (fail_recv_pipe & 1) ? -1 : 1337; + fail_recv_pipe >>= 1; + return retval; +} + +int main() +{ + struct log_config conf = {NULL, NULL}; + + __dlog_init_pipe(&conf); + assert(critical_failure_detected); + assert(!write_to_log); + critical_failure_detected = false; + + assert(LOG_ID_MAIN == 0); + for (int i = 1; i < LOG_ID_MAX; ++i) { + char key[MAX_CONF_KEY_LEN]; + snprintf(key, sizeof key, "%s_write_sock", log_name_by_id((log_id_t)i)); + log_config_set(&conf, key, "/foo"); + } + +#define MAXLEN (sizeof ((struct sockaddr_un *)NULL)->sun_path) // static const size_t was not enough and there is no constexpr in C + char pipe_path[MAXLEN + 2] = { 'x', 'f', 'o', 'o', '\0', [5 ... MAXLEN] = 'x' }; +#undef MAXLEN + + log_config_set(&conf, "main_write_sock", pipe_path); // "xfoo" + __dlog_init_pipe(&conf); + assert(critical_failure_detected); + assert(!write_to_log); + critical_failure_detected = false; + + pipe_path[0] = '/'; + pipe_path[4] = 'x'; + log_config_set(&conf, "main_write_sock", pipe_path); // "/fooxxxxxx..." + __dlog_init_pipe(&conf); + assert(critical_failure_detected); + assert(!write_to_log); + critical_failure_detected = false; + + pipe_path[4] = '\0'; + log_config_set(&conf, "main_write_sock", pipe_path); // "/foo" + __dlog_init_pipe(&conf); + assert(!critical_failure_detected); + assert(write_to_log); + +#define ACTUAL_PAYLOAD_SIZE (LOG_MAX_PAYLOAD_SIZE - 5) // 1 priority, 3 tag "xx\0", 1 null terminator + char payload[ACTUAL_PAYLOAD_SIZE + 1] = { [0 ... ACTUAL_PAYLOAD_SIZE] = 'x' }; + +#define F(B,P,L) assert(write_to_log(B,P,"xx",L) == DLOG_ERROR_INVALID_PARAMETER) + F(LOG_ID_MAIN , DLOG_ERROR , payload); + payload[ACTUAL_PAYLOAD_SIZE] = '\0'; + + F(LOG_ID_INVALID, DLOG_ERROR , payload); + F(LOG_ID_MAX , DLOG_ERROR , payload); + F(LOG_ID_MAIN , DLOG_UNKNOWN , payload); + F(LOG_ID_MAIN , (log_priority) -7, payload); + F(LOG_ID_MAIN , (log_priority) 23, payload); + F(LOG_ID_MAIN , DLOG_ERROR , NULL ); +#undef F + +#define TC(FC,FW,FR,ERR,RES,TAG,CC,CW,CR) do { \ + fail_connect = FC; \ + fail_write = FW; \ + fail_recv_pipe = FR; \ + errno_to_set = ERR; \ + assert(write_to_log(LOG_ID_MAIN, DLOG_ERROR, TAG, payload) == RES); \ + assert(CC == called_connect); \ + assert(CW == called_write); \ + assert(CR == called_recv_pipe); \ + called_connect = 0; \ + called_write = 0; \ + called_recv_pipe = 0; \ +} while(0) + + const size_t ITERATIONS_TO_REACH_MIN_TIMEOUT = 2 + log2(DEFAULT_WAIT_PIPE_MS / MIN_WAIT_PIPE_MS); + for (size_t i = 0; i < ITERATIONS_TO_REACH_MIN_TIMEOUT; ++i) + TC(0, 0, 1, 13, -1, "xx", 1, 1, 1); + assert(expected_timeout == MIN_WAIT_PIPE_MS); + + TC(1, 0, 0, 27, -1, "xx", 1, 0, 0); + +#define WTC(FW,ERR,RES,CC,CW,CR) TC(0,FW,0,ERR,RES,"xx",CC,CW,CR) + WTC( 1, EIO, -1, 1, 1, 0); + WTC( 0, EIO, 302, 1, 2, 1); + // at this point the first connection succeeded + WTC( 3, EBADF, -1, 1, 2, 0); + WTC( 3, EPIPE, -1, 1, 2, 0); + WTC( 1, EIO, -1, 0, 1, 0); + WTC(13, EBADF, -1, 1, 4, 1); + WTC( 5, EPIPE, -1, 1, 3, 1); + WTC( 5, EBADF, 304, 1, 4, 1); + WTC( 1, EBADF, 304, 1, 4, 1); + WTC( 1, EPIPE, 303, 1, 3, 1); +#undef WTC + + // NULL tag is fine, apparently. + TC(0, 0, 0, 45, 301, NULL, 0, 1, 0); +#undef TC +}