[Feature] Allow to have high precision timestamps in logs

diff --git a/src/libserver/cfg_file.h b/src/libserver/cfg_file.h
index 45202f5ab92e96937f28a3ba8f8863f1fa6ff0e2..d96c6e474605fb664529261b1672cfff23f461f4 100644 (file)
--- a/src/libserver/cfg_file.h
+++ b/src/libserver/cfg_file.h
@@ -334,6 +334,7 @@ struct rspamd_config {
        gboolean log_extended;                          /**< log extended information                                                   */
        gboolean log_systemd;                           /**< special case for systemd logger                                    */
        gboolean log_re_cache;                          /**< show statistics about regexps                                              */
+       gboolean log_usec;                              /**< log microseconds if possible                                               */
        guint log_error_elts;                           /**< number of elements in error logbuf                                 */
        guint log_error_elt_maxlen;                     /**< maximum size of error log element                                  */
        struct rspamd_worker_log_pipe *log_pipes;

diff --git a/src/libserver/cfg_rcl.c b/src/libserver/cfg_rcl.c
index 596be1cf6782939ebc665df179cad0f1024d6dde..acd108f6ce95187cd6e260bde036392f291f5f6f 100644 (file)
--- a/src/libserver/cfg_rcl.c
+++ b/src/libserver/cfg_rcl.c
@@ -1851,6 +1851,12 @@ rspamd_rcl_config_init (struct rspamd_config *cfg)
                        G_STRUCT_OFFSET (struct rspamd_config, log_error_elt_maxlen),
                        RSPAMD_CL_FLAG_UINT,
                        "Size of each element in error log buffer (1000 by default)");
+       rspamd_rcl_add_default_handler (sub,
+                       "log_usec",
+                       rspamd_rcl_parse_struct_boolean,
+                       G_STRUCT_OFFSET (struct rspamd_config, log_usec),
+                       0,
+                       "Use microseconds resolution for timestamps");
        /**
         * Options section
         */

diff --git a/src/libutil/logger.c b/src/libutil/logger.c
index d4e3e95a7afa3b25d4d61c684e1bb8331082cd56..de301cc62cffac75e29c337bc5f388f1a856398f 100644 (file)
--- a/src/libutil/logger.c
+++ b/src/libutil/logger.c
@@ -833,9 +833,9 @@ file_log_function (const gchar *module, const gchar *id,
                const gchar *message,
                gpointer arg)
 {
-       gchar tmpbuf[256], timebuf[32], modulebuf[64];
+       gchar tmpbuf[256], timebuf[64], modulebuf[64];
        gchar *m;
-       time_t now;
+       gdouble now;
        struct tm *tms;
        struct iovec iov[5];
        gulong r = 0, mr = 0;
@@ -851,7 +851,7 @@ file_log_function (const gchar *module, const gchar *id,
 
        /* Check throttling due to write errors */
        if (!(level_flags & RSPAMD_LOG_FORCED) && rspamd_log->throttling) {
-               now = time (NULL);
+               now = rspamd_get_calendar_ticks ();
                if (rspamd_log->throttling_time != now) {
                        rspamd_log->throttling_time = now;
                        got_time = TRUE;
@@ -973,14 +973,25 @@ file_log_function (const gchar *module, const gchar *id,
 
        if (rspamd_log->cfg->log_extended) {
                if (!got_time) {
-                       now = time (NULL);
+                       now = rspamd_get_calendar_ticks ();
                }
 
                /* Format time */
                if (!rspamd_log->cfg->log_systemd) {
-                       tms = localtime (&now);
+                       time_t sec = now;
+                       gsize r;
 
-                       strftime (timebuf, sizeof (timebuf), "%F %H:%M:%S", tms);
+                       tms = localtime (&sec);
+                       r = strftime (timebuf, sizeof (timebuf), "%F %H:%M:%S", tms);
+
+                       if (rspamd_log->cfg->log_usec) {
+                               gchar usec_buf[16];
+
+                               rspamd_snprintf (usec_buf, sizeof (usec_buf), "%.5f",
+                                               now - (gdouble)sec);
+                               rspamd_snprintf (timebuf + r, sizeof (timebuf) - r,
+                                               "%s", usec_buf + 1);
+                       }
                }
 
                cptype = g_quark_to_string (rspamd_log->process_type);