[patches] [log 2/2] say: Fix log_rotate
Konstantin Osipov
kostja at tarantool.org
Thu Mar 22 16:12:20 MSK 2018
* Ilya Markov <imarkov at tarantool.org> [18/03/15 17:13]:
> * Refactor tests.
> * Add locks and condition varaible for thread-safe log_rotate usage.
>
> Follow up #3015
> ---
> src/errinj.h | 2 ++
> src/say.c | 21 +++++++++++++++
> src/say.h | 7 +++++
> test/box/errinj.result | 2 ++
> test/unit/say.c | 73 +++++++++++++++-----------------------------------
> 5 files changed, 54 insertions(+), 51 deletions(-)
>
> diff --git a/src/errinj.h b/src/errinj.h
> index 352a3c3..f13cc98 100644
> --- a/src/errinj.h
> +++ b/src/errinj.h
> @@ -107,6 +107,8 @@ struct errinj {
> _(ERRINJ_RELAY_EXIT_DELAY, ERRINJ_DOUBLE, {.dparam = 0}) \
> _(ERRINJ_VY_DELAY_PK_LOOKUP, ERRINJ_BOOL, {.bparam = false}) \
> _(ERRINJ_VY_RUN_WRITE_STMT_TIMEOUT, ERRINJ_DOUBLE, {.dparam = 0}) \
> + _(ERRINJ_LOG_ROTATE, ERRINJ_BOOL, {.bparam = false}) \
> +
>
> ENUM0(errinj_id, ERRINJ_LIST);
> extern struct errinj errinjs[];
> diff --git a/src/say.c b/src/say.c
> index b92514d..a7c4c4a 100644
> --- a/src/say.c
> +++ b/src/say.c
> @@ -30,6 +30,7 @@
> */
> #include "say.h"
> #include "fiber.h"
> +#include "errinj.h"
>
> #include <errno.h>
> #include <stdarg.h>
> @@ -242,6 +243,11 @@ log_rotate(struct log *log)
> if (log->type != SAY_LOGGER_FILE) {
> return 0;
> }
> + tt_pthread_mutex_lock(&log->mutex);
> + log->rotating_threads++;
> + tt_pthread_mutex_unlock(&log->mutex);
> + ERROR_INJECT(ERRINJ_LOG_ROTATE, { usleep(10); });
> +
> int fd = open(log->path, O_WRONLY | O_APPEND | O_CREAT,
> S_IRUSR | S_IWUSR | S_IRGRP);
> if (fd < 0) {
> @@ -276,6 +282,11 @@ log_rotate(struct log *log)
> dup2(log_default->fd, STDERR_FILENO);
> }
>
> + tt_pthread_mutex_lock(&log->mutex);
> + log->rotating_threads--;
> + tt_pthread_cond_signal(&log->cond);
You should signal the cond only when the number of rotating
threadss is <=0
> + tt_pthread_mutex_unlock(&log->mutex);
> +
> return 0;
> }
>
> @@ -502,6 +513,9 @@ log_create(struct log *log, const char *init_str, bool nonblock)
> log->format_func = NULL;
> log->level = S_INFO;
> log->nonblock = nonblock;
> + log->rotating_threads = 0;
> + tt_pthread_cond_init(&log->cond, NULL);
> + tt_pthread_mutex_init(&log->mutex, NULL);
> setvbuf(stderr, NULL, _IONBF, 0);
>
> if (init_str != NULL) {
> @@ -1016,10 +1030,17 @@ void
> log_destroy(struct log *log)
> {
> assert(log != NULL);
> + tt_pthread_mutex_lock(&log->mutex);
> + while(log->rotating_threads > 0)
> + tt_pthread_cond_wait(&log->cond, &log->mutex);
> if (log->fd != -1)
> close(log->fd);
> free(log->syslog_ident);
> rlist_del_entry(log, in_log_list);
> + log->type = SAY_LOGGER_BOOT;
> + tt_pthread_mutex_unlock(&log->mutex);
> + tt_pthread_cond_destroy(&log->cond);
> + tt_pthread_mutex_destroy(&log->mutex);
> }
>
> static inline int
> diff --git a/src/say.h b/src/say.h
> index 46e6976..953a09e 100644
> --- a/src/say.h
> +++ b/src/say.h
> @@ -119,6 +119,13 @@ struct log {
> pid_t pid;
> /* Application identifier used to group syslog messages. */
> char *syslog_ident;
> + /* mutex and conditional variable securing variable below
> + * from concurrent usage
> + */
> + pthread_mutex_t mutex;
> + pthread_cond_t cond;
> + /* Counter identifying number of threads executing log_rotate*/
> + int rotating_threads;
> struct rlist in_log_list;
> };
>
> diff --git a/test/box/errinj.result b/test/box/errinj.result
> index db27dd4..cc79c14 100644
> --- a/test/box/errinj.result
> +++ b/test/box/errinj.result
> @@ -60,6 +60,8 @@ errinj.info()
> state: false
> ERRINJ_WAL_ROTATE:
> state: false
> + ERRINJ_LOG_ROTATE:
> + state: false
> ERRINJ_RELAY_EXIT_DELAY:
> state: 0
> ERRINJ_VY_POINT_ITER_WAIT:
> diff --git a/test/unit/say.c b/test/unit/say.c
> index e2583a9..4beaa73 100644
> --- a/test/unit/say.c
> +++ b/test/unit/say.c
> @@ -4,6 +4,8 @@
> #include "unit.h"
> #include "say.h"
> #include <pthread.h>
> +#include <errinj.h>
> +#include <coio_task.h>
>
> int
> parse_logger_type(const char *input)
> @@ -61,67 +63,37 @@ 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;
> -}
> -
Please restore back concurrency tests.
> static void
> test_log_rotate()
> {
> char template[] = "/tmp/tmpdir.XXXXXX";
> const char *tmp_dir = mkdtemp(template);
> - int running = 0;
> + const int NUMBER_LOGGERS = 10;
> + struct log * loggers = (struct log *) calloc(NUMBER_LOGGERS,
> + sizeof(struct log));
> + if (loggers == NULL) {
> + return;
> + }
> + char tmp_filename[30];
> for (int i = 0; i < 10; i++) {
> - pthread_t thread;
> - if (pthread_create(&thread, NULL, dummy_log, (void *) tmp_dir) >= 0)
> - running++;
> + sprintf(tmp_filename, "%s/%i.log", tmp_dir, i);
> + log_create(&loggers[i], tmp_filename, false);
> }
> - pthread_mutex_lock(&mutex);
> - // wait loggers are created
> - while (created_logs < running) {
> - pthread_cond_wait(&cond_sync, &mutex);
> + say_logrotate(NULL, NULL, 0);
> + for (int i = 0; i < 10; i++) {
> + log_destroy(&loggers[i]);
> }
> - 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);
> + memset(loggers, '#', NUMBER_LOGGERS * sizeof(struct log));
> + free(loggers);
> + usleep(1000);
> }
>
> int main()
> {
> memory_init();
> fiber_init(fiber_c_invoke);
> + coio_init();
> + coio_enable();
> say_logger_init("/dev/null", S_INFO, 0, "plain", 0);
>
> plan(23);
> @@ -187,11 +159,10 @@ int main()
> }
> log_destroy(&test_log);
>
> + struct errinj *inj = errinj_by_name("ERRINJ_LOG_ROTATE");
> + inj->bparam = true;
> // 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);
> + inj->bparam = false;
> return check_plan();
--
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