From 1a7529bf5f867b43e0475f7f9ac0cd8671fb16f1 Mon Sep 17 00:00:00 2001 From: Pavel Březina Date: Mon, 29 Aug 2011 10:32:03 +0200 Subject: DEBUG timestamps offer higher precision https://fedorahosted.org/sssd/ticket/956 Added: --debug-microseconds=0/1 Added: debug_microseconds to sssd.conf --- src/util/debug.c | 1 + src/util/server.c | 16 +++++++++++++++ src/util/util.h | 61 +++++++++++++++++++++++++++++++++++++++++++------------ 3 files changed, 65 insertions(+), 13 deletions(-) (limited to 'src/util') diff --git a/src/util/debug.c b/src/util/debug.c index 3a1b7ca2..7816bc41 100644 --- a/src/util/debug.c +++ b/src/util/debug.c @@ -35,6 +35,7 @@ const char *debug_prg_name = "sssd"; int debug_level = SSSDBG_UNRESOLVED; int debug_timestamps = SSSDBG_TIMESTAMP_UNRESOLVED; +int debug_microseconds = SSSDBG_MICROSECONDS_UNRESOLVED; int debug_to_file = 0; const char *debug_log_file = "sssd"; FILE *debug_file = NULL; diff --git a/src/util/server.c b/src/util/server.c index 42fd9360..0c9501b1 100644 --- a/src/util/server.c +++ b/src/util/server.c @@ -382,6 +382,7 @@ int server_setup(const char *name, int flags, int ret = EOK; bool dt; bool dl; + bool dm; struct tevent_signal *tes; struct logrotate_ctx *lctx; @@ -489,6 +490,21 @@ int server_setup(const char *name, int flags, else debug_timestamps = 0; } + /* same for debug microseconds */ + if (debug_microseconds == SSSDBG_MICROSECONDS_UNRESOLVED) { + ret = confdb_get_bool(ctx->confdb_ctx, ctx, conf_entry, + CONFDB_SERVICE_DEBUG_MICROSECONDS, + SSSDBG_MICROSECONDS_DEFAULT, + &dm); + if (ret != EOK) { + DEBUG(0, ("Error reading from confdb (%d) [%s]\n", + ret, strerror(ret))); + return ret; + } + if (dm) debug_microseconds = 1; + else debug_microseconds = 0; + } + /* same for debug to file */ dl = (debug_to_file != 0); ret = confdb_get_bool(ctx->confdb_ctx, ctx, conf_entry, diff --git a/src/util/util.h b/src/util/util.h index c37cab8a..118d70c5 100644 --- a/src/util/util.h +++ b/src/util/util.h @@ -54,6 +54,7 @@ typedef int errno_t; extern const char *debug_prg_name; extern int debug_level; extern int debug_timestamps; +extern int debug_microseconds; extern int debug_to_file; extern const char *debug_log_file; void debug_fn(const char *format, ...); @@ -80,13 +81,18 @@ errno_t set_debug_file_from_fd(const int fd); #define SSSDBG_TIMESTAMP_UNRESOLVED -1 #define SSSDBG_TIMESTAMP_DEFAULT 1 +#define SSSDBG_MICROSECONDS_UNRESOLVED -1 +#define SSSDBG_MICROSECONDS_DEFAULT 0 + #define SSSD_DEBUG_OPTS \ {"debug-level", 'd', POPT_ARG_INT, &debug_level, 0, \ _("Debug level"), NULL}, \ {"debug-to-files", 'f', POPT_ARG_NONE, &debug_to_file, 0, \ _("Send the debug output to files instead of stderr"), NULL }, \ {"debug-timestamps", 0, POPT_ARG_INT, &debug_timestamps, 0, \ - _("Add debug timestamps"), NULL}, + _("Add debug timestamps"), NULL}, \ + {"debug-microseconds", 0, POPT_ARG_INT, &debug_microseconds, 0, \ + _("Show timestamps with microseconds"), NULL}, /** \def DEBUG(level, body) \brief macro to generate debug messages @@ -107,12 +113,26 @@ errno_t set_debug_file_from_fd(const int fd); int __debug_macro_newlevel = debug_get_level(level); \ if (DEBUG_IS_SET(__debug_macro_newlevel)) { \ if (debug_timestamps) { \ - time_t rightnow = time(NULL); \ - char stamp[25]; \ - memcpy(stamp, ctime(&rightnow), 24); \ - stamp[24] = '\0'; \ - debug_fn("(%s) [%s] [%s] (%#.4x): ", \ - stamp, debug_prg_name, __FUNCTION__, __debug_macro_newlevel); \ + struct timeval __debug_macro_tv; \ + struct tm *__debug_macro_tm; \ + char __debug_macro_datetime[20]; \ + int __debug_macro_year; \ + gettimeofday(&__debug_macro_tv, NULL); \ + __debug_macro_tm = localtime(&__debug_macro_tv.tv_sec); \ + __debug_macro_year = __debug_macro_tm->tm_year + 1900; \ + /* get date time without year */ \ + memcpy(__debug_macro_datetime, ctime(&__debug_macro_tv.tv_sec), 19); \ + __debug_macro_datetime[19] = '\0'; \ + if (debug_microseconds) { \ + debug_fn("(%s:%.6d %d) [%s] [%s] (%#.4x): ", \ + __debug_macro_datetime, __debug_macro_tv.tv_usec, \ + __debug_macro_year, debug_prg_name, \ + __FUNCTION__, __debug_macro_newlevel); \ + } else { \ + debug_fn("(%s %d) [%s] [%s] (%#.4x): ", \ + __debug_macro_datetime, __debug_macro_year, \ + debug_prg_name, __FUNCTION__, __debug_macro_newlevel); \ + } \ } else { \ debug_fn("[%s] [%s] (%#.4x): ", \ debug_prg_name, __FUNCTION__, __debug_macro_newlevel); \ @@ -134,12 +154,27 @@ errno_t set_debug_file_from_fd(const int fd); int __debug_macro_newlevel = debug_get_level(level); \ if (DEBUG_IS_SET(__debug_macro_newlevel)) { \ if (debug_timestamps) { \ - time_t rightnow = time(NULL); \ - char stamp[25]; \ - memcpy(stamp, ctime(&rightnow), 24); \ - stamp[24] = '\0'; \ - debug_fn("(%s) [%s] [%s] (%#.4x): %s\n", \ - stamp, debug_prg_name, function, __debug_macro_newlevel, message); \ + struct timeval __debug_macro_tv; \ + struct tm *__debug_macro_tm; \ + char __debug_macro_datetime[20]; \ + int __debug_macro_year; \ + gettimeofday(&__debug_macro_tv, NULL); \ + __debug_macro_tm = localtime(&__debug_macro_tv.tv_sec); \ + __debug_macro_year = __debug_macro_tm->tm_year + 1900; \ + /* get date time without year */ \ + memcpy(__debug_macro_datetime, ctime(&__debug_macro_tv.tv_sec), 19); \ + __debug_macro_datetime[19] = '\0'; \ + if (debug_microseconds) { \ + debug_fn("(%s:%.6d %d) [%s] [%s] (%#.4x): %s\n", \ + __debug_macro_datetime, __debug_macro_tv.tv_usec, \ + __debug_macro_year, debug_prg_name, \ + function, __debug_macro_newlevel, message); \ + } else { \ + debug_fn("(%s %d) [%s] [%s] (%#.4x): %s\n", \ + __debug_macro_datetime, __debug_macro_year, \ + debug_prg_name, function, __debug_macro_newlevel, \ + message); \ + } \ } else { \ debug_fn("[%s] [%s] (%#.4x): %s\n", \ debug_prg_name, function, __debug_macro_newlevel, message); \ -- cgit