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.
This commit is contained in:
Kovid Goyal 2019-04-24 16:16:40 +05:30
parent 099510f4d1
commit 0987a536b1
No known key found for this signature in database
GPG Key ID: 06BC317B515ACE7C
6 changed files with 46 additions and 4 deletions

View File

@ -18,6 +18,9 @@ clean:
debug: debug:
python3 setup.py build $(VVAL) --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 # Build with the ASAN and UBSAN sanitizers
asan: asan:
python3 setup.py build $(VVAL) --debug --sanitize python3 setup.py build $(VVAL) --debug --sanitize

14
glfw/init.c vendored
View File

@ -193,6 +193,20 @@ void _glfwInputError(int code, const char* format, ...)
_glfwErrorCallback(code, description); _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 ////// ////// GLFW public API //////

10
glfw/internal.h vendored
View File

@ -743,13 +743,21 @@ void _glfwInputJoystickHat(_GLFWjoystick* js, int hat, char value);
void _glfwInputMonitor(_GLFWmonitor* monitor, int action, int placement); void _glfwInputMonitor(_GLFWmonitor* monitor, int action, int placement);
void _glfwInputMonitorWindow(_GLFWmonitor* monitor, _GLFWwindow* window); void _glfwInputMonitorWindow(_GLFWmonitor* monitor, _GLFWwindow* window);
#if defined(__GNUC__) #if defined(__GNUC__) || defined(__clang__)
void _glfwInputError(int code, const char* format, ...) void _glfwInputError(int code, const char* format, ...)
__attribute__((format(printf, 2, 3))); __attribute__((format(printf, 2, 3)));
void _glfwDebug(const char* format, ...)
__attribute__((format(printf, 1, 2)));
#else #else
void _glfwInputError(int code, const char* format, ...); void _glfwInputError(int code, const char* format, ...);
void _glfwDebug(const char* format, ...);
#endif #endif
#ifdef DEBUG_EVENT_LOOP
#define EVDBG(...) _glfwDebug(__VA_ARGS__)
#else
#define EVDBG(...)
#endif
////////////////////////////////////////////////////////////////////////// //////////////////////////////////////////////////////////////////////////
////// GLFW internal API ////// ////// GLFW internal API //////

1
glfw/main_loop.h vendored
View File

@ -29,6 +29,7 @@ void _glfwPlatformRunMainLoop(GLFWtickcallback callback, void* data) {
keep_going = GLFW_TRUE; keep_going = GLFW_TRUE;
tick_callback_requested = GLFW_FALSE; tick_callback_requested = GLFW_FALSE;
while(keep_going) { while(keep_going) {
EVDBG("tick_callback_requested: %d", tick_callback_requested);
while (tick_callback_requested) { while (tick_callback_requested) {
tick_callback_requested = GLFW_FALSE; tick_callback_requested = GLFW_FALSE;
callback(data); callback(data);

8
glfw/x11_window.c vendored
View File

@ -59,10 +59,16 @@ GLFWbool _glfwDispatchX11Events(void);
static void static void
handleEvents(double timeout) { handleEvents(double timeout) {
EVDBG("starting handleEvents(%.2f)", timeout);
int display_read_ok = pollForEvents(&_glfw.x11.eventLoopData, 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_ibus_dispatch(&_glfw.x11.xkb.ibus);
glfw_dbus_session_bus_dispatch(); glfw_dbus_session_bus_dispatch();
EVDBG("other dispatch done");
} }
static GLFWbool static GLFWbool

View File

@ -178,7 +178,8 @@ class Env:
def init_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 native_optimizations = native_optimizations and not sanitize and not debug
cc, ccver = cc_version() cc, ccver = cc_version()
@ -200,6 +201,8 @@ def init_env(
) )
) )
cppflags = shlex.split(cppflags) cppflags = shlex.split(cppflags)
for el in extra_logging:
cppflags.append('-DDEBUG_{}'.format(el.upper().replace('-', '_')))
cflags = os.environ.get( cflags = os.environ.get(
'OVERRIDE_CFLAGS', ( 'OVERRIDE_CFLAGS', (
'-Wextra -Wno-missing-field-initializers -Wall -std=c11' '-Wextra -Wno-missing-field-initializers -Wall -std=c11'
@ -508,7 +511,7 @@ def build(args, native_optimizations=True):
compilation_database = { compilation_database = {
(k['file'], k.get('output')): k['arguments'] for k in 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: try:
compile_c_extension( compile_c_extension(
kitty_env(), 'kitty/fast_data_types', args.incremental, compilation_database, all_keys, *find_c_files() kitty_env(), 'kitty/fast_data_types', args.incremental, compilation_database, all_keys, *find_c_files()
@ -842,6 +845,13 @@ def option_parser(): # {{{
default='lib', default='lib',
help='The name of the directory inside --prefix in which to store compiled files. Defaults to "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 return p
# }}} # }}}