<HTML><BODY><br><br><br>-------- Пересылаемое сообщение --------<br>
От кого: Ilya Markov <imarkov@tarantool.org><br>
Кому: georgy@tarantool.org<br>
Копия: patches@tarantool.org<br>
Дата: Вторник, 27 марта 2018, 17:09 +03:00<br>
Тема: [patches] [log 2/2] say: Fix log_rotate<br>
<br>
<div class="js-helper js-readmsg-msg">
<style type="text/css"></style>
<div>
<base target="_self" href="https://e.mail.ru/">
<div id="style_15221597540000000077_BODY">* Refactor tests.<br>
* Add ev_async and fiber_cond for thread-safe log_rotate usage.<br>
<br>
Follow up #3015<br>
---<br>
src/errinj.h | 1 +<br>
src/say.c | 31 +++++++++++++-<br>
src/say.h | 13 ++++++<br>
test/box/errinj.result | 2 +<br>
test/unit/say.c | 107 ++++++++++++++++++++++++++++++++++---------------<br>
5 files changed, 120 insertions(+), 34 deletions(-)<br>
<br>
diff --git a/src/errinj.h b/src/errinj.h<br>
index a5417ba..6a5ba33 100644<br>
--- a/src/errinj.h<br>
+++ b/src/errinj.h<br>
@@ -108,6 +108,7 @@ struct errinj {<br>
_(ERRINJ_VY_DELAY_PK_LOOKUP, ERRINJ_BOOL, {.bparam = false}) \<br>
_(ERRINJ_VY_RUN_WRITE_STMT_TIMEOUT, ERRINJ_DOUBLE, {.dparam = 0}) \<br>
_(ERRINJ_IPROTO_TX_DELAY, ERRINJ_BOOL, {.bparam = false}) \<br>
+ _(ERRINJ_LOG_ROTATE, ERRINJ_BOOL, {.bparam = false}) \<br>
<br>
ENUM0(errinj_id, ERRINJ_LIST);<br>
extern struct errinj errinjs[];<br>
diff --git a/src/say.c b/src/say.c<br>
index b92514d..2d9357a 100644<br>
--- a/src/say.c<br>
+++ b/src/say.c<br>
@@ -30,6 +30,7 @@<br>
*/<br>
#include "say.h"<br>
#include "fiber.h"<br>
+#include "errinj.h"<br>
<br>
#include <errno.h><br>
#include <stdarg.h><br>
@@ -239,9 +240,11 @@ write_to_syslog(struct log *log, int total);<br>
static int<br>
log_rotate(struct log *log)<br>
{<br>
- if (log->type != SAY_LOGGER_FILE) {<br>
+ if (pm_atomic_load(&log->type) != SAY_LOGGER_FILE)<br>
return 0;<br>
- }<br>
+<br>
+ ERROR_INJECT(ERRINJ_LOG_ROTATE, { usleep(10); });<br>
+<br>
int fd = open(log->path, O_WRONLY | O_APPEND | O_CREAT,<br>
S_IRUSR | S_IWUSR | S_IRGRP);<br>
if (fd < 0) {<br>
@@ -282,6 +285,7 @@ log_rotate(struct log *log)<br>
struct rotate_task {<br>
struct coio_task base;<br>
struct log *log;<br>
+ struct ev_loop *loop;<br>
};<br>
<br>
static int<br>
@@ -291,6 +295,7 @@ logrotate_cb(struct coio_task *ptr)<br>
if (log_rotate(task->log) < 0) {<br>
diag_log();<br>
}<br>
+ ev_async_send(task->loop, &task->log->log_async);<br>
return 0;<br>
}<br>
<br>
@@ -303,6 +308,16 @@ logrotate_cleanup_cb(struct coio_task *ptr)<br>
return 0;<br>
}<br>
<br>
+static void<br>
+log_rotate_async_cb(struct ev_loop *loop, struct ev_async *watcher, int events)<br>
+{<br>
+ (void)loop;<br>
+ (void)events;<br>
+ struct log *log = container_of(watcher, struct log, log_async);<br>
+ log->rotating_threads--;<br>
+ fiber_cond_signal(&log->rotate_cond);<br>
+}<br>
+<br>
void<br>
say_logrotate(struct ev_loop *loop, struct ev_signal *w, int revents)<br>
{<br>
@@ -320,8 +335,11 @@ say_logrotate(struct ev_loop *loop, struct ev_signal *w, int revents)<br>
diag_log();<br>
continue;<br>
}<br>
+ ev_async_start(loop(), &log->log_async);<br>
+ log->rotating_threads++;<br>
coio_task_create(&task->base, logrotate_cb, logrotate_cleanup_cb);<br>
task->log = log;<br>
+ task->loop = loop();<br>
coio_task_post(&task->base, 0);<br>
}<br>
errno = saved_errno;<br>
@@ -502,6 +520,9 @@ log_create(struct log *log, const char *init_str, bool nonblock)<br>
log->format_func = NULL;<br>
log->level = S_INFO;<br>
log->nonblock = nonblock;<br>
+ log->rotating_threads = 0;<br>
+ fiber_cond_create(&log->rotate_cond);<br>
+ ev_async_init(&log->log_async, log_rotate_async_cb);<br>
setvbuf(stderr, NULL, _IONBF, 0);<br>
<br>
if (init_str != NULL) {<br>
@@ -1016,10 +1037,16 @@ void<br>
log_destroy(struct log *log)<br>
{<br>
assert(log != NULL);<br>
+ while(log->rotating_threads > 0)<br>
+ fiber_cond_wait(&log->rotate_cond);<br>
+ pm_atomic_store(&log->type, SAY_LOGGER_BOOT);<br>
+<br>
if (log->fd != -1)<br>
close(log->fd);<br>
free(log->syslog_ident);<br>
rlist_del_entry(log, in_log_list);<br>
+ ev_async_stop(loop(), &log->log_async);<br>
+ fiber_cond_destroy(&log->rotate_cond);<br>
}<br>
<br>
static inline int<br>
diff --git a/src/say.h b/src/say.h<br>
index 46e6976..c05ec74 100644<br>
--- a/src/say.h<br>
+++ b/src/say.h<br>
@@ -36,7 +36,9 @@<br>
#include <stdarg.h><br>
#include <errno.h><br>
#include <sys/types.h> /* pid_t */<br>
+#include <tarantool_ev.h><br>
#include "small/rlist.h"<br>
+#include "fiber_cond.h"<br>
<br>
#if defined(__cplusplus)<br>
extern "C" {<br>
@@ -119,6 +121,17 @@ struct log {<br>
pid_t pid;<br>
/* Application identifier used to group syslog messages. */<br>
char *syslog_ident;<br>
+ /**<br>
+ * Used to wake up the main logger thread from a eio thread.<br>
+ */<br>
+ ev_async log_async;<br>
+ /**<br>
+ * Conditional variable securing variable below<br>
+ * from concurrent usage.<br>
+ */<br>
+ struct fiber_cond rotate_cond;<br>
+ /** Counter identifying number of threads executing log_rotate. */<br>
+ int rotating_threads;<br>
struct rlist in_log_list;<br>
};<br>
<br>
diff --git a/test/box/errinj.result b/test/box/errinj.result<br>
index cd0c35c..1cb5c23 100644<br>
--- a/test/box/errinj.result<br>
+++ b/test/box/errinj.result<br>
@@ -60,6 +60,8 @@ errinj.info()<br>
state: false<br>
ERRINJ_WAL_ROTATE:<br>
state: false<br>
+ ERRINJ_LOG_ROTATE:<br>
+ state: false<br>
ERRINJ_VY_POINT_ITER_WAIT:<br>
state: false<br>
ERRINJ_RELAY_EXIT_DELAY:<br>
diff --git a/test/unit/say.c b/test/unit/say.c<br>
index 8c996ba..0ffd267 100644<br>
--- a/test/unit/say.c<br>
+++ b/test/unit/say.c<br>
@@ -4,6 +4,8 @@<br>
#include "unit.h"<br>
#include "say.h"<br>
#include <pthread.h><br>
+#include <errinj.h><br>
+#include <coio_task.h><br>
<br>
int<br>
parse_logger_type(const char *input)<br>
@@ -67,28 +69,34 @@ pthread_cond_t cond_sync = PTHREAD_COND_INITIALIZER;<br>
<br>
bool is_raised = false;<br>
int created_logs = 0;<br>
+const char *tmp_dir;<br>
+<br>
+struct create_log {<br>
+ struct log logger;<br>
+ int id;<br>
+};<br>
<br>
static void *<br>
dummy_log(void *arg)<br>
{<br>
- const char *tmp_dir = (const char *) arg;<br>
+ struct create_log *create_log = (struct create_log *) arg;<br>
+<br>
char tmp_filename[30];<br>
- sprintf(tmp_filename, "%s/%i.log", tmp_dir, (int) pthread_self());<br>
- pthread_mutex_lock(&mutex);<br>
- struct log test_log;<br>
- log_create(&test_log, tmp_filename, false);<br>
- // signal that log is created<br>
+ sprintf(tmp_filename, "%s/%i.log", tmp_dir, create_log->id);<br>
+ tt_pthread_mutex_lock(&mutex);<br>
+ log_create(&create_log->logger, tmp_filename, false);<br>
+<br>
+ /* signal that log is created */<br>
created_logs++;<br>
- pthread_cond_signal(&cond_sync);<br>
+ tt_pthread_cond_signal(&cond_sync);<br>
<br>
- // wait until rotate signal is raised<br>
+ /* wait until rotate signal is raised */<br>
while (!is_raised)<br>
- pthread_cond_wait(&cond, &mutex);<br>
-<br>
- log_destroy(&test_log);<br>
+ tt_pthread_cond_wait(&cond, &mutex);<br>
created_logs--;<br>
- pthread_cond_signal(&cond_sync);<br>
- pthread_mutex_unlock(&mutex);<br>
+ if (created_logs == 0)<br>
+ pthread_cond_signal(&cond_sync);<br>
+ tt_pthread_mutex_unlock(&mutex);<br>
return NULL;<br>
}<br>
<br>
@@ -96,26 +104,54 @@ static void<br>
test_log_rotate()<br>
{<br>
char template[] = "/tmp/tmpdir.XXXXXX";<br>
- const char *tmp_dir = mkdtemp(template);<br>
+ tmp_dir = mkdtemp(template);<br>
+ const int NUMBER_LOGGERS = 10;<br>
+ struct create_log *loggers = (struct create_log *) calloc(NUMBER_LOGGERS,<br>
+ sizeof(struct create_log));<br>
+ if (loggers == NULL) {<br>
+ return;<br>
+ }<br>
int running = 0;<br>
- for (int i = 0; i < 10; i++) {<br>
+ for (int i = 0; i < NUMBER_LOGGERS; i++) {<br>
pthread_t thread;<br>
- if (pthread_create(&thread, NULL, dummy_log, (void *) tmp_dir) >= 0)<br>
+ loggers[i].id = i;<br>
+ if (tt_pthread_create(&thread, NULL, dummy_log,<br>
+ (void *) &loggers[i]) >= 0)<br>
running++;<br>
}<br>
- pthread_mutex_lock(&mutex);<br>
- // wait loggers are created<br>
- while (created_logs < running) {<br>
- pthread_cond_wait(&cond_sync, &mutex);<br>
+ tt_pthread_mutex_lock(&mutex);<br>
+ /* wait loggers are created */<br>
+ while (created_logs < running)<br>
+ tt_pthread_cond_wait(&cond_sync, &mutex);<br>
+ tt_pthread_mutex_unlock(&mutex);<br>
+ say_logrotate(NULL, NULL, 0);<br>
+<br>
+ for (int i = 0; i < created_logs; i++) {<br>
+ log_destroy(&loggers[i].logger);<br>
}<br>
- raise(SIGHUP);<br>
+ memset(loggers, '#', NUMBER_LOGGERS * sizeof(struct create_log));<br>
+ free(loggers);<br>
+<br>
is_raised = true;<br>
- pthread_cond_broadcast(&cond);<br>
+ tt_pthread_cond_broadcast(&cond);<br>
<br>
- // wait until loggers are closed<br>
- while(created_logs != 0)<br>
- pthread_cond_wait(&cond_sync, &mutex);<br>
- pthread_mutex_unlock(&mutex);<br>
+ tt_pthread_mutex_lock(&mutex);<br>
+ /* wait threads are finished */<br>
+ while (created_logs > 0)<br>
+ tt_pthread_cond_wait(&cond_sync, &mutex);<br>
+ tt_pthread_mutex_unlock(&mutex);<br>
+}<br>
+<br>
+static int<br>
+main_f(va_list ap)<br>
+{<br>
+ struct errinj *inj = errinj_by_name("ERRINJ_LOG_ROTATE");<br>
+ inj->bparam = true;<br>
+ /* test on log_rotate signal handling */<br>
+ test_log_rotate();<br>
+ inj->bparam = false;<br>
+ ev_break(loop(), EVBREAK_ALL);<br>
+ return 0;<br>
}<br>
<br>
int main()<br>
@@ -187,11 +223,18 @@ int main()<br>
}<br>
log_destroy(&test_log);<br>
<br>
- // test on log_rotate signal handling<br>
- struct ev_signal ev_sig;<br>
- ev_signal_init(&ev_sig, say_logrotate, SIGHUP);<br>
- ev_signal_start(loop(), &ev_sig);<br>
- test_log_rotate();<br>
- ev_signal_stop(loop(), &ev_sig);<br>
+ coio_init();<br>
+ coio_enable();<br>
+<br>
+ struct fiber *test = fiber_new("loggers", main_f);<br>
+ if (test == NULL) {<br>
+ diag_log();<br>
+ return check_plan();<br>
+ }<br>
+ fiber_wakeup(test);<br>
+ ev_run(loop(), 0);<br>
+<br>
+ fiber_free();<br>
+ memory_free();<br>
return check_plan();<br>
}<br>
-- <br>
2.7.4<br>
<br>
</div>
<base target="_self" href="https://e.mail.ru/">
</div>
</div>
<br><hr>
<br>-- <br>Thank you,<br>Ilya Markov<br></BODY></HTML>