core: add debug functions to measure time spent in code/functions

src/core/wee-debug.c

@@ -29,6 +29,7 @@
 #endif
 #include <string.h>
 #include <time.h>
+#include <sys/time.h>
 #include <gcrypt.h>
 #include <curl/curl.h>
 #include <zlib.h>
@@ -48,6 +49,7 @@
 #include "wee-log.h"
 #include "wee-proxy.h"
 #include "wee-string.h"
+#include "wee-util.h"
 #include "../gui/gui-bar.h"
 #include "../gui/gui-bar-item.h"
 #include "../gui/gui-buffer.h"
@@ -63,6 +65,9 @@
 
 int debug_dump_active = 0;
 
+char *debug_time_name = NULL;
+struct timeval debug_timeval_start = { 0, 0 };
+
 
 /*
  * Writes dump of data to WeeChat log file.
@@ -578,7 +583,62 @@ debug_directories ()
 }
 
 /*
- * Hooks signals for debug.
+ * Starts time measure.
+ */
+
+void
+debug_time_start (const char *name)
+{
+    if (debug_time_name)
+    {
+        free (debug_time_name);
+        debug_time_name = NULL;
+    }
+    if (name)
+        debug_time_name = strdup (name);
+
+    gettimeofday (&debug_timeval_start, NULL);
+}
+
+/*
+ * Ends time measure and display elapsed time.
+ *
+ * If display is 1, the message is displayed in core buffer, otherwise it's
+ * written in log file.
+ */
+
+void
+debug_time_end (int display)
+{
+    struct timeval debug_timeval_end;
+    long long diff, diff_hour, diff_min, diff_sec, diff_usec;
+
+    gettimeofday (&debug_timeval_end, NULL);
+    diff = util_timeval_diff (&debug_timeval_start,
+                              &debug_timeval_end);
+
+    diff_usec = diff % 1000000;
+    diff_sec = (diff / 1000000) % 60;
+    diff_min = ((diff / 1000000) / 60) % 60;
+    diff_hour = (diff / 1000000) / 3600;
+
+    if (display)
+    {
+        gui_chat_printf (NULL,
+                         "debug: time[%s] -> %lld:%02lld:%02lld.%06d",
+                         (debug_time_name) ? debug_time_name : "?",
+                         diff_hour, diff_min, diff_sec, diff_usec);
+    }
+    else
+    {
+        log_printf ("debug: time[%s] -> %lld:%02lld:%02lld.%06d",
+                    (debug_time_name) ? debug_time_name : "?",
+                    diff_hour, diff_min, diff_sec, diff_usec);
+    }
+}
+
+/*
+ * Initializes debug.
  */
 
 void
@@ -592,3 +652,17 @@ debug_init ()
     hook_signal (NULL, "2000|debug_dump", &debug_dump_cb, NULL);
     hook_signal (NULL, "2000|debug_libs", &debug_libs_cb, NULL);
 }
+
+/*
+ * Ends debug.
+ */
+
+void
+debug_end ()
+{
+    if (debug_time_name)
+    {
+        free (debug_time_name);
+        debug_time_name = NULL;
+    }
+}

src/core/wee-debug.h

@@ -29,6 +29,9 @@ extern void debug_hdata ();
 extern void debug_hooks ();
 extern void debug_infolists ();
 extern void debug_directories ();
+extern void debug_time_start (const char *name);
+extern void debug_time_end (int display);
 extern void debug_init ();
+extern void debug_end ();
 
 #endif /* WEECHAT_DEBUG_H */

src/core/weechat.c

@@ -483,6 +483,8 @@ weechat_shutdown (int return_code, int crash)
 
     network_end ();
 
+    debug_end ();
+
     if (crash)
         abort();
     else if (return_code >= 0)