From 9f99bc626dcc0cf232c5144540c289bff5c50718 Mon Sep 17 00:00:00 2001 From: IlyaMarkovMipt <markovilya197@gmail.com> Date: Tue, 23 Jan 2018 16:23:29 +0300 Subject: [PATCH] say: Wrap logrotate signal handler with ev_signal Current log rotation is not async signal safe. In order to make it so refactor signal handling with ev_signal. Log rotation for each logger performs in separate coio_task to provide async and thread-safe execution. Relates #3015 --- src/lua/log.lua | 8 ++++-- src/main.cc | 3 ++- src/say.c | 58 ++++++++++++++++++++++++++++++++++--------- src/say.h | 5 +++- test/unit/say.c | 65 +++++++++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 124 insertions(+), 15 deletions(-) diff --git a/src/lua/log.lua b/src/lua/log.lua index b90eb88bbb..0ac0e8f261 100644 --- a/src/lua/log.lua +++ b/src/lua/log.lua @@ -12,7 +12,11 @@ ffi.cdef[[ extern sayfunc_t _say; - extern void say_logrotate(int); + extern struct ev_loop; + extern struct ev_signal; + + extern void + say_logrotate(struct ev_loop *, struct ev_signal *, int); enum say_level { S_FATAL, @@ -104,7 +108,7 @@ local function say_closure(lvl) end local function log_rotate() - ffi.C.say_logrotate(0) + ffi.C.say_logrotate(nil, nil, 0) end local function log_level(level) diff --git a/src/main.cc b/src/main.cc index ec061030c5..1682baea0b 100644 --- a/src/main.cc +++ b/src/main.cc @@ -83,7 +83,7 @@ static char *pid_file = NULL; static char **main_argv; static int main_argc; /** Signals handled after start as part of the event loop. */ -static ev_signal ev_sigs[5]; +static ev_signal ev_sigs[6]; static const int ev_sig_count = sizeof(ev_sigs)/sizeof(*ev_sigs); static double start_time; @@ -335,6 +335,7 @@ signal_init(void) ev_signal_init(&ev_sigs[2], signal_cb, SIGTERM); ev_signal_init(&ev_sigs[3], signal_cb, SIGHUP); ev_signal_init(&ev_sigs[4], signal_sigwinch_cb, SIGWINCH); + ev_signal_init(&ev_sigs[5], say_logrotate, SIGHUP); for (int i = 0; i < ev_sig_count; i++) ev_signal_start(loop(), &ev_sigs[i]); diff --git a/src/say.c b/src/say.c index 65808a631b..d42d5f21e0 100644 --- a/src/say.c +++ b/src/say.c @@ -42,6 +42,7 @@ #include <sys/socket.h> #include <sys/un.h> #include <arpa/inet.h> +#include <coio_task.h> pid_t log_pid = 0; int log_level = S_INFO; @@ -265,26 +266,62 @@ log_rotate(const struct log *log) ssize_t r = write(log->fd, logrotate_message, (sizeof logrotate_message) - 1); (void) r; + /* + * log_background applies only to log_default logger + */ + if (log == log_default && log_background && + log->type == SAY_LOGGER_FILE) { + dup2(log_default->fd, STDOUT_FILENO); + dup2(log_default->fd, STDERR_FILENO); + } + + return 0; +} + +struct rotate_task { + struct coio_task base; + struct log *log; +}; + +static int +logrotate_cb(struct coio_task *ptr) +{ + struct rotate_task *task = (struct rotate_task *) ptr; + if (log_rotate(task->log) < 0) { + diag_log(); + } + return 0; +} + +static int +logrotate_cleanup_cb(struct coio_task *ptr) +{ + struct rotate_task *task = (struct rotate_task *) ptr; + coio_task_destroy(&task->base); + free(task); return 0; } void -say_logrotate(int signo) +say_logrotate(struct ev_loop *loop, struct ev_signal *w, int revents) { - (void) signo; + (void) loop; + (void) w; + (void) revents; int saved_errno = errno; struct log *log; rlist_foreach_entry(log, &log_rotate_list, in_log_list) { - if (log_rotate(log) < 0) { + struct rotate_task *task = + (struct rotate_task *) calloc(1, sizeof(*task)); + if (task == NULL) { + diag_set(OutOfMemory, sizeof(*task), "malloc", + "say_logrotate"); diag_log(); + continue; } - } - /* - * log_background applies only to log_default logger - */ - if (log_background && log_default->type == SAY_LOGGER_FILE) { - dup2(log_default->fd, STDOUT_FILENO); - dup2(log_default->fd, STDERR_FILENO); + coio_task_create(&task->base, logrotate_cb, logrotate_cleanup_cb); + task->log = log; + coio_task_post(&task->base, 0); } errno = saved_errno; } @@ -535,7 +572,6 @@ say_logger_init(const char *init_str, int level, int nonblock, say_set_log_level(level); log_background = background; log_pid = log_default->pid; - signal(SIGHUP, say_logrotate); say_set_log_format(say_format_by_name(format)); if (background) { diff --git a/src/say.h b/src/say.h index 1b632298ba..46e6976e46 100644 --- a/src/say.h +++ b/src/say.h @@ -185,8 +185,11 @@ say_set_log_format(enum say_format format); enum say_format say_format_by_name(const char *format); +struct ev_loop; +struct ev_signal; + void -say_logrotate(int /* signo */); +say_logrotate(struct ev_loop *, struct ev_signal *, int /* revents */); /** Init default logger. */ void diff --git a/test/unit/say.c b/test/unit/say.c index 4e4b3f94e8..e2583a93aa 100644 --- a/test/unit/say.c +++ b/test/unit/say.c @@ -3,6 +3,7 @@ #include <memory.h> #include "unit.h" #include "say.h" +#include <pthread.h> int parse_logger_type(const char *input) @@ -60,6 +61,63 @@ format_func_custom(struct log *log, char *buf, int len, int level, return total; } +pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER; +pthread_cond_t cond = PTHREAD_COND_INITIALIZER; +pthread_cond_t cond_sync = PTHREAD_COND_INITIALIZER; + +bool is_raised = false; +int created_logs = 0; + +static void * +dummy_log(void *arg) +{ + const char *tmp_dir = (const char *) arg; + char tmp_filename[30]; + sprintf(tmp_filename, "%s/%i.log", tmp_dir, (int) pthread_self()); + pthread_mutex_lock(&mutex); + struct log test_log; + log_create(&test_log, tmp_filename, false); + // signal that log is created + created_logs++; + pthread_cond_signal(&cond_sync); + + // wait until rotate signal is raised + while (!is_raised) + pthread_cond_wait(&cond, &mutex); + + log_destroy(&test_log); + created_logs--; + pthread_cond_signal(&cond_sync); + pthread_mutex_unlock(&mutex); + return NULL; +} + +static void +test_log_rotate() +{ + char template[] = "/tmp/tmpdir.XXXXXX"; + const char *tmp_dir = mkdtemp(template); + int running = 0; + for (int i = 0; i < 10; i++) { + pthread_t thread; + if (pthread_create(&thread, NULL, dummy_log, (void *) tmp_dir) >= 0) + running++; + } + pthread_mutex_lock(&mutex); + // wait loggers are created + while (created_logs < running) { + pthread_cond_wait(&cond_sync, &mutex); + } + raise(SIGHUP); + is_raised = true; + pthread_cond_broadcast(&cond); + + // wait until loggers are closed + while(created_logs != 0) + pthread_cond_wait(&cond_sync, &mutex); + pthread_mutex_unlock(&mutex); +} + int main() { memory_init(); @@ -128,5 +186,12 @@ int main() ok(strstr(line, "\"msg\" = \"hello user\"") != NULL, "custom"); } log_destroy(&test_log); + + // test on log_rotate signal handling + struct ev_signal ev_sig; + ev_signal_init(&ev_sig, say_logrotate, SIGHUP); + ev_signal_start(loop(), &ev_sig); + test_log_rotate(); + ev_signal_stop(loop(), &ev_sig); return check_plan(); } -- GitLab