file-logger: Add option to print milliseconds within the current second after timestamp

For this to look right time_format should end with %S or %T.

Closes strongswan/strongswan#18.

diff --git a/conf/options/charon-logging.opt b/conf/options/charon-logging.opt
index b437a9c..2bbb5dc 100644 (file)
--- a/conf/options/charon-logging.opt
+++ b/conf/options/charon-logging.opt
@@ -28,6 +28,10 @@ charon.filelog.<filename>.time_format
        Prefix each log entry with a timestamp. The option accepts a format string
        as passed to **strftime**(3).
 
+charon.filelog.<filename>.time_add_ms = no
+       Adds the milliseconds within the current second after the timestamp
+       (separated by a dot, so _time_format_ should end with %S or %T).
+
 charon.syslog {}
        Section to define syslog loggers, see LOGGER CONFIGURATION in
        **strongswan.conf**(5).

diff --git a/src/conftest/conftest.c b/src/conftest/conftest.c
index a134d53..eadb181 100644 (file)
--- a/src/conftest/conftest.c
+++ b/src/conftest/conftest.c
@@ -390,7 +390,7 @@ static void load_logger_options(file_logger_t *logger, char *section)
        ike_name = conftest->test->get_bool(conftest->test,
                                        "log.%s.ike_name", FALSE, section);
 
-       logger->set_options(logger, time_format, ike_name);
+       logger->set_options(logger, time_format, FALSE, ike_name);
 }
 
 /**
@@ -463,7 +463,7 @@ int main(int argc, char *argv[])
        lib->credmgr->add_set(lib->credmgr, &conftest->creds->set);
 
        logger = file_logger_create("stdout");
-       logger->set_options(logger, NULL, FALSE);
+       logger->set_options(logger, NULL, FALSE, FALSE);
        logger->open(logger, FALSE, FALSE);
        logger->set_level(logger, DBG_ANY, LEVEL_CTRL);
        charon->bus->add_logger(charon->bus, &logger->logger);

diff --git a/src/libcharon/bus/listeners/file_logger.c b/src/libcharon/bus/listeners/file_logger.c
index e3661bd..7a53e93 100644 (file)
--- a/src/libcharon/bus/listeners/file_logger.c
+++ b/src/libcharon/bus/listeners/file_logger.c
@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 2012 Tobias Brunner
+ * Copyright (C) 2012-2015 Tobias Brunner
  * Copyright (C) 2006 Martin Willi
  * Hochschule fuer Technik Rapperswil
  *
@@ -65,6 +65,11 @@ struct private_file_logger_t {
        char *time_format;
 
        /**
+        * Add milliseconds after the time string
+        */
+       bool add_ms;
+
+       /**
         * Print the name/# of the IKE_SA?
         */
        bool ike_name;
@@ -87,7 +92,9 @@ METHOD(logger_t, log_, void,
        char timestr[128], namestr[128] = "";
        const char *current = message, *next;
        struct tm tm;
-       time_t t;
+       timeval_t tv;
+       time_t s;
+       u_int ms = 0;
 
        this->lock->read_lock(this->lock);
        if (!this->out)
@@ -97,8 +104,10 @@ METHOD(logger_t, log_, void,
        }
        if (this->time_format)
        {
-               t = time(NULL);
-               localtime_r(&t, &tm);
+               gettimeofday(&tv, NULL);
+               s = tv.tv_sec;
+               ms = tv.tv_usec / 1000;
+               localtime_r(&s, &tm);
                strftime(timestr, sizeof(timestr), this->time_format, &tm);
        }
        if (this->ike_name && ike_sa)
@@ -126,8 +135,16 @@ METHOD(logger_t, log_, void,
                next = strchr(current, '\n');
                if (this->time_format)
                {
-                       fprintf(this->out, "%s %.2d[%N]%s ",
-                                       timestr, thread, debug_names, group, namestr);
+                       if (this->add_ms)
+                       {
+                               fprintf(this->out, "%s.%03u %.2d[%N]%s ",
+                                               timestr, ms, thread, debug_names, group, namestr);
+                       }
+                       else
+                       {
+                               fprintf(this->out, "%s %.2d[%N]%s ",
+                                               timestr, thread, debug_names, group, namestr);
+                       }
                }
                else
                {
@@ -182,11 +199,12 @@ METHOD(file_logger_t, set_level, void,
 }
 
 METHOD(file_logger_t, set_options, void,
-       private_file_logger_t *this, char *time_format, bool ike_name)
+       private_file_logger_t *this, char *time_format, bool add_ms, bool ike_name)
 {
        this->lock->write_lock(this->lock);
        free(this->time_format);
        this->time_format = strdupnull(time_format);
+       this->add_ms = add_ms;
        this->ike_name = ike_name;
        this->lock->unlock(this->lock);
 }

diff --git a/src/libcharon/bus/listeners/file_logger.h b/src/libcharon/bus/listeners/file_logger.h
index 9e5aed5..1bcfec1 100644 (file)
--- a/src/libcharon/bus/listeners/file_logger.h
+++ b/src/libcharon/bus/listeners/file_logger.h
@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 2012 Tobias Brunner
+ * Copyright (C) 2012-2015 Tobias Brunner
  * Copyright (C) 2006 Martin Willi
  * Hochschule fuer Technik Rapperswil
  *
@@ -48,9 +48,12 @@ struct file_logger_t {
         * Set options used by this logger
         *
         * @param time_format   format of timestamp prefix, as in strftime(), cloned
+        * @param add_ms                TRUE to add the number of milliseconds within the
+        *                                              current second after the timestamp
         * @param ike_name              TRUE to prefix the name of the IKE_SA
         */
-       void (*set_options) (file_logger_t *this, char *time_format, bool ike_name);
+       void (*set_options) (file_logger_t *this, char *time_format, bool add_ms,
+                                                bool ike_name);
 
        /**
         * Open (or reopen) the log file according to the given parameters

diff --git a/src/libcharon/daemon.c b/src/libcharon/daemon.c
index 316be76..f3fe3f8 100644 (file)
--- a/src/libcharon/daemon.c
+++ b/src/libcharon/daemon.c
@@ -324,11 +324,13 @@ static void load_file_logger(private_daemon_t *this, char *filename,
        file_logger_t *file_logger;
        debug_t group;
        level_t def;
-       bool ike_name, flush_line, append;
+       bool add_ms, ike_name, flush_line, append;
        char *time_format;
 
        time_format = lib->settings->get_str(lib->settings,
                                                "%s.filelog.%s.time_format", NULL, lib->ns, filename);
+       add_ms = lib->settings->get_bool(lib->settings,
+                                               "%s.filelog.%s.time_add_ms", FALSE, lib->ns, filename);
        ike_name = lib->settings->get_bool(lib->settings,
                                                "%s.filelog.%s.ike_name", FALSE, lib->ns, filename);
        flush_line = lib->settings->get_bool(lib->settings,
@@ -337,7 +339,7 @@ static void load_file_logger(private_daemon_t *this, char *filename,
                                                "%s.filelog.%s.append", TRUE, lib->ns, filename);
 
        file_logger = add_file_logger(this, filename, current_loggers);
-       file_logger->set_options(file_logger, time_format, ike_name);
+       file_logger->set_options(file_logger, time_format, add_ms, ike_name);
        file_logger->open(file_logger, flush_line, append);
 
        def = lib->settings->get_int(lib->settings, "%s.filelog.%s.default", 1,