daemon: Introduce log mutex.
authorAndre Noll <maan@tuebingen.mpg.de>
Mon, 7 Aug 2017 22:02:03 +0000 (00:02 +0200)
committerAndre Noll <maan@tuebingen.mpg.de>
Tue, 13 Mar 2018 02:28:10 +0000 (03:28 +0100)
Currently the server processes append messages to the log file without
coordination. This usually does not cause problems, but sometimes
the log messages of the main server process and the afs process get
interleaved due to the lack of serialization.

This patch serializes access to the common log file by employing a
new lock: the log_mutex. Like the mmd_mutex, it is realized as an
one-element System V semaphore set.

Logging is performed by the daemon subsystem implemented in daemon.c.
This subsystem is also used by para_audiod which is single-threaded
and thus does not need to care about serialization of log messages.
To keep daemon.c working for both para_server and para_audiod,
struct daemon gains two optional methods, ->pre_log_hook and
->post_log_hook. If the function pointers are not NULL, the methods
are called before and after a message is logged. For para_server
the methods call back to the server code to take and release the
lock. para_audiod does not need to be modified because if the new
function pointers are left at their default value NULL, so no hooks
are called.

daemon.c
daemon.h
server.c

index ddfe680cebc63dc1c7af89fde333c665873765eb..bfa81487430f62dc7417db6ba6e0c6d53c008051 100644 (file)
--- a/daemon.c
+++ b/daemon.c
@@ -31,6 +31,12 @@ struct daemon {
        /** Used for colored log messages. */
        char log_colors[NUM_LOGLEVELS][COLOR_MAXLEN];
        char *old_cwd;
        /** Used for colored log messages. */
        char log_colors[NUM_LOGLEVELS][COLOR_MAXLEN];
        char *old_cwd;
+       /*
+        * If these pointers are non-NULL, the functions are called from
+        * daemon_log() before and after writing each log message.
+        */
+       void (*pre_log_hook)(void);
+       void (*post_log_hook)(void);
 };
 
 static struct daemon the_daemon, *me = &the_daemon;
 };
 
 static struct daemon the_daemon, *me = &the_daemon;
@@ -140,6 +146,12 @@ void daemon_set_loglevel(const char *loglevel)
        me->loglevel = ret;
 }
 
        me->loglevel = ret;
 }
 
+void daemon_set_hooks(void (*pre_log_hook)(void), void (*post_log_hook)(void))
+{
+       me->pre_log_hook = pre_log_hook;
+       me->post_log_hook = post_log_hook;
+}
+
 /**
  * Set one of the daemon config flags.
  *
 /**
  * Set one of the daemon config flags.
  *
@@ -409,6 +421,8 @@ __printf_2_3 void daemon_log(int ll, const char* fmt,...)
                return;
 
        fp = me->logfile? me->logfile : stderr;
                return;
 
        fp = me->logfile? me->logfile : stderr;
+       if (me->pre_log_hook)
+               me->pre_log_hook();
        color = daemon_test_flag(DF_COLOR_LOG)? me->log_colors[ll] : NULL;
        if (color)
                fprintf(fp, "%s", color);
        color = daemon_test_flag(DF_COLOR_LOG)? me->log_colors[ll] : NULL;
        if (color)
                fprintf(fp, "%s", color);
@@ -441,4 +455,6 @@ __printf_2_3 void daemon_log(int ll, const char* fmt,...)
        va_end(argp);
        if (color)
                fprintf(fp, "%s", COLOR_RESET);
        va_end(argp);
        if (color)
                fprintf(fp, "%s", COLOR_RESET);
+       if (me->post_log_hook)
+               me->post_log_hook();
 }
 }
index 989678df40e6b29a44ae8fb5491db05841d25bca..b530b0d76b48b673fd7ae7626c48a6dd91ab7751 100644 (file)
--- a/daemon.h
+++ b/daemon.h
@@ -11,6 +11,7 @@ void daemon_set_start_time(void);
 time_t daemon_get_uptime(const struct timeval *current_time);
 __malloc char *daemon_get_uptime_str(const struct timeval *current_time);
 void daemon_set_logfile(const char *logfile_name);
 time_t daemon_get_uptime(const struct timeval *current_time);
 __malloc char *daemon_get_uptime_str(const struct timeval *current_time);
 void daemon_set_logfile(const char *logfile_name);
+void daemon_set_hooks(void (*pre_log_hook)(void), void (*post_log_hook)(void));
 void daemon_set_flag(unsigned flag);
 void daemon_set_loglevel(const char *loglevel);
 bool daemon_init_colors_or_die(int color_arg, int color_arg_auto,
 void daemon_set_flag(unsigned flag);
 void daemon_set_loglevel(const char *loglevel);
 bool daemon_init_colors_or_die(int color_arg, int color_arg_auto,
index 13c8c85f98339023b90415125e9df275a28c98f3..690f7163984c2f00cb0de1e4982da4668676e500 100644 (file)
--- a/server.c
+++ b/server.c
@@ -100,6 +100,9 @@ uint32_t afs_socket_cookie;
 /** The mutex protecting the shared memory area containing the mmd struct. */
 int mmd_mutex;
 
 /** The mutex protecting the shared memory area containing the mmd struct. */
 int mmd_mutex;
 
