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

@@ -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)

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]);
 

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) {

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

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();
 }