[logging] Use timestamps relative to usb-moded start for stderr logging

Use of wall clock timestamps with microsecond accuracy makes it difficult to see where usb-moded is spending time during startup. Use timestamps that use millisecond accuracy and are relative to usb-moded startup time. Signed-off-by: Simo Piiroinen <simo.piiroinen@jollamobile.com>
sailfishos · Nov 7, 2016 · 5579463 · 5579463
1 parent bae8743
commit 5579463
Show file tree

Hide file tree

Showing 3 changed files with 25 additions and 3 deletions.
diff --git a/src/usb_moded-log.c b/src/usb_moded-log.c
@@ -2,9 +2,12 @@
   @file usb_moded-log.c
 
   Copyright (C) 2010 Nokia Corporation. All rights reserved.
+  Copyright (C) 2016 Jolla Ltd.
 
   @author: Philippe De Swert <philippe.de-swert@nokia.com>
   @author: Simo Piiroinen <simo.piiroinen@nokia.com>
+  @author: Simo Piiroinen <simo.piiroinen@jollamobile.com>
+
 
   This program is free software; you can redistribute it and/or
   modify it under the terms of the Lesser GNU General Public License 
@@ -53,6 +56,14 @@ static char *strip(char *str)
   return str;
 }
 
+static struct timeval log_begtime = { 0, 0 };
+
+static void log_gettime(struct timeval *tv)
+{
+	gettimeofday(tv, 0);
+	timersub(tv, &log_begtime, tv);
+}
+
 /**
  * Print the logged messages to the selected output
  *
@@ -79,10 +90,10 @@ void log_emit_va(int lev, const char *fmt, va_list va)
 #if LOG_ENABLE_TIMESTAMPS
                         {
                                 struct timeval tv;
-                                gettimeofday(&tv, 0);
-                                fprintf(stderr, "%ld.%06ld ",
+				log_gettime(&tv);
+                                fprintf(stderr, "%3ld.%03ld ",
                                         (long)tv.tv_sec,
-                                        (long)tv.tv_usec);
+                                        (long)tv.tv_usec/1000);
                         }
 #endif
 
@@ -156,3 +167,10 @@ inline void log_set_level(int lev)
         log_level = lev;
 }
 
+/** Initialize logging */
+void log_init(void)
+{
+	/* Get reference time used for verbose logging */
+	if( !timerisset(&log_begtime) )
+		gettimeofday(&log_begtime, 0);
+}
diff --git a/src/usb_moded-log.h b/src/usb_moded-log.h
@@ -1,7 +1,9 @@
 /*
   Copyright (C) 2010 Nokia Corporation. All rights reserved.
+  Copyright (C) 2016 Jolla Ltd.
 
   Author: Philippe De Swert <philippe.de-swert@nokia.com>
+  Author: Simo Piiroinen <simo.piiroinen@jollamobile.com>
 
   This program is free software; you can redistribute it and/or
   modify it under the terms of the Lesser GNU General Public License 
@@ -44,6 +46,7 @@ enum
 void log_set_level(int lev); 
 int log_get_level(void);
 
+void log_init(void);
 void log_emit_va(int lev, const char *fmt, va_list va);
 void log_emit(int lev, const char *fmt, ...) __attribute__((format(printf,2,3)));
 void log_debugf(const char *fmt, ...) __attribute__((format(printf,1,2)));

diff --git a/src/usb_moded.c b/src/usb_moded.c
@@ -1103,6 +1103,7 @@ int main(int argc, char* argv[])
                 { 0, 0, 0, 0 }
         };
 
+	log_init();
 	log_name = basename(*argv);
 
 	 /* Parse the command-line options */