[Libusbx-devel] [PATCH 2/2] Logging: Only display timestamps in debug mode and use libusb_init as origin

[Pete Batard]

This one does a few things:

1. It sets the origin of the timestamps to the first libusb_init() call 
issued by the application. The idea is to avoid getting an arbitrary 
origin once we have toggleable logging, as it is currently set to the 
first debug message ever issued, which isn't something an app developer 
can reference against as it could occur wherever.

2. It only displays the timestamp and thread ID if the global logging 
level has been set to debug. The rationale behind that is that, outside 
of debug, logging messages are expected to be sparse and likely to only 
occur for errors and warnings. As such, timestamping and thread ID are 
probably be irrelevant for the app developer, even more so if they only 
get one error/warning during the course of the app.

Regards,

/Pete



>From bbd7c0b2b1b15348133e05eeec617d3020aac715 Mon Sep 17 00:00:00 2001
From: Pete Batard <p...@akeo.ie>
Date: Thu, 24 May 2012 16:18:58 +0100
Subject: [PATCH 2/2] Core: Only display timestamps in debug mode and use
 init() as origin

---
 libusb/core.c         |   33 +++++++++++++++++++++++----------
 1 file changed, 24 insertions(+), 11 deletions(-)

diff --git a/libusb/core.c b/libusb/core.c
index e6f2f82..415f46d 100644
--- a/libusb/core.c
+++ b/libusb/core.c
@@ -51,6 +51,7 @@ const struct libusb_version libusb_version_internal =
          LIBUSB_RC, "unused - please use the nano" };
 static int default_context_refcnt = 0;
 static usbi_mutex_static_t default_context_lock = USBI_MUTEX_INITIALIZER;
+static struct timeval timestamp_origin = { 0, 0 };
 
 /**
  * \mainpage libusbx-1.0 API Reference
@@ -1614,6 +1615,11 @@ int API_EXPORTED libusb_init(libusb_context **context)
        int r = 0;
 
        usbi_mutex_static_lock(&default_context_lock);
+
+       if (!timestamp_origin.tv_sec) {
+               usbi_gettimeofday(&timestamp_origin, NULL);
+       }
+
        if (!context && usbi_default_context) {
                usbi_dbg("reusing default context");
                default_context_refcnt++;
@@ -1781,10 +1787,14 @@ void usbi_log_v(struct libusb_context *ctx, enum 
usbi_log_level level,
        FILE *stream = stdout;
        const char *prefix;
        struct timeval now;
-       static struct timeval first = { 0, 0 };
+       int global_debug;
+       static int has_debug_header_been_displayed = 0;
 
-#ifndef ENABLE_DEBUG_LOGGING
+#ifdef ENABLE_DEBUG_LOGGING
+       global_debug = 1;
+#else
        USBI_GET_CONTEXT(ctx);
+       global_debug = (ctx->debug == LOG_LEVEL_DEBUG);
        if (!ctx->debug)
                return;
        if (level == LOG_LEVEL_WARNING && ctx->debug < LOG_LEVEL_WARNING)
@@ -1794,18 +1804,17 @@ void usbi_log_v(struct libusb_context *ctx, enum 
usbi_log_level level,
 #endif
 
        usbi_gettimeofday(&now, NULL);
-       if (!first.tv_sec) {
-               first.tv_sec = now.tv_sec;
-               first.tv_usec = now.tv_usec;
+       if ((global_debug) && (!has_debug_header_been_displayed)) {
+               has_debug_header_been_displayed = 1;
                fprintf(stream, "[timestamp] [threadID] facility level 
[function call] <message>\n");
                fprintf(stream, 
"--------------------------------------------------------------------------------\n");
        }
-       if (now.tv_usec < first.tv_usec) {
+       if (now.tv_usec < timestamp_origin.tv_usec) {
                now.tv_sec--;
                now.tv_usec += 1000000;
        }
-       now.tv_sec -= first.tv_sec;
-       now.tv_usec -= first.tv_usec;
+       now.tv_sec -= timestamp_origin.tv_sec;
+       now.tv_usec -= timestamp_origin.tv_usec;
 
        switch (level) {
        case LOG_LEVEL_INFO:
@@ -1829,8 +1838,12 @@ void usbi_log_v(struct libusb_context *ctx, enum 
usbi_log_level level,
                break;
        }
 
-       fprintf(stream, "[%2d.%06d] [%08x] libusbx: %s [%s] ",
-               (int)now.tv_sec, (int)now.tv_usec, usbi_get_tid(), prefix, 
function);
+       if (global_debug) {
+               fprintf(stream, "[%2d.%06d] [%08x] libusbx: %s [%s]",
+                       (int)now.tv_sec, (int)now.tv_usec, usbi_get_tid(), 
prefix, function);
+       } else {
+               fprintf(stream, "libusbx: %s [%s] ", prefix, function);
+       }
 
        vfprintf(stream, format, args);
 
-- 
1.7.10.msysgit.1

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/_______________________________________________
libusbx-devel mailing list
libusbx-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/libusbx-devel