[Rework] Logger: Fix issues found so far

diff --git a/src/controller.c b/src/controller.c
index adbc2b8485cb1df62614eab6148c4be5a56d8ff3..23ff7237bda3cc2b1a2f7d874047bd5de8c75174 100644 (file)
--- a/src/controller.c
+++ b/src/controller.c
@@ -3685,7 +3685,7 @@ start_controller_worker (struct rspamd_worker *worker)
        g_hash_table_unref (ctx->custom_commands);
 
        REF_RELEASE (ctx->cfg);
-       rspamd_log_close (worker->srv->logger, TRUE);
+       rspamd_log_close (worker->srv->logger);
 
        exit (EXIT_SUCCESS);
 }

diff --git a/src/fuzzy_storage.c b/src/fuzzy_storage.c
index bc13b7049b85162ae7334d738e1b3b1a80997151..a57f077970959fd8d419013ead078749c549e49e 100644 (file)
--- a/src/fuzzy_storage.c
+++ b/src/fuzzy_storage.c
@@ -2100,7 +2100,7 @@ start_fuzzy (struct rspamd_worker *worker)
        }
 
        REF_RELEASE (ctx->cfg);
-       rspamd_log_close (worker->srv->logger, TRUE);
+       rspamd_log_close (worker->srv->logger);
 
        exit (EXIT_SUCCESS);
 }

diff --git a/src/hs_helper.c b/src/hs_helper.c
index f6292be680e751b82c4d96dfbe4ee5485e77af3c..873dc7f8860898b5a8831a1335663091add1280e 100644 (file)
--- a/src/hs_helper.c
+++ b/src/hs_helper.c
@@ -344,7 +344,7 @@ start_hs_helper (struct rspamd_worker *worker)
        ev_loop (ctx->event_loop, 0);
        rspamd_worker_block_signals ();
 
-       rspamd_log_close (worker->srv->logger, TRUE);
+       rspamd_log_close (worker->srv->logger);
        REF_RELEASE (ctx->cfg);
 
        exit (EXIT_SUCCESS);

