[Minor] Further logging improvements

diff --git a/lualib/lua_redis.lua b/lualib/lua_redis.lua
index d607c68dc472db9bc3a63084f0f98721271f9bbd..fb98a5b9c26620d1215e1e21165cf8b318082a23 100644 (file)
--- a/lualib/lua_redis.lua
+++ b/lualib/lua_redis.lua
@@ -1031,7 +1031,7 @@ local function redis_make_request_taskless(ev_base, cfg, redis_params, key,
   end
 
   lutil.debugm(N, cfg, 'perform taskless request to redis server' ..
-      ' (host=%s, timeout=%s): cmd: %s', options.host,
+      ' (host=%s, timeout=%s): cmd: %s', options.host:tostring(true),
       options.timeout, options.cmd)
   local ret,conn = rspamd_redis.make_request(options)
   if not ret then

diff --git a/src/libserver/logger.h b/src/libserver/logger.h
index f8ecbf1ee6a056239a1deea53cea3e9ba31f0ed8..c5cc5beed266ed34f80625efca6112f02ba66cce 100644 (file)
--- a/src/libserver/logger.h
+++ b/src/libserver/logger.h
@@ -13,6 +13,8 @@ extern "C" {
 #define G_LOG_LEVEL_USER_SHIFT 8
 #endif
 
+#define RSPAMD_LOG_ID_LEN 6
+
 struct rspamd_config;
 
 enum rspamd_log_flags {

diff --git a/src/libserver/logger/logger_console.c b/src/libserver/logger/logger_console.c
index 1bc91007a27430a9e3126022fdb6e8b94c58cfb7..b348aa92909c66c6fd03a50bf77ca65a8c3e2ba5 100644 (file)
--- a/src/libserver/logger/logger_console.c
+++ b/src/libserver/logger/logger_console.c
@@ -228,7 +228,7 @@ rspamd_log_console_log (const gchar *module, const gchar *id,
 
                if (id != NULL) {
                        guint slen = strlen (id);
-                       slen = MIN (LOG_ID, slen);
+                       slen = MIN (RSPAMD_LOG_ID_LEN, slen);
                        mr = rspamd_snprintf (m, mremain, "<%*.s>; ", slen,
                                        id);
                        m += mr;

diff --git a/src/libserver/logger/logger_file.c b/src/libserver/logger/logger_file.c
index d8ce15de2c0c452e41fdaa822e0bc27fa1e64533..3d5cc148b7b0c04ba41e12de7c330a1d3460ca76 100644 (file)
--- a/src/libserver/logger/logger_file.c
+++ b/src/libserver/logger/logger_file.c
@@ -526,7 +526,7 @@ rspamd_log_file_log (const gchar *module, const gchar *id,
 
        if (id != NULL) {
                guint slen = strlen (id);
-               slen = MIN (LOG_ID, slen);
+               slen = MIN (RSPAMD_LOG_ID_LEN, slen);
                mr = rspamd_snprintf (m, mremain, "<%*.s>; ", slen,
                                id);
                m += mr;

diff --git a/src/libserver/logger/logger_private.h b/src/libserver/logger/logger_private.h
index 23361e38d9cc0ba91e45d057891f134ca0143e74..4b0dbfef5abc055c9889468d846e0b07490818dc 100644 (file)
--- a/src/libserver/logger/logger_private.h
+++ b/src/libserver/logger/logger_private.h
@@ -19,7 +19,6 @@
 /* How much message should be repeated before it is count to be repeated one */
 #define REPEATS_MIN 3
 #define REPEATS_MAX 300
-#define LOG_ID 6
 #define LOGBUF_LEN 8192
 
 struct rspamd_log_module {
@@ -39,7 +38,7 @@ struct rspamd_logger_error_elt {
        GQuark ptype;
        pid_t pid;
        gdouble ts;
-       gchar id[LOG_ID + 1];
+       gchar id[RSPAMD_LOG_ID_LEN + 1];
        gchar module[9];
        gchar message[];
 };

diff --git a/src/libserver/logger/logger_syslog.c b/src/libserver/logger/logger_syslog.c
index ca72279907ce92618e5387fe2bdc53fdc9e34e9d..ad10b7c133e35b743c54d3e791ea596c58932189 100644 (file)
--- a/src/libserver/logger/logger_syslog.c
+++ b/src/libserver/logger/logger_syslog.c
@@ -92,7 +92,7 @@ rspamd_log_syslog_log (const gchar *module, const gchar *id,
        }
 
        syslog (syslog_level, "<%.*s>; %s; %s: %.*s",
-                       LOG_ID, id != NULL ? id : "",
+                       RSPAMD_LOG_ID_LEN, id != NULL ? id : "",
                        module != NULL ? module : "",
                        function != NULL ? function : "",
                        (gint)mlen, message);

diff --git a/src/lua/lua_redis.c b/src/lua/lua_redis.c
index 97d521e6c72747810adb6f39ae62c61c518f729d..24d30964fd53093bdea0a697a1d6c109b5a67385 100644 (file)
--- a/src/lua/lua_redis.c
+++ b/src/lua/lua_redis.c
@@ -102,7 +102,7 @@ struct lua_redis_userdata {
        struct rspamd_config *cfg;
        struct rspamd_redis_pool *pool;
        gchar *server;
-       const gchar *log_tag;
+       gchar log_tag[RSPAMD_LOG_ID_LEN + 1];
        struct lua_redis_request_specific_userdata *specific;
        gdouble timeout;
        guint16 port;
@@ -265,7 +265,8 @@ lua_redis_fin (void *arg)
 
        ev_timer_stop (sp_ud->ctx->async.event_loop, &sp_ud->timeout_ev);
 
-       msg_debug_lua_redis ("finished redis query %p from session %p", sp_ud, ctx);
+       msg_debug_lua_redis ("finished redis query %p from session %p; refcount=%d",
+                       sp_ud, ctx, ctx->ref.refcount);
        sp_ud->flags |= LUA_REDIS_SPECIFIC_FINISHED;
 
        REDIS_RELEASE (ctx);
@@ -485,6 +486,8 @@ lua_redis_callback (redisAsyncContext *c, gpointer r, gpointer priv)
                ud->ctx = NULL;
 
                if (ac) {
+                       msg_debug_lua_redis ("release redis connection ud=%p; ctx=%p; refcount=%d",
+                                       ud, ctx, ctx->ref.refcount);
                        rspamd_redis_pool_release_connection (ud->pool, ac,
                                        (ctx->flags & LUA_REDIS_NO_POOL) ?
                                        RSPAMD_REDIS_RELEASE_ENFORCE : RSPAMD_REDIS_RELEASE_DEFAULT);
@@ -829,7 +832,7 @@ rspamd_lua_redis_prepare_connection (lua_State *L, gint *pcbref, gboolean is_asy
        struct lua_redis_userdata *ud = NULL;
        struct rspamd_lua_ip *addr = NULL;
        struct rspamd_task *task = NULL;
-       const gchar *host;
+       const gchar *host = NULL;
        const gchar *password = NULL, *dbname = NULL, *log_tag = NULL;
        gint cbref = -1;
        struct rspamd_config *cfg = NULL;
@@ -854,10 +857,6 @@ rspamd_lua_redis_prepare_connection (lua_State *L, gint *pcbref, gboolean is_asy
                        lua_gettable (L, -2);
                        if (lua_type (L, -1) == LUA_TUSERDATA) {
                                cfg = lua_check_config (L, -1);
-
-                               if (cfg) {
-                                       log_tag = cfg->cfg_pool->tag.uid;
-                               }
                        }
                        lua_pop (L, 1);
 
@@ -913,6 +912,7 @@ rspamd_lua_redis_prepare_connection (lua_State *L, gint *pcbref, gboolean is_asy
 
                if (lua_type (L, -1) == LUA_TUSERDATA) {
                        addr = lua_check_ip (L, -1);
+                       host = rspamd_inet_address_to_string_pretty (addr->addr);
                }
                else if (lua_type (L, -1) == LUA_TSTRING) {
                        host = lua_tostring (L, -1);
@@ -983,7 +983,16 @@ rspamd_lua_redis_prepare_connection (lua_State *L, gint *pcbref, gboolean is_asy
                        ud->pool = cfg->redis_pool;
                        ud->event_loop = ev_base;
                        ud->task = task;
-                       ud->log_tag = log_tag;
+
+                       if (log_tag) {
+                               rspamd_strlcpy (ud->log_tag, log_tag, sizeof (ud->log_tag));
+                       }
+                       else {
+                               /* Use pointer itself as a tag */
+                               rspamd_snprintf (ud->log_tag, sizeof (ud->log_tag),
+                                               "%ud",
+                                               (int)rspamd_cryptobox_fast_hash (&ud, sizeof (ud), 0));
+                       }
 
                        if (task) {
                                ud->item = rspamd_symcache_get_cur_item (task);
@@ -1030,7 +1039,8 @@ rspamd_lua_redis_prepare_connection (lua_State *L, gint *pcbref, gboolean is_asy
                        return NULL;
                }
 
-               msg_debug_lua_redis ("opened redis connection %p", ctx);
+               msg_debug_lua_redis ("opened redis connection host=%s; ctx=%p; ud=%p",
+                               host, ctx, ud);
 
                return ctx;
        }