From 0987a536b1385da2c675f15a91e2fb8af04cd1ad Mon Sep 17 00:00:00 2001
From: Kovid Goyal <kovid@kovidgoyal.net>
Date: Wed, 24 Apr 2019 16:16:40 +0530
Subject: [PATCH] Add extra logging to debug the event loop

This should make tracking down the root cause of the
event loop pauses on X11 easier. And the infrastructure
should come in handy in the future as well.
---
 Makefile          |  3 +++
 glfw/init.c       | 14 ++++++++++++++
 glfw/internal.h   | 10 +++++++++-
 glfw/main_loop.h  |  1 +
 glfw/x11_window.c |  8 +++++++-
 setup.py          | 14 ++++++++++++--
 6 files changed, 46 insertions(+), 4 deletions(-)

diff --git a/Makefile b/Makefile
index 0b724b394..4c402815b 100644
--- a/Makefile
+++ b/Makefile
@@ -18,6 +18,9 @@ clean:
 debug:
 	python3 setup.py build $(VVAL) --debug
 
+debug-event-loop:
+	python3 setup.py build $(VVAL) --debug --extra-logging=event-loop
+
 # Build with the ASAN and UBSAN sanitizers
 asan:
 	python3 setup.py build $(VVAL) --debug --sanitize
diff --git a/glfw/init.c b/glfw/init.c
index 436d87c31..155c345ef 100644
--- a/glfw/init.c
+++ b/glfw/init.c
@@ -193,6 +193,20 @@ void _glfwInputError(int code, const char* format, ...)
         _glfwErrorCallback(code, description);
 }
 
+void
+_glfwDebug(const char *format, ...) {
+    if (format)
+    {
+        va_list vl;
+
+        fprintf(stderr, "[%.4f] ", glfwGetTime());
+        va_start(vl, format);
+        vfprintf(stderr, format, vl);
+        va_end(vl);
+        fprintf(stderr, "\n");
+    }
+
+}
 
 //////////////////////////////////////////////////////////////////////////
 //////                        GLFW public API                       //////
diff --git a/glfw/internal.h b/glfw/internal.h
index cd97dd91e..5d58acc69 100644
--- a/glfw/internal.h
+++ b/glfw/internal.h
@@ -743,13 +743,21 @@ void _glfwInputJoystickHat(_GLFWjoystick* js, int hat, char value);
 void _glfwInputMonitor(_GLFWmonitor* monitor, int action, int placement);
 void _glfwInputMonitorWindow(_GLFWmonitor* monitor, _GLFWwindow* window);
 
-#if defined(__GNUC__)
+#if defined(__GNUC__) || defined(__clang__)
 void _glfwInputError(int code, const char* format, ...)
     __attribute__((format(printf, 2, 3)));
+void _glfwDebug(const char* format, ...)
+    __attribute__((format(printf, 1, 2)));
 #else
 void _glfwInputError(int code, const char* format, ...);
+void _glfwDebug(const char* format, ...);
 #endif
 
+#ifdef DEBUG_EVENT_LOOP
+#define EVDBG(...) _glfwDebug(__VA_ARGS__)
+#else
+#define EVDBG(...)
+#endif
 
 //////////////////////////////////////////////////////////////////////////
 //////                       GLFW internal API                      //////
diff --git a/glfw/main_loop.h b/glfw/main_loop.h
index 56b337978..74bdae368 100644
--- a/glfw/main_loop.h
+++ b/glfw/main_loop.h
@@ -29,6 +29,7 @@ void _glfwPlatformRunMainLoop(GLFWtickcallback callback, void* data) {
     keep_going = GLFW_TRUE;
     tick_callback_requested = GLFW_FALSE;
     while(keep_going) {
+		EVDBG("tick_callback_requested: %d", tick_callback_requested);
         while (tick_callback_requested) {
             tick_callback_requested = GLFW_FALSE;
             callback(data);
diff --git a/glfw/x11_window.c b/glfw/x11_window.c
index 615d5145f..459626847 100644
--- a/glfw/x11_window.c
+++ b/glfw/x11_window.c
@@ -59,10 +59,16 @@ GLFWbool _glfwDispatchX11Events(void);
 
 static void
 handleEvents(double timeout) {
+    EVDBG("starting handleEvents(%.2f)", timeout);
     int display_read_ok = pollForEvents(&_glfw.x11.eventLoopData, timeout);
-    if (display_read_ok) _glfwDispatchX11Events();
+    EVDBG("display_read_ok: %d", display_read_ok);
+    if (display_read_ok) {
+        _glfwDispatchX11Events();
+        EVDBG("_glfwDispatchX11Events() done");
+    }
     glfw_ibus_dispatch(&_glfw.x11.xkb.ibus);
     glfw_dbus_session_bus_dispatch();
+    EVDBG("other dispatch done");
 }
 
 static GLFWbool
diff --git a/setup.py b/setup.py
index 9f9716124..e00432874 100755
--- a/setup.py
+++ b/setup.py
@@ -178,7 +178,8 @@ class Env:
 
 
 def init_env(
-    debug=False, sanitize=False, native_optimizations=True, profile=False
+    debug=False, sanitize=False, native_optimizations=True, profile=False,
+    extra_logging=()
 ):
     native_optimizations = native_optimizations and not sanitize and not debug
     cc, ccver = cc_version()
@@ -200,6 +201,8 @@ def init_env(
         )
     )
     cppflags = shlex.split(cppflags)
+    for el in extra_logging:
+        cppflags.append('-DDEBUG_{}'.format(el.upper().replace('-', '_')))
     cflags = os.environ.get(
         'OVERRIDE_CFLAGS', (
             '-Wextra -Wno-missing-field-initializers -Wall -std=c11'
@@ -508,7 +511,7 @@ def build(args, native_optimizations=True):
     compilation_database = {
         (k['file'], k.get('output')): k['arguments'] for k in compilation_database
     }
-    env = init_env(args.debug, args.sanitize, native_optimizations, args.profile)
+    env = init_env(args.debug, args.sanitize, native_optimizations, args.profile, args.extra_logging)
     try:
         compile_c_extension(
             kitty_env(), 'kitty/fast_data_types', args.incremental, compilation_database, all_keys, *find_c_files()
@@ -842,6 +845,13 @@ def option_parser():  # {{{
         default='lib',
         help='The name of the directory inside --prefix in which to store compiled files. Defaults to "lib"'
     )
+    p.add_argument(
+        '--extra-logging',
+        action='append',
+        choices=('event-loop',),
+        help='Turn on extra logging for debugging in this build. Can be specified multiple times, to turn'
+        'on different types of logging.'
+    )
     return p
 # }}}