diff --git a/src/libserver/worker_util.c b/src/libserver/worker_util.c
index c835a4dbdf3775edc25d989ad1e8be869b3bec13..ebc6a19803d26b953935995a0f3b2bb3b6222f56 100644 (file)
--- a/src/libserver/worker_util.c
+++ b/src/libserver/worker_util.c
@@ -305,7 +305,7 @@ rspamd_worker_usr1_handler (struct rspamd_worker_signal_handler *sigh, void *arg
 {
        struct rspamd_main *rspamd_main = sigh->worker->srv;
 
-       rspamd_log_reopen (sigh->worker->srv->logger);
+       rspamd_log_reopen (sigh->worker->srv->logger, rspamd_main->cfg, -1, -1);
        msg_info_main ("logging reinitialised");
 
        /* Get more signals */
@@ -996,9 +996,7 @@ rspamd_fork_worker (struct rspamd_main *rspamd_main,
        switch (wrk->pid) {
        case 0:
                /* Update pid for logging */
-               rspamd_log_update_pid (cf->type, rspamd_main->logger);
-               /* To avoid atomic writes issue */
-               rspamd_log_reopen (rspamd_main->logger);
+               rspamd_log_on_fork (cf->type, rspamd_main->cfg, rspamd_main->logger);
                wrk->pid = getpid ();
 
                /* Init PRNG after fork */
@@ -1047,17 +1045,10 @@ rspamd_fork_worker (struct rspamd_main *rspamd_main,
                        rspamd_pidfile_close (rspamd_main->pfh);
                }
 
-               /* Do silent log reopen to avoid collisions */
-               rspamd_log_close (rspamd_main->logger, FALSE);
-
-
                if (rspamd_main->cfg->log_silent_workers) {
-                       rspamd_main->cfg->log_level = G_LOG_LEVEL_MESSAGE;
-                       rspamd_set_logger (rspamd_main->cfg, cf->type,
-                                       &rspamd_main->logger, rspamd_main->server_pool);
+                       rspamd_log_set_log_level (rspamd_main->logger, G_LOG_LEVEL_MESSAGE);
                }
 
-               rspamd_log_open (rspamd_main->logger);
                wrk->start_time = rspamd_get_calendar_ticks ();
 
                if (cf->bind_conf) {
@@ -1075,8 +1066,9 @@ rspamd_fork_worker (struct rspamd_main *rspamd_main,
                rspamd_socket_nonblocking (wrk->control_pipe[1]);
                rspamd_socket_nonblocking (wrk->srv_pipe[1]);
                rspamd_main->cfg->cur_worker = wrk;
-               /* Execute worker */
+               /* Execute worker (this function should not return normally!) */
                cf->worker->worker_start_func (wrk);
+               /* To distinguish from normal termination */
                exit (EXIT_FAILURE);
                break;
        case -1:
@@ -1167,7 +1159,7 @@ rspamd_hard_terminate (struct rspamd_main *rspamd_main)
 
        msg_err_main ("shutting down Rspamd due to fatal error");
 
-       rspamd_log_close (rspamd_main->logger, TRUE);
+       rspamd_log_close (rspamd_main->logger);
        exit (EXIT_FAILURE);
 }
 

diff --git a/src/libutil/logger.c b/src/libutil/logger.c
index af71665fda971931f9bb86addcce8d2237723cff..4fed80d3e990c2bc8eaae2a8d0744174dcb92a25 100644 (file)
--- a/src/libutil/logger.c
+++ b/src/libutil/logger.c
@@ -66,6 +66,12 @@ rspamd_log_close (rspamd_logger_t *logger)
 {
        g_assert (logger != NULL);
 
+       if (logger->closed) {
+               return;
+       }
+
+       logger->closed = TRUE;
+
        if (logger->debug_ip) {
                rspamd_map_helper_destroy_radix (logger->debug_ip);
        }
@@ -105,6 +111,15 @@ rspamd_log_reopen (rspamd_logger_t *rspamd_log,  struct rspamd_config *cfg,
 
        nspec = rspamd_log->ops.reload (rspamd_log, cfg, rspamd_log->ops.specific,
                        uid, gid, &err);
+
+       if (nspec != NULL) {
+               rspamd_log->ops.specific = nspec;
+       }
+       else {
+
+       }
+
+       return nspec != NULL;
 }
 
 static void
@@ -116,7 +131,7 @@ rspamd_emergency_logger_dtor (gpointer d)
 }
 
 rspamd_logger_t *
-rspamd_log_init (rspamd_mempool_t *pool)
+rspamd_log_open_emergency (rspamd_mempool_t *pool)
 {
        rspamd_logger_t *logger;
        GError *err = NULL;
@@ -167,8 +182,7 @@ rspamd_log_open_specific (rspamd_mempool_t *pool,
        rspamd_logger_t *logger;
        GError *err = NULL;
 
-       g_assert (default_logger == NULL);
-       g_assert (emergency_logger == NULL);
+       g_assert (emergency_logger != NULL);
 
        if (pool) {
                logger = rspamd_mempool_alloc0 (pool, sizeof (rspamd_logger_t));
@@ -208,6 +222,17 @@ rspamd_log_open_specific (rspamd_mempool_t *pool,
        g_assert (funcs != NULL);
        memcpy (&logger->ops, funcs, sizeof (*funcs));
 
+       logger->ops.specific = logger->ops.init (logger, cfg, uid, gid, &err);
+
+       if (logger->ops.specific == NULL) {
+               rspamd_common_log_function (emergency_logger, G_LOG_LEVEL_CRITICAL,
+                               "logger", NULL, G_STRFUNC,
+                               "cannot open specific logger: %e", err);
+               g_error_free (err);
+
+               return NULL;
+       }
+
        logger->pid = getpid ();
        logger->process_type = ptype;
 
@@ -241,6 +266,8 @@ rspamd_log_open_specific (rspamd_mempool_t *pool,
        }
 
        default_logger = logger;
+
+       return logger;
 }
 
 
@@ -358,7 +385,7 @@ rspamd_log_write_ringbuffer (rspamd_logger_t *rspamd_log,
        }
 
        elt->pid = rspamd_log->pid;
-       elt->ptype = rspamd_log->process_type;
+       elt->ptype = g_quark_from_string (rspamd_log->process_type);
        elt->ts = rspamd_get_calendar_ticks ();
 
        if (id) {
@@ -846,4 +873,7 @@ struct rspamd_logger_funcs*
 rspamd_logger_set_log_function (rspamd_logger_t *logger,
                                                                struct rspamd_logger_funcs *nfuncs)
 {
+       /* TODO: write this */
+
+       return NULL;
 }
\ No newline at end of file

diff --git a/src/libutil/logger_console.c b/src/libutil/logger_console.c
index fae12ea1186def8130a8e75bfb0f4d4a1dd97d42..05bb67f215b21bb5b1d7fda7be5e76b2f045fb3b 100644 (file)
--- a/src/libutil/logger_console.c
+++ b/src/libutil/logger_console.c
@@ -76,7 +76,7 @@ rspamd_log_console_init (rspamd_logger_t *logger, struct rspamd_config *cfg,
 
        if (priv->fd == -1) {
                g_set_error (err, CONSOLE_LOG_QUARK, errno,
-                               "open_log: cannot dup console fd: %s, %s\n",
+                               "open_log: cannot dup console fd: %s\n",
                                strerror (errno));
                rspamd_log_console_dtor (logger, priv);
 
@@ -85,6 +85,10 @@ rspamd_log_console_init (rspamd_logger_t *logger, struct rspamd_config *cfg,
 
        if (isatty (priv->fd)) {
                priv->log_tty = true;
+
+               if (priv->log_color) {
+                       priv->log_color = false;
+               }
        }
 
        return priv;

diff --git a/src/libutil/logger_private.h b/src/libutil/logger_private.h
index f4b6fe8d6f079787a0aa7ab941de004fa734d8d3..23361e38d9cc0ba91e45d057891f134ca0143e74 100644 (file)
--- a/src/libutil/logger_private.h
+++ b/src/libutil/logger_private.h
@@ -67,6 +67,7 @@ struct rspamd_logger_s {
        struct rspamd_cryptobox_keypair *keypair;
 
        guint flags;
+       gboolean closed;
        gboolean enabled;
        gboolean is_debug;
        gboolean no_lock;

diff --git a/src/lua/lua_worker.c b/src/lua/lua_worker.c
index 17266ae96dc7ece1348441248c4d421fb272f678..4364a1b869392965247cebe16c3001a49fa657bb 100644 (file)
--- a/src/lua/lua_worker.c
+++ b/src/lua/lua_worker.c
@@ -817,7 +817,7 @@ lua_worker_spawn_process (lua_State *L)
                gint rc;
                gchar inbuf[4];
 
-               rspamd_log_update_pid (w->cf->type, w->srv->logger);
+               rspamd_log_on_fork (w->cf->type, w->srv->cfg, w->srv->logger);
                rc = ottery_init (w->srv->cfg->libs_ctx->ottery_cfg);
 
                if (rc != OTTERY_ERR_NONE) {

diff --git a/src/rspamadm/configdump.c b/src/rspamadm/configdump.c
index 32e8ab3f1223a4349c8071c4c888e1df05862fc2..de45d1cee267ee527aad54ff6779a49765930674 100644 (file)
--- a/src/rspamadm/configdump.c
+++ b/src/rspamadm/configdump.c
@@ -89,18 +89,6 @@ rspamadm_configdump_help (gboolean full_help, const struct rspamadm_command *cmd
 static void
 config_logger (rspamd_mempool_t *pool, gpointer ud)
 {
-       struct rspamd_main *rm = ud;
-
-       rm->cfg->log_type = RSPAMD_LOG_CONSOLE;
-       rm->cfg->log_level = G_LOG_LEVEL_CRITICAL;
-
-       rspamd_set_logger (rm->cfg, g_quark_try_string ("main"), &rm->logger,
-                       rm->server_pool);
-       if (rspamd_log_open_priv (rm->logger, rm->workers_uid, rm->workers_gid) ==
-                       -1) {
-               fprintf (stderr, "Fatal error, cannot open logfile, exiting\n");
-               exit (EXIT_FAILURE);
-       }
 }
 
 static void

diff --git a/src/rspamadm/configtest.c b/src/rspamadm/configtest.c
index 1ebabe48bcdc932ce9921df0c649417104d2e584..bc7afd9d84c2d72fc80f030ebf66a319187173fa 100644 (file)
--- a/src/rspamadm/configtest.c
+++ b/src/rspamadm/configtest.c
@@ -77,25 +77,6 @@ rspamadm_configtest_help (gboolean full_help, const struct rspamadm_command *cmd
 static void
 config_logger (rspamd_mempool_t *pool, gpointer ud)
 {
-       struct rspamd_main *rm = ud;
-       GQuark configtest_quark = g_quark_from_static_string ("configtest");
-
-       rm->cfg->log_type = RSPAMD_LOG_CONSOLE;
-
-       if (quiet) {
-               rm->cfg->log_level = G_LOG_LEVEL_CRITICAL;
-       }
-       else {
-               rm->cfg->log_level = G_LOG_LEVEL_WARNING;
-       }
-
-       rspamd_set_logger (rm->cfg, configtest_quark, &rm->logger,
-                       rm->server_pool);
-       if (rspamd_log_open_priv (rm->logger, rm->workers_uid, rm->workers_gid) ==
-                       -1) {
-               fprintf (stderr, "Fatal error, cannot open logfile, exiting\n");
-               exit (EXIT_FAILURE);
-       }
 }
 
 static void

diff --git a/src/rspamadm/rspamadm.c b/src/rspamadm/rspamadm.c
index 775b505eedc22b4d8e18228685e623f2de91335c..1c1d6f52c2d64f68741d4926848c71e04469551e 100644 (file)
--- a/src/rspamadm/rspamadm.c
+++ b/src/rspamadm/rspamadm.c
@@ -438,22 +438,20 @@ main (gint argc, gchar **argv, gchar **env)
                exit (1);
        }
 
+       /* Setup logger */
+       rspamd_main->logger = rspamd_log_open_emergency (rspamd_main->server_pool);
+
        /* Setup logger */
        if (verbose) {
-               cfg->log_level = G_LOG_LEVEL_DEBUG;
-               cfg->log_flags |= RSPAMD_LOG_FLAG_USEC|RSPAMD_LOG_FLAG_ENFORCED;
+               rspamd_log_set_log_level (rspamd_main->logger, G_LOG_LEVEL_DEBUG);
+               rspamd_log_set_log_flags (rspamd_main->logger,
+                               RSPAMD_LOG_FLAG_USEC|RSPAMD_LOG_FLAG_ENFORCED|RSPAMD_LOG_FLAG_RSPAMADM);
        }
        else {
-               cfg->log_level = G_LOG_LEVEL_MESSAGE;
+               rspamd_log_set_log_level (rspamd_main->logger, G_LOG_LEVEL_MESSAGE);
+               rspamd_log_set_log_flags (rspamd_main->logger,RSPAMD_LOG_FLAG_RSPAMADM);
        }
 
-       cfg->log_type = RSPAMD_LOG_CONSOLE;
-       /* Avoid timestamps printing */
-       cfg->log_flags |= RSPAMD_LOG_FLAG_RSPAMADM;
-       rspamd_set_logger (cfg, process_quark, &rspamd_main->logger,
-                       rspamd_main->server_pool);
-       (void) rspamd_log_open (rspamd_main->logger);
-
        rspamd_main->event_loop = ev_default_loop (EVFLAG_SIGNALFD|EVBACKEND_ALL);
 
        resolver = rspamd_dns_resolver_init (rspamd_main->logger,
@@ -616,7 +614,7 @@ end:
        rspamd_dns_resolver_deinit (resolver);
        REF_RELEASE (rspamd_main->cfg);
        rspamd_http_context_free (rspamd_main->http_ctx);
-       rspamd_log_close (rspamd_main->logger, TRUE);
+       rspamd_log_close (rspamd_main->logger);
        rspamd_url_deinit ();
        g_ptr_array_free (all_commands, TRUE);
        ev_loop_destroy (rspamd_main->event_loop);

diff --git a/src/rspamd.c b/src/rspamd.c
index 108b2299694dec72a56119db637d4436707aa7c2..9a95c416a5e1661fa1617c8d64e4d90e9581b90f 100644 (file)
--- a/src/rspamd.c
+++ b/src/rspamd.c
@@ -257,12 +257,18 @@ config_logger (rspamd_mempool_t *pool, gpointer ud)
 {
        struct rspamd_main *rspamd_main = ud;
 
-       rspamd_set_logger (rspamd_main->cfg, g_quark_try_string ("main"),
-                       &rspamd_main->logger, rspamd_main->server_pool);
+       rspamd_main->logger = rspamd_log_open_specific (rspamd_main->server_pool,
+                       rspamd_main->cfg,
+                       "main",
+                       rspamd_main->workers_uid,
+                       rspamd_main->workers_gid);
 
-       if (rspamd_log_open_priv (rspamd_main->logger,
-                       rspamd_main->workers_uid, rspamd_main->workers_gid) == -1) {
-               fprintf (stderr, "Fatal error, cannot open logfile, exiting\n");
+       if (rspamd_main->logger == NULL) {
+               /*
+                * XXX:
+                * Error has been already logged (in fact,
+                * we might fall back to console logger here)
+                */
                exit (EXIT_FAILURE);
        }
 
@@ -287,24 +293,18 @@ reread_config (struct rspamd_main *rspamd_main)
        tmp_cfg->cfg_name = cfg_file;
        old_cfg = rspamd_main->cfg;
        rspamd_main->cfg = tmp_cfg;
+       rspamd_logger_t *old_logger = rspamd_main->logger;
 
        if (!load_rspamd_config (rspamd_main, tmp_cfg, TRUE, load_opts, TRUE)) {
                rspamd_main->cfg = old_cfg;
-               rspamd_log_close_priv (rspamd_main->logger,
-                                       FALSE,
-                                       rspamd_main->workers_uid,
-                                       rspamd_main->workers_gid);
-               rspamd_set_logger (rspamd_main->cfg, g_quark_try_string ("main"),
-                               &rspamd_main->logger, rspamd_main->server_pool);
-               rspamd_log_open_priv (rspamd_main->logger,
-                                       rspamd_main->workers_uid,
-                                       rspamd_main->workers_gid);
+               rspamd_main->logger = old_logger;
                msg_err_main ("cannot parse new config file, revert to old one");
                REF_RELEASE (tmp_cfg);
 
                return FALSE;
        }
        else {
+               rspamd_log_close (old_logger);
                msg_info_main ("replacing config");
                REF_RELEASE (old_cfg);
                rspamd_main->cfg->rspamd_user = rspamd_user;
@@ -975,7 +975,8 @@ rspamd_usr1_handler (struct ev_loop *loop, ev_signal *w, int revents)
        struct rspamd_main *rspamd_main = (struct rspamd_main *)w->data;
 
        if (!rspamd_main->wanna_die) {
-               rspamd_log_reopen_priv (rspamd_main->logger,
+               rspamd_log_reopen (rspamd_main->logger,
+                               rspamd_main->cfg,
                                rspamd_main->workers_uid,
                                rspamd_main->workers_gid);
                msg_info_main ("logging reinitialised");
@@ -1029,12 +1030,6 @@ rspamd_hup_handler (struct ev_loop *loop, ev_signal *w, int revents)
                /* Detach existing workers and stop their heartbeats */
                g_hash_table_foreach (rspamd_main->workers, stop_srv_ev, rspamd_main);
 
-               /* Close log to avoid FDs leak, as reread_config will re-init logging */
-               rspamd_log_close_priv (rspamd_main->logger,
-                               FALSE,
-                               rspamd_main->workers_uid,
-                               rspamd_main->workers_gid);
-
                if (reread_config (rspamd_main)) {
                        msg_info_main ("kill old workers");
                        g_hash_table_foreach (rspamd_main->workers, kill_old_workers, NULL);
@@ -1237,10 +1232,16 @@ main (gint argc, gchar **argv, gchar **env)
        type = g_quark_from_static_string ("main");
 
        /* First set logger to console logger */
-       rspamd_main->logger = rspamd_log_init (rspamd_main->server_pool);
-       rspamd_set_logger (rspamd_main->cfg, type,
-                       &rspamd_main->logger, rspamd_main->server_pool);
-       (void) rspamd_log_open (rspamd_main->logger);
+       rspamd_main->logger = rspamd_log_open_emergency (rspamd_main->server_pool);
+       g_assert (rspamd_main->logger != NULL);
+
+       if (is_debug) {
+               rspamd_log_set_log_level (rspamd_main->logger, G_LOG_LEVEL_DEBUG);
+       }
+       else {
+               rspamd_log_set_log_level (rspamd_main->logger, G_LOG_LEVEL_MESSAGE);
+       }
+
        g_log_set_default_handler (rspamd_glib_log_function, rspamd_main->logger);
        g_set_printerr_handler (rspamd_glib_printerr_function);
 
@@ -1255,10 +1256,6 @@ main (gint argc, gchar **argv, gchar **env)
 
        /* Init listen sockets hash */
        listen_sockets = g_hash_table_new (g_direct_hash, g_direct_equal);
-
-       rspamd_log_close_priv (rspamd_main->logger, FALSE,
-                       rspamd_main->workers_uid, rspamd_main->workers_gid);
-
        sqlite3_initialize ();
 
        /* Load config */
@@ -1274,7 +1271,7 @@ main (gint argc, gchar **argv, gchar **env)
 
        /* Force debug log */
        if (is_debug) {
-               rspamd_main->cfg->log_level = G_LOG_LEVEL_DEBUG;
+               rspamd_log_set_log_level (rspamd_main->logger, G_LOG_LEVEL_DEBUG);
        }
 
        /* Create rolling history */
@@ -1452,7 +1449,7 @@ main (gint argc, gchar **argv, gchar **env)
        msg_info_main ("terminating...");
 
        REF_RELEASE (rspamd_main->cfg);
-       rspamd_log_close (rspamd_main->logger, TRUE);
+       rspamd_log_close (rspamd_main->logger);
        g_hash_table_unref (rspamd_main->spairs);
        g_hash_table_unref (rspamd_main->workers);
        rspamd_mempool_delete (rspamd_main->server_pool);

diff --git a/src/rspamd_proxy.c b/src/rspamd_proxy.c
index 7e460c040ba63abca0320dcaa165e895114746b1..5050a3f65bab1dfd840e1a41bb913298d510b352 100644 (file)
--- a/src/rspamd_proxy.c
+++ b/src/rspamd_proxy.c
@@ -2369,7 +2369,7 @@ start_rspamd_proxy (struct rspamd_worker *worker)
        }
 
        REF_RELEASE (ctx->cfg);
-       rspamd_log_close (worker->srv->logger, TRUE);
+       rspamd_log_close (worker->srv->logger);
 
        exit (EXIT_SUCCESS);
 }

diff --git a/src/worker.c b/src/worker.c
index 7d955024900d0915e3c73d341f0836510fd10b37..b75cb03176fe1d8e5bebecb6b836e436d7142ce9 100644 (file)
--- a/src/worker.c
+++ b/src/worker.c
@@ -561,7 +561,7 @@ start_worker (struct rspamd_worker *worker)
 
        rspamd_stat_close ();
        REF_RELEASE (ctx->cfg);
-       rspamd_log_close (worker->srv->logger, TRUE);
+       rspamd_log_close (worker->srv->logger);
 
        exit (EXIT_SUCCESS);
 }