From 87310856d296c172f77605038146e7d279dc6e73 Mon Sep 17 00:00:00 2001 From: Fabien MARTY Date: Fri, 6 Aug 2021 17:03:07 +0200 Subject: [PATCH 1/6] fix: potential fix for malloc deadlock in some corner cases This is a big change with a refactor to circumvent the problem by using threads instead of signal handlers. Close: #29 --- src/Makefile | 6 +++--- src/log_proxy.c | 45 +++++++++++++++++++++------------------------ src/out.c | 1 - 3 files changed, 24 insertions(+), 28 deletions(-) diff --git a/src/Makefile b/src/Makefile index 1c61aae..11df469 100644 --- a/src/Makefile +++ b/src/Makefile @@ -32,11 +32,11 @@ else DEBUG_CFLAGS=-O2 -Os endif ifeq ($(shell expr $(GCC_VERSION) \< "8.0.0" ), 1) - _CFLAGS=$(CFLAGS) -I. $(shell pkg-config --cflags $(_STATIC_EXTRA_OPT) glib-2.0) -fPIC -Wall -std=c99 -Wextra -pedantic -Wshadow -Wstrict-overflow -Wno-deprecated-declarations -fno-strict-aliasing -DG_LOG_DOMAIN=\"log_proxy\" $(DEBUG_CFLAGS) $(COVERAGE_CFLAGS) + _CFLAGS=$(CFLAGS) -I. $(shell pkg-config --cflags $(_STATIC_EXTRA_OPT) glib-2.0 gthread-2.0) -fPIC -Wall -std=c99 -Wextra -pedantic -Wshadow -Wstrict-overflow -Wno-deprecated-declarations -fno-strict-aliasing -DG_LOG_DOMAIN=\"log_proxy\" $(DEBUG_CFLAGS) $(COVERAGE_CFLAGS) else - _CFLAGS=$(CFLAGS) -I. $(shell pkg-config --cflags $(_STATIC_EXTRA_OPT) glib-2.0) -fPIC -Wall -std=c99 -Wextra -pedantic -Wshadow -Wstrict-overflow -Wno-deprecated-declarations -Wno-cast-function-type -fno-strict-aliasing -DG_LOG_DOMAIN=\"log_proxy\" $(DEBUG_CFLAGS) $(COVERAGE_CFLAGS) + _CFLAGS=$(CFLAGS) -I. $(shell pkg-config --cflags $(_STATIC_EXTRA_OPT) glib-2.0 gthread-2.0) -fPIC -Wall -std=c99 -Wextra -pedantic -Wshadow -Wstrict-overflow -Wno-deprecated-declarations -Wno-cast-function-type -fno-strict-aliasing -DG_LOG_DOMAIN=\"log_proxy\" $(DEBUG_CFLAGS) $(COVERAGE_CFLAGS) endif -_LDFLAGS=$(LDFLAGS) -L. $(shell pkg-config --libs $(_STATIC_EXTRA_OPT) glib-2.0) $(shell echo '$(FORCE_RPATH_STR)' |sed 's/@/$$/g' |sed s/~/"'"/g) -lrt +_LDFLAGS=$(LDFLAGS) -L. $(shell pkg-config --libs $(_STATIC_EXTRA_OPT) glib-2.0 gthread-2.0) $(shell echo '$(FORCE_RPATH_STR)' |sed 's/@/$$/g' |sed s/~/"'"/g) -lrt OBJECTS=util.o control.o out.o BINARIES=log_proxy log_proxy_wrapper diff --git a/src/log_proxy.c b/src/log_proxy.c index 74fbbed..f0f9aea 100644 --- a/src/log_proxy.c +++ b/src/log_proxy.c @@ -17,6 +17,7 @@ struct sigaction sigact; static gboolean first_iteration = TRUE; +static GMutex *mutex = NULL; gint _list_compare(gconstpointer a, gconstpointer b) { gchar *ca = (gchar *) a; @@ -24,6 +25,8 @@ gint _list_compare(gconstpointer a, gconstpointer b) { return g_strcmp0(cb, ca); } +#define UNUSED(x) (void)(x) + void clean_too_old_files() { gchar *dirpath = g_path_get_dirname(log_file); GDir *dir = g_dir_open(dirpath, 0, NULL); @@ -97,7 +100,8 @@ void signal_handler(int signum) { } } -static void every_second(int sig) { + +static void every_second() { int fd = lock_control_file(log_file); if (fd >= 0) { if (first_iteration) { @@ -111,19 +115,11 @@ static void every_second(int sig) { destroy_output_channel(); init_output_channel(log_file, use_locks, TRUE, chmod_str, chown_str, chgrp_str); unlock_control_file(fd); - if (sig > 0) { - // if sig<0, this is the final call before program end - alarm(1); - } return; } glong size = get_file_size(log_file); if (size < 0) { unlock_control_file(fd); - if (sig > 0) { - // if sig<0, this is the final call before program end - alarm(1); - } return; } gboolean must_rotate = FALSE; @@ -149,18 +145,16 @@ static void every_second(int sig) { } unlock_control_file(fd); } - if (sig > 0) { - // if sig<0, this is the final call before program end - alarm(1); - } } -void init_every_second_signal() { - sigact.sa_handler = every_second; - sigemptyset(&sigact.sa_mask); - sigact.sa_flags = 0; - sigaction(SIGALRM, &sigact, (struct sigaction *)NULL); - alarm(1); +gpointer management_thread(gpointer data) { + UNUSED(data); + while TRUE { + sleep(1); + g_mutex_lock(mutex); + every_second(0); + g_mutex_unlock(mutex); + } } void init_or_reinit_output_channel(const gchar *lg_file, gboolean us_locks) { @@ -198,6 +192,8 @@ int main(int argc, char *argv[]) g_print("%s", g_option_context_get_help(context, TRUE, NULL)); exit(1); } + g_thread_init(NULL); + mutex = g_mutex_new(); atexit(exit_handler); signal(SIGTERM, signal_handler); signal(SIGINT, signal_handler); @@ -228,30 +224,31 @@ int main(int argc, char *argv[]) GIOStatus in_status = G_IO_STATUS_NORMAL; GString *in_buffer = g_string_new(NULL); init_or_reinit_output_channel(log_file, use_locks); - init_every_second_signal(); + GThread* management = g_thread_create(management_thread, NULL, FALSE, NULL); + UNUSED(management); while ((in_status != G_IO_STATUS_EOF) && (in_status != G_IO_STATUS_ERROR)) { in_status = g_io_channel_read_line_string(in, in_buffer, NULL, NULL); if (in_status == G_IO_STATUS_NORMAL) { + g_mutex_lock(mutex); while (TRUE) { gboolean write_status = write_output_channel(in_buffer); if (write_status == FALSE) { g_warning("error during write on: %s", log_file); - alarm(0); // to avoid a potential deadlock with SIGALARM every_second() calls init_or_reinit_output_channel(log_file, use_locks); - alarm(1); continue; } break; } + g_mutex_unlock(mutex); } } - alarm(0); // to avoid a potential deadlock with SIGALARM every_second() calls - every_second(-1); + every_second(); destroy_output_channel(); g_io_channel_shutdown(in, FALSE, NULL); g_io_channel_unref(in); g_string_free(in_buffer, TRUE); g_option_context_free(context); g_free(log_file); + g_mutex_free(mutex); return 0; } diff --git a/src/out.c b/src/out.c index cf70b0f..afdbd14 100644 --- a/src/out.c +++ b/src/out.c @@ -6,7 +6,6 @@ #include #include #include -#include #include #include "util.h" #include "control.h" From bfdee3fcde11ea1ffd7fb8726256294dfe67aabd Mon Sep 17 00:00:00 2001 From: Fabien MARTY Date: Fri, 6 Aug 2021 21:36:24 +0200 Subject: [PATCH 2/6] build: fix every_second signature --- src/log_proxy.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/log_proxy.c b/src/log_proxy.c index f0f9aea..966104b 100644 --- a/src/log_proxy.c +++ b/src/log_proxy.c @@ -152,7 +152,7 @@ gpointer management_thread(gpointer data) { while TRUE { sleep(1); g_mutex_lock(mutex); - every_second(0); + every_second(); g_mutex_unlock(mutex); } } From 6a9359675a1797c941a976a4f5c280bb3b0d4d72 Mon Sep 17 00:00:00 2001 From: Fabien MARTY Date: Fri, 6 Aug 2021 21:56:44 +0200 Subject: [PATCH 3/6] build: better shutdown process --- src/log_proxy.c | 27 +++++++++++++-------------- 1 file changed, 13 insertions(+), 14 deletions(-) diff --git a/src/log_proxy.c b/src/log_proxy.c index 966104b..34baa27 100644 --- a/src/log_proxy.c +++ b/src/log_proxy.c @@ -18,6 +18,8 @@ struct sigaction sigact; static gboolean first_iteration = TRUE; static GMutex *mutex = NULL; +static gboolean stop_flag = FALSE; +static GIOChannel *in = NULL; gint _list_compare(gconstpointer a, gconstpointer b) { gchar *ca = (gchar *) a; @@ -95,13 +97,14 @@ gboolean rotate() { void signal_handler(int signum) { if ((signum == SIGTERM) || (signum == SIGTERM)) { - // nice exit to execute exit_handler - exit(0); + stop_flag = TRUE; } } - static void every_second() { + if (stop_flag == TRUE) { + return; + } int fd = lock_control_file(log_file); if (fd >= 0) { if (first_iteration) { @@ -149,12 +152,13 @@ static void every_second() { gpointer management_thread(gpointer data) { UNUSED(data); - while TRUE { + while (stop_flag == FALSE) { sleep(1); g_mutex_lock(mutex); every_second(); g_mutex_unlock(mutex); } + g_io_channel_shutdown(in); } void init_or_reinit_output_channel(const gchar *lg_file, gboolean us_locks) { @@ -168,14 +172,6 @@ void init_or_reinit_output_channel(const gchar *lg_file, gboolean us_locks) { unlock_control_file(lock_fd); } -void exit_handler() { - if (rm_fifo_at_exit == TRUE) { - if (fifo != NULL) { - g_unlink(fifo); - } - } -} - int main(int argc, char *argv[]) { GOptionContext *context; @@ -194,7 +190,6 @@ int main(int argc, char *argv[]) } g_thread_init(NULL); mutex = g_mutex_new(); - atexit(exit_handler); signal(SIGTERM, signal_handler); signal(SIGINT, signal_handler); set_default_values_from_env(); @@ -208,7 +203,6 @@ int main(int argc, char *argv[]) } } g_free(log_dir); - GIOChannel *in = NULL; if (fifo == NULL) { // We read from stdin in = g_io_channel_unix_new(fileno(stdin)); @@ -250,5 +244,10 @@ int main(int argc, char *argv[]) g_option_context_free(context); g_free(log_file); g_mutex_free(mutex); + if (rm_fifo_at_exit == TRUE) { + if (fifo != NULL) { + g_unlink(fifo); + } + } return 0; } From 208cb3912c4c9eb0493b7b3c76c5297eb62f1cb7 Mon Sep 17 00:00:00 2001 From: Fabien MARTY Date: Fri, 6 Aug 2021 22:00:56 +0200 Subject: [PATCH 4/6] Update log_proxy.c --- src/log_proxy.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/log_proxy.c b/src/log_proxy.c index 34baa27..0371985 100644 --- a/src/log_proxy.c +++ b/src/log_proxy.c @@ -220,7 +220,7 @@ int main(int argc, char *argv[]) init_or_reinit_output_channel(log_file, use_locks); GThread* management = g_thread_create(management_thread, NULL, FALSE, NULL); UNUSED(management); - while ((in_status != G_IO_STATUS_EOF) && (in_status != G_IO_STATUS_ERROR)) { + while ((stop_flag == FALSE) && (in_status != G_IO_STATUS_EOF) && (in_status != G_IO_STATUS_ERROR)) { in_status = g_io_channel_read_line_string(in, in_buffer, NULL, NULL); if (in_status == G_IO_STATUS_NORMAL) { g_mutex_lock(mutex); From 9b97aea683b3827c384c2fae2e73d2a12c71fdb1 Mon Sep 17 00:00:00 2001 From: Fabien MARTY Date: Fri, 6 Aug 2021 22:04:21 +0200 Subject: [PATCH 5/6] Update log_proxy.c --- src/log_proxy.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/log_proxy.c b/src/log_proxy.c index 0371985..3afa332 100644 --- a/src/log_proxy.c +++ b/src/log_proxy.c @@ -158,7 +158,7 @@ gpointer management_thread(gpointer data) { every_second(); g_mutex_unlock(mutex); } - g_io_channel_shutdown(in); + g_io_channel_shutdown(in, TRUE, NULL); } void init_or_reinit_output_channel(const gchar *lg_file, gboolean us_locks) { From e3fa3e3348c23c3b4be20fe64039357fc573dedf Mon Sep 17 00:00:00 2001 From: Fabien MARTY Date: Fri, 6 Aug 2021 22:07:32 +0200 Subject: [PATCH 6/6] Update log_proxy.c --- src/log_proxy.c | 69 ++++++++++++++++++++++++++++++++++++------------- 1 file changed, 51 insertions(+), 18 deletions(-) diff --git a/src/log_proxy.c b/src/log_proxy.c index 3afa332..5627384 100644 --- a/src/log_proxy.c +++ b/src/log_proxy.c @@ -18,7 +18,8 @@ struct sigaction sigact; static gboolean first_iteration = TRUE; static GMutex *mutex = NULL; -static gboolean stop_flag = FALSE; +static GAsyncQueue *queue = NULL; +static volatile gboolean stop_signal = FALSE; static GIOChannel *in = NULL; gint _list_compare(gconstpointer a, gconstpointer b) { @@ -97,14 +98,11 @@ gboolean rotate() { void signal_handler(int signum) { if ((signum == SIGTERM) || (signum == SIGTERM)) { - stop_flag = TRUE; + stop_signal = TRUE; } } static void every_second() { - if (stop_flag == TRUE) { - return; - } int fd = lock_control_file(log_file); if (fd >= 0) { if (first_iteration) { @@ -150,15 +148,51 @@ static void every_second() { } } -gpointer management_thread(gpointer data) { +gpointer stop_thread(gpointer data) { + // we do this here and not in signal_handler to avoid malloc in signal + // handlers UNUSED(data); - while (stop_flag == FALSE) { + while (stop_signal == FALSE) { sleep(1); + } + g_async_queue_push(queue, GINT_TO_POINTER(2)); + return NULL; +} + +gpointer management_thread(gpointer data) { + gpointer qdata; + GTimeVal tval; + gint stop_flag = 0; + UNUSED(data); + while (TRUE) { + g_get_current_time(&tval); + g_time_val_add(&tval, 1000000); + qdata = g_async_queue_timed_pop(queue, &tval); + if (qdata != NULL) { + stop_flag = GPOINTER_TO_INT(qdata); + } g_mutex_lock(mutex); every_second(); g_mutex_unlock(mutex); + if (qdata != NULL) { + break; + } + } + if (stop_flag == 2) { + // in this case (sigterm), we prefer to keep the mutex + g_mutex_lock(mutex); } - g_io_channel_shutdown(in, TRUE, NULL); + destroy_output_channel(); + if (rm_fifo_at_exit == TRUE) { + if (fifo != NULL) { + g_unlink(fifo); + } + } + if (stop_flag == 2) { + // we exit here for sigterm as main thread is blocked in reading + exit(0); + } + return NULL; } void init_or_reinit_output_channel(const gchar *lg_file, gboolean us_locks) { @@ -190,6 +224,7 @@ int main(int argc, char *argv[]) } g_thread_init(NULL); mutex = g_mutex_new(); + queue = g_async_queue_new(); signal(SIGTERM, signal_handler); signal(SIGINT, signal_handler); set_default_values_from_env(); @@ -218,9 +253,9 @@ int main(int argc, char *argv[]) GIOStatus in_status = G_IO_STATUS_NORMAL; GString *in_buffer = g_string_new(NULL); init_or_reinit_output_channel(log_file, use_locks); - GThread* management = g_thread_create(management_thread, NULL, FALSE, NULL); - UNUSED(management); - while ((stop_flag == FALSE) && (in_status != G_IO_STATUS_EOF) && (in_status != G_IO_STATUS_ERROR)) { + g_thread_create(stop_thread, NULL, FALSE, NULL); + GThread* management = g_thread_create(management_thread, NULL, TRUE, NULL); + while ((in_status != G_IO_STATUS_EOF) && (in_status != G_IO_STATUS_ERROR)) { in_status = g_io_channel_read_line_string(in, in_buffer, NULL, NULL); if (in_status == G_IO_STATUS_NORMAL) { g_mutex_lock(mutex); @@ -236,18 +271,16 @@ int main(int argc, char *argv[]) g_mutex_unlock(mutex); } } - every_second(); - destroy_output_channel(); + // if we are here, the "in" input channel is closed + signal(SIGINT, SIG_DFL); + signal(SIGTERM, SIG_DFL); + g_async_queue_push(queue, GINT_TO_POINTER(1)); + g_thread_join(management); g_io_channel_shutdown(in, FALSE, NULL); g_io_channel_unref(in); g_string_free(in_buffer, TRUE); g_option_context_free(context); g_free(log_file); g_mutex_free(mutex); - if (rm_fifo_at_exit == TRUE) { - if (fifo != NULL) { - g_unlink(fifo); - } - } return 0; }