From 4c2b2a8a9db9e45f4555a6dc9f57f2fb3a998a6c Mon Sep 17 00:00:00 2001 From: Andre Noll Date: Sat, 19 Dec 2009 12:54:08 +0100 Subject: [PATCH] Implement --log-timing for server and audiod. This adds another option to include milliseconds in the output of each log message. --- audiod.c | 2 ++ daemon.c | 25 +++++++++++++++++-------- daemon.h | 2 ++ ggo/audiod.m4 | 1 + ggo/log_timing.m4 | 12 ++++++++++++ ggo/makefile | 2 +- ggo/server.m4 | 1 + server.c | 2 ++ 8 files changed, 38 insertions(+), 9 deletions(-) create mode 100644 ggo/log_timing.m4 diff --git a/audiod.c b/audiod.c index e0a455d2..395a14d3 100644 --- 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(); diff --git a/daemon.c b/daemon.c index c855daa1..a669482f 100644 --- a/daemon.c +++ b/daemon.c @@ -10,6 +10,8 @@ #include #include /* getgrnam() */ #include +#include +#include #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) diff --git a/daemon.h b/daemon.h index c8dd997f..3705b9da 100644 --- 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 }; diff --git a/ggo/audiod.m4 b/ggo/audiod.m4 index 29bce100..7ff8806c 100644 --- a/ggo/audiod.m4 +++ b/ggo/audiod.m4 @@ -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 index 00000000..ac0ea841 --- /dev/null +++ b/ggo/log_timing.m4 @@ -0,0 +1,12 @@ + +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. +" + diff --git a/ggo/makefile b/ggo/makefile index d7bfc4fb..d4f3a8cd 100644 --- a/ggo/makefile +++ b/ggo/makefile @@ -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 diff --git a/ggo/server.m4 b/ggo/server.m4 index df943575..4be4e2c9 100644 --- a/ggo/server.m4 +++ b/ggo/server.m4 @@ -9,6 +9,7 @@ section "General options" include(loglevel.m4) +include(log_timing.m4) include(color.m4) include(daemon.m4) include(user.m4) diff --git a/server.c b/server.c index f7aad898..d9cd1fd4 100644 --- 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); -- 2.39.5