From 9c01d6ca6752e9ad93e570c00754dae72d75028a Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Tue, 29 Oct 2019 16:50:08 +0100 Subject: [PATCH] libnm: print timestamp in LIBNM_CLIENT_DEBUG debug logging It's useful, because it's easy to get overwhelemed by the logging output. The timestamp makes it easier to keep track. Also, it allows to see how long things take. --- libnm/nm-libnm-utils.c | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/libnm/nm-libnm-utils.c b/libnm/nm-libnm-utils.c index 7d34d2fd41..3d7b0ba6df 100644 --- a/libnm/nm-libnm-utils.c +++ b/libnm/nm-libnm-utils.c @@ -8,6 +8,8 @@ #include "nm-libnm-utils.h" +#include "nm-glib-aux/nm-time-utils.h" + /*****************************************************************************/ volatile int _nml_dbus_log_level = 0; @@ -43,6 +45,7 @@ _nml_dbus_log (NMLDBusLogLevel level, gs_free char *msg = NULL; va_list args; const char *prefix = ""; + gint64 ts; /* we only call _nml_dbus_log() after nml_dbus_log_enabled(), which already does * an atomic access to the variable. Since the value is only initialized once and @@ -84,7 +87,13 @@ _nml_dbus_log (NMLDBusLogLevel level, break; } - g_printerr ("libnm-dbus: %s%s\n", prefix, msg); + ts = nm_utils_clock_gettime_ns (CLOCK_BOOTTIME); + + g_printerr ("libnm-dbus: %s[%"G_GINT64_FORMAT".%05"G_GINT64_FORMAT"] %s\n", + prefix, + ts / NM_UTILS_NS_PER_SECOND, + (ts / (NM_UTILS_NS_PER_SECOND / 10000)) % 10000, + msg); } /*****************************************************************************/