Implement --log-timing for server and audiod.
authorAndre Noll <maan@systemlinux.org>
Sat, 19 Dec 2009 11:54:08 +0000 (12:54 +0100)
committerAndre Noll <maan@systemlinux.org>
Sat, 19 Dec 2009 11:54:08 +0000 (12:54 +0100)
This adds another option to include milliseconds in the output of each log message.

audiod.c
daemon.c
daemon.h
ggo/audiod.m4
ggo/log_timing.m4 [new file with mode: 0644]
ggo/makefile
ggo/server.m4
server.c

index e0a455d..395a14d 100644 (file)
--- a/audiod.c
+++ b/audiod.c
@@ -1207,6 +1207,8 @@ int main(int argc, char *argv[])
        daemon_set_flag(DF_LOG_TIME);
        daemon_set_flag(DF_LOG_HOSTNAME);
        daemon_set_flag(DF_LOG_LL);
+       if (conf.log_timing_given)
+               daemon_set_flag(DF_LOG_TIMING);
        if (conf.logfile_given) {
                daemon_set_logfile(conf.logfile_arg);
                daemon_open_log_or_die();
index c855daa..a669482 100644 (file)
--- a/daemon.c
+++ b/daemon.c
@@ -10,6 +10,8 @@
 #include <pwd.h>
 #include <sys/types.h> /* getgrnam() */
 #include <grp.h>
+#include <sys/time.h>
+#include <stdbool.h>
 
 #include "para.h"
 #include "daemon.h"
@@ -141,7 +143,7 @@ void daemon_clear_flag(unsigned flag)
        me->flags &= ~flag;
 }
 
-static unsigned daemon_test_flag(unsigned flag)
+static bool daemon_test_flag(unsigned flag)
 {
        return me->flags & flag;
 }
@@ -332,8 +334,9 @@ __printf_2_3 void para_log(int ll, const char* fmt,...)
        va_list argp;
        FILE *fp;
        struct tm *tm;
-       time_t t1;
        char *color;
+       bool log_time = daemon_test_flag(DF_LOG_TIME), log_timing =
+               daemon_test_flag(DF_LOG_TIMING);
 
        ll = PARA_MIN(ll, NUM_LOGLEVELS - 1);
        ll = PARA_MAX(ll, LL_DEBUG);
@@ -344,12 +347,18 @@ __printf_2_3 void para_log(int ll, const char* fmt,...)
        color = daemon_test_flag(DF_COLOR_LOG)? me->log_colors[ll] : NULL;
        if (color)
                fprintf(fp, "%s", color);
-       if (daemon_test_flag(DF_LOG_TIME)) { /* print date and time */
-               char str[100];
-               time(&t1);
-               tm = localtime(&t1);
-               strftime(str, sizeof(str), "%b %d %H:%M:%S", tm);
-               fprintf(fp, "%s ", str);
+       if (log_time || log_timing) {
+               struct timeval tv;
+               gettimeofday(&tv, NULL);
+               if (daemon_test_flag(DF_LOG_TIME)) { /* print date and time */
+                       time_t t1 = tv.tv_sec;
+                       char str[100];
+                       tm = localtime(&t1);
+                       strftime(str, sizeof(str), "%b %d %H:%M:%S", tm);
+                       fprintf(fp, "%s%s", str, log_timing? ":" : " ");
+               }
+               if (log_timing) /* print milliseconds */
+                       fprintf(fp, "%04lu ", (long unsigned)tv.tv_usec / 1000);
        }
        if (daemon_test_flag(DF_LOG_HOSTNAME)) {
                if (!me->hostname)
index c8dd997..3705b9d 100644 (file)
--- a/daemon.h
+++ b/daemon.h
@@ -29,4 +29,6 @@ enum daemon_flags {
        DF_LOG_LL = 8,
        /** Use colored output. */
        DF_COLOR_LOG = 16,
+       /** Include milliseconds in log output. */
+       DF_LOG_TIMING = 32
 };
index 29bce10..7ff8806 100644 (file)
@@ -12,6 +12,7 @@ include(loglevel.m4)
 include(color.m4)
 include(config_file.m4)
 include(logfile.m4)
+include(log_timing.m4)
 include(daemon.m4)
 include(user.m4)
 include(group.m4)
diff --git a/ggo/log_timing.m4 b/ggo/log_timing.m4
new file mode 100644 (file)
index 0000000..ac0ea84
--- /dev/null
@@ -0,0 +1,12 @@
+<qu>
+option "log-timing" T
+#~~~~~~~~~~~~~~~~~~~~
+"show milliseconds in log messages"
+flag off
+details = "
+       Selecting this option causes milliseconds to be included in
+       the log message output. This allows to measure the interval
+       between log messages in milliseconds which is useful for
+       identifying timing problems.
+"
+</qu>
index d7bfc4f..d4f3a8c 100644 (file)
@@ -50,7 +50,7 @@ $(ggo_dir)/server.ggo $(ggo_dir)/audiod.ggo: \
        $(ggo_dir)/loglevel.m4 $(ggo_dir)/color.m4 \
        $(ggo_dir)/config_file.m4 $(ggo_dir)/logfile.m4 \
        $(ggo_dir)/daemon.m4 $(ggo_dir)/user.m4 \
-       $(ggo_dir)/group.m4
+       $(ggo_dir)/group.m4 $(ggo_dir)/log_timing.m4
 
 $(ggo_dir)/afh.ggo: $(ggo_dir)/loglevel.m4
 $(ggo_dir)/audioc.ggo: $(ggo_dir)/loglevel.m4
index df94357..4be4e2c 100644 (file)
@@ -9,6 +9,7 @@ section "General options"
 </qu>
 
 include(loglevel.m4)
+include(log_timing.m4)
 include(color.m4)
 include(daemon.m4)
 include(user.m4)
index f7aad89..d9cd1fd 100644 (file)
--- a/server.c
+++ b/server.c
@@ -243,6 +243,8 @@ void parse_config_or_die(int override)
        daemon_set_flag(DF_LOG_PID);
        daemon_set_flag(DF_LOG_LL);
        daemon_set_flag(DF_LOG_TIME);
+       if (conf.log_timing_given)
+               daemon_set_flag(DF_LOG_TIMING);
        ret = 1;
 out:
        free(cf);