+/* Serializes log output. */
+static int log_mutex;
+
 static struct sched sched;
 static struct signal_task *signal_task;
 
 static struct sched sched;
 static struct signal_task *signal_task;
 
@@ -151,9 +154,17 @@ char *server_get_tasks(void)
        return get_task_list(&sched);
 }
 
        return get_task_list(&sched);
 }
 
-/*
- * setup shared memory area and get mutex for locking
- */
+static void pre_log_hook(void)
+{
+       mutex_lock(log_mutex);
+}
+
+static void post_log_hook(void)
+{
+       mutex_unlock(log_mutex);
+}
+
+/* Setup shared memory area and init mutexes */
 static void init_ipc_or_die(void)
 {
        void *shm;
 static void init_ipc_or_die(void)
 {
        void *shm;
@@ -172,6 +183,10 @@ static void init_ipc_or_die(void)
        if (ret < 0)
                goto err_out;
        mmd_mutex = ret;
        if (ret < 0)
                goto err_out;
        mmd_mutex = ret;
+       ret = mutex_new();
+       if (ret < 0)
+               goto destroy_mmd_mutex;
+       log_mutex = ret;
 
        mmd->num_played = 0;
        mmd->num_commands = 0;
 
        mmd->num_played = 0;
        mmd->num_commands = 0;
@@ -181,6 +196,8 @@ static void init_ipc_or_die(void)
        mmd->vss_status_flags = VSS_NEXT;
        mmd->new_vss_status_flags = VSS_NEXT;
        return;
        mmd->vss_status_flags = VSS_NEXT;
        mmd->new_vss_status_flags = VSS_NEXT;
        return;
+destroy_mmd_mutex:
+       mutex_destroy(mmd_mutex);
 err_out:
        PARA_EMERG_LOG("%s\n", para_strerror(-ret));
        exit(EXIT_FAILURE);
 err_out:
        PARA_EMERG_LOG("%s\n", para_strerror(-ret));
        exit(EXIT_FAILURE);
@@ -548,8 +565,9 @@ static void server_init(int argc, char **argv, struct server_command_task *sct)
        server_pid = getpid();
        init_random_seed_or_die();
        daemon_log_welcome("server");
        server_pid = getpid();
        init_random_seed_or_die();
        daemon_log_welcome("server");
-       init_ipc_or_die(); /* init mmd struct and mmd->lock */
+       init_ipc_or_die(); /* init mmd struct, mmd and log mutex */
        daemon_set_start_time();
        daemon_set_start_time();
+       daemon_set_hooks(pre_log_hook, post_log_hook);
        PARA_NOTICE_LOG("initializing audio format handlers\n");
        afh_init();
 
        PARA_NOTICE_LOG("initializing audio format handlers\n");
        afh_init();
 
@@ -653,6 +671,8 @@ int main(int argc, char *argv[])
        signal_shutdown(signal_task);
        if (!process_is_command_handler()) { /* parent (server) */
                mutex_destroy(mmd_mutex);
        signal_shutdown(signal_task);
        if (!process_is_command_handler()) { /* parent (server) */
                mutex_destroy(mmd_mutex);
+               daemon_set_hooks(NULL, NULL); /* only one process remaining */
+               mutex_destroy(log_mutex);
                shm_detach(mmd);
                if (ret < 0)
                        PARA_EMERG_LOG("%s\n", para_strerror(-ret));
                shm_detach(mmd);
                if (ret < 0)
                        PARA_EMERG_LOG("%s\n", para_strerror(-ret));