commit 3424122: [Rework] Logger: Fix issues found so far
Vsevolod Stakhov
vsevolod at highsecure.ru
Mon Feb 10 21:28:12 UTC 2020
Author: Vsevolod Stakhov
Date: 2020-02-10 20:53:22 +0000
URL: https://github.com/rspamd/rspamd/commit/3424122c9d082d53e8c437066d34cf602380a69c
[Rework] Logger: Fix issues found so far
---
src/controller.c | 2 +-
src/fuzzy_storage.c | 2 +-
src/hs_helper.c | 2 +-
src/libserver/worker_util.c | 20 +++++----------
src/libutil/logger.c | 38 +++++++++++++++++++++++++---
src/libutil/logger_console.c | 6 ++++-
src/libutil/logger_private.h | 1 +
src/lua/lua_worker.c | 2 +-
src/rspamadm/configdump.c | 12 ---------
src/rspamadm/configtest.c | 19 --------------
src/rspamadm/rspamadm.c | 20 +++++++--------
src/rspamd.c | 59 +++++++++++++++++++++-----------------------
src/rspamd_proxy.c | 2 +-
src/worker.c | 2 +-
14 files changed, 89 insertions(+), 98 deletions(-)
diff --git a/src/controller.c b/src/controller.c
index adbc2b848..23ff7237b 100644
--- 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 bc13b7049..a57f07797 100644
--- 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 f6292be68..873dc7f88 100644
--- 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 c835a4dbd..ebc6a1980 100644
--- 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 af71665fd..4fed80d3e 100644
--- 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 fae12ea11..05bb67f21 100644
--- 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 f4b6fe8d6..23361e38d 100644
--- 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 17266ae96..4364a1b86 100644
--- 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 32e8ab3f1..de45d1cee 100644
--- 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 1ebabe48b..bc7afd9d8 100644
--- 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 775b505ee..1c1d6f52c 100644
--- 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 108b22996..9a95c416a 100644
--- 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 7e460c040..5050a3f65 100644
--- 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 7d9550249..b75cb0317 100644
--- 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);
}
More information about the Commits
mailing list