[patches] [say 2/3] say: Wrap logrotate signal handler with ev_signal
Konstantin Osipov
kostja at tarantool.org
Tue Mar 13 21:05:36 MSK 2018
I will push these patches now. The test case should be updated re
coding style.
The patch is still incomplete. If I rotate logs while I'm
concurrently destroying a log object, there will be a crash
in concurrent access to the log object from two threads.
Please add a fix and a test case before I can close the bug.
Please use tt_pthread.h wrappers and make sure the test case
follows Tarantool coding style.
Thanks,
* Ilya Markov <imarkov at tarantool.org> [18/03/07 16:25]:
> From: IlyaMarkovMipt <markovilya197 at gmail.com>
>
> 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 b90eb88..0ac0e8f 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 ec06103..1682bae 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 65808a6..d42d5f2 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 1b63229..46e6976 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 4e4b3f9..e2583a9 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();
> }
> --
> 2.7.4
--
Konstantin Osipov, Moscow, Russia, +7 903 626 22 32
http://tarantool.org - www.twitter.com/kostja_osipov
More information about the Tarantool-patches
mailing list