Log output updates.

Add a Qt message handler that calls g_log. Add milliseconds to the
g_log_message_handler timestamp.

Change-Id: I5b1c1d902b6b05cd8daa01741b19d6c2048dfb9a
Reviewed-on: https://code.wireshark.org/review/24865
Reviewed-by: Gerald Combs <gerald@wireshark.org>
Petri-Dish: Gerald Combs <gerald@wireshark.org>
Tested-by: Petri Dish Buildbot
Reviewed-by: Michael Mann <mmann78@netscape.net>

5 files changed, 91 insertions, 53 deletions

diff --git a/dumpcap.c b/dumpcap.c
index 19287b9fe7..bebe9195ef 100644
--- a/dumpcap.c
+++ b/dumpcap.c
@@ -94,6 +94,7 @@
 #include "wsutil/os_version_info.h"
 #include "wsutil/str_util.h"
 #include "wsutil/inet_addr.h"
+#include "wsutil/time_util.h"
 
 #include "caputils/ws80211_utils.h"
 
@@ -424,58 +425,6 @@ static void report_cfilter_error(capture_options *capture_opts, guint i, const c
 
 #define MSG_MAX_LENGTH 4096
 
-/* Copied from pcapio.c pcapng_write_interface_statistics_block()*/
-static guint64
-create_timestamp(void) {
-    guint64  timestamp;
-#ifdef _WIN32
-    FILETIME now;
-#else
-    struct timeval now;
-#endif
-
-#ifdef _WIN32
-    /*
-     * Current time, represented as 100-nanosecond intervals since
-     * January 1, 1601, 00:00:00 UTC.
-     *
-     * I think DWORD might be signed, so cast both parts of "now"
-     * to guint32 so that the sign bit doesn't get treated specially.
-     *
-     * Windows 8 provides GetSystemTimePreciseAsFileTime which we
-     * might want to use instead.
-     */
-    GetSystemTimeAsFileTime(&now);
-    timestamp = (((guint64)(guint32)now.dwHighDateTime) << 32) +
-                (guint32)now.dwLowDateTime;
-
-    /*
-     * Convert to same thing but as 1-microsecond, i.e. 1000-nanosecond,
-     * intervals.
-     */
-    timestamp /= 10;
-
-    /*
-     * Subtract difference, in microseconds, between January 1, 1601
-     * 00:00:00 UTC and January 1, 1970, 00:00:00 UTC.
-     */
-    timestamp -= G_GUINT64_CONSTANT(11644473600000000);
-#else
-    /*
-     * Current time, represented as seconds and microseconds since
-     * January 1, 1970, 00:00:00 UTC.
-     */
-    gettimeofday(&now, NULL);
-
-    /*
-     * Convert to delta in microseconds.
-     */
-    timestamp = (guint64)(now.tv_sec) * 1000000 +
-                (guint64)(now.tv_usec);
-#endif
-    return timestamp;
-}
-
 static void
 print_usage(FILE *output)
 {
diff --git a/ui/console.c b/ui/console.c
index a2d156909e..23419119d0 100644
--- a/ui/console.c
+++ b/ui/console.c
@@ -26,6 +26,7 @@
 
 
 #include "epan/prefs.h"
+#include "wsutil/time_util.h"
 
 #include "console.h"
 
@@ -91,9 +92,11 @@ console_log_handler(const char *log_domain, GLogLevelFlags log_level,
         /* create a "timestamp" */
         time(&curr);
         today = localtime(&curr);
+        guint64 microseconds = create_timestamp();
         if (today != NULL) {
-                fprintf(stderr, "%02d:%02d:%02d %8s %s %s\n",
+                fprintf(stderr, "%02d:%02d:%02d.%03" G_GUINT64_FORMAT " %8s %s %s\n",
                         today->tm_hour, today->tm_min, today->tm_sec,
+                        microseconds % 1000000 / 1000,
                         log_domain != NULL ? log_domain : "",
                         level, message);
         } else {
diff --git a/wireshark-qt.cpp b/wireshark-qt.cpp
index 94b20298a6..c65bb75775 100644
--- a/wireshark-qt.cpp
+++ b/wireshark-qt.cpp
@@ -256,6 +256,33 @@ get_wireshark_runtime_info(GString *str)
 #endif
 }
 
+void
+g_log_message_handler(QtMsgType type, const QMessageLogContext &, const QString &msg)
+{
+    GLogLevelFlags log_level = G_LOG_LEVEL_DEBUG;
+
+    switch (type) {
+    case QtDebugMsg:
+    default:
+        break;
+#if (QT_VERSION >= QT_VERSION_CHECK(5, 5, 0))
+    case QtInfoMsg:
+        log_level = G_LOG_LEVEL_INFO;
+        break;
+#endif
+    case QtWarningMsg:
+        log_level = G_LOG_LEVEL_WARNING;
+        break;
+    case QtCriticalMsg:
+        log_level = G_LOG_LEVEL_CRITICAL;
+        break;
+    case QtFatalMsg:
+        log_level = G_LOG_FLAG_FATAL;
+        break;
+    }
+    g_log(LOG_DOMAIN_MAIN, log_level, "%s", qUtf8Printable(msg));
+}
+
 #ifdef HAVE_LIBPCAP
 /*  Check if there's something important to tell the user during startup.
  *  We want to do this *after* showing the main window so that any windows
@@ -582,6 +609,7 @@ int main(int argc, char *qt_argv[])
 #endif
 
     set_console_log_handler();
+    qInstallMessageHandler(g_log_message_handler);
 #ifdef DEBUG_STARTUP_TIME
     g_log(LOG_DOMAIN_MAIN, G_LOG_LEVEL_INFO, "set_console_log_handler, elapsed time %" G_GUINT64_FORMAT " us \n", g_get_monotonic_time() - start_time);
 #endif
diff --git a/wsutil/time_util.c b/wsutil/time_util.c
index b35061478f..03aa37dc76 100644
--- a/wsutil/time_util.c
+++ b/wsutil/time_util.c
@@ -113,6 +113,58 @@ void log_resource_usage(gboolean reset_delta, const char *format, ...) {
 
 }
 
+/* Copied from pcapio.c pcapng_write_interface_statistics_block()*/
+guint64
+create_timestamp(void) {
+    guint64  timestamp;
+#ifdef _WIN32
+    FILETIME now;
+#else
+    struct timeval now;
+#endif
+
+#ifdef _WIN32
+    /*
+     * Current time, represented as 100-nanosecond intervals since
+     * January 1, 1601, 00:00:00 UTC.
+     *
+     * I think DWORD might be signed, so cast both parts of "now"
+     * to guint32 so that the sign bit doesn't get treated specially.
+     *
+     * Windows 8 provides GetSystemTimePreciseAsFileTime which we
+     * might want to use instead.
+     */
+    GetSystemTimeAsFileTime(&now);
+    timestamp = (((guint64)(guint32)now.dwHighDateTime) << 32) +
+                (guint32)now.dwLowDateTime;
+
+    /*
+     * Convert to same thing but as 1-microsecond, i.e. 1000-nanosecond,
+     * intervals.
+     */
+    timestamp /= 10;
+
+    /*
+     * Subtract difference, in microseconds, between January 1, 1601
+     * 00:00:00 UTC and January 1, 1970, 00:00:00 UTC.
+     */
+    timestamp -= G_GUINT64_CONSTANT(11644473600000000);
+#else
+    /*
+     * Current time, represented as seconds and microseconds since
+     * January 1, 1970, 00:00:00 UTC.
+     */
+    gettimeofday(&now, NULL);
+
+    /*
+     * Convert to delta in microseconds.
+     */
+    timestamp = (guint64)(now.tv_sec) * 1000000 +
+                (guint64)(now.tv_usec);
+#endif
+    return timestamp;
+}
+
 /*
  * Editor modelines  -  http://www.wireshark.org/tools/modelines.html
  *
diff --git a/wsutil/time_util.h b/wsutil/time_util.h
index 51a3aa64c3..1775bb62a3 100644
--- a/wsutil/time_util.h
+++ b/wsutil/time_util.h
@@ -45,6 +45,12 @@ void get_resource_usage(double *user_time, double *sys_time);
 WS_DLL_PUBLIC
 void log_resource_usage(gboolean reset_delta, const char *format, ...);
 
+/**
+ * Fetch the number of microseconds since midnight (0 hour), January 1, 1970.
+ */
+WS_DLL_PUBLIC
+guint64 create_timestamp(void);
+
 #ifdef __cplusplus
 }
 #endif /* __cplusplus */