From 8fc96c5bd7ea2b46128654879fc41b1875ba2f33 Mon Sep 17 00:00:00 2001 From: Kovid Goyal Date: Mon, 8 Apr 2024 12:53:55 +0530 Subject: [PATCH] Make the debug logging functions consistent They now all output the same format of: [time since program start] msg --- glfw/cocoa_window.m | 2 +- glfw/ibus_glfw.c | 3 +-- glfw/internal.h | 2 ++ glfw/wl_client_side_decorations.c | 1 + glfw/wl_init.c | 1 + glfw/wl_platform.h | 1 - glfw/wl_text_input.c | 3 +-- glfw/wl_window.c | 5 +++-- glfw/xkb_glfw.c | 5 ++--- kitty/boss.py | 3 ++- kitty/child-monitor.c | 2 +- kitty/core_text.m | 2 +- kitty/data-types.c | 12 ++++++++++++ kitty/data-types.h | 1 - kitty/fast_data_types.pyi | 1 + kitty/fonts.c | 18 +++++++++--------- kitty/glfw.c | 22 ++-------------------- kitty/keys.h | 2 +- kitty/monotonic.h | 19 +++++++++++++++++++ kitty/mouse.c | 2 +- kitty/screen.c | 16 ++++------------ kitty/state.h | 3 +++ kitty/utils.py | 5 +++++ 23 files changed, 73 insertions(+), 58 deletions(-) diff --git a/glfw/cocoa_window.m b/glfw/cocoa_window.m index 02112ba09..1be408816 100644 --- a/glfw/cocoa_window.m +++ b/glfw/cocoa_window.m @@ -36,7 +36,7 @@ #include #include -#define debug(...) if (_glfw.hints.init.debugRendering) fprintf(stderr, __VA_ARGS__); +#define debug debug_rendering static const char* polymorphic_string_as_utf8(id string) { diff --git a/glfw/ibus_glfw.c b/glfw/ibus_glfw.c index 43afb50ed..fcf4dfc04 100644 --- a/glfw/ibus_glfw.c +++ b/glfw/ibus_glfw.c @@ -46,8 +46,7 @@ #include "internal.h" #include "ibus_glfw.h" -#undef debug -#define debug(...) if (_glfw.hints.init.debugKeyboard) printf(__VA_ARGS__); +#define debug debug_input static const char IBUS_SERVICE[] = "org.freedesktop.IBus"; static const char IBUS_PATH[] = "/org/freedesktop/IBus"; static const char IBUS_INTERFACE[] = "org.freedesktop.IBus"; diff --git a/glfw/internal.h b/glfw/internal.h index 019f33d83..f3d10357a 100644 --- a/glfw/internal.h +++ b/glfw/internal.h @@ -883,3 +883,5 @@ char* _glfw_strdup(const char* source); void _glfw_free_clipboard_data(_GLFWClipboardData *cd); +#define debug_rendering(...) if (_glfw.hints.init.debugRendering) { timed_debug_print(__VA_ARGS__); } +#define debug_input(...) if (_glfw.hints.init.debugKeyboard) { timed_debug_print(__VA_ARGS__); } diff --git a/glfw/wl_client_side_decorations.c b/glfw/wl_client_side_decorations.c index c36a03429..f5396da06 100644 --- a/glfw/wl_client_side_decorations.c +++ b/glfw/wl_client_side_decorations.c @@ -14,6 +14,7 @@ #include #define decs window->wl.decorations +#define debug debug_rendering #define ARGB(a, r, g, b) (((a) << 24) | ((r) << 16) | ((g) << 8) | (b)) #define A(x) (((x) >> 24) & 0xff) diff --git a/glfw/wl_init.c b/glfw/wl_init.c index 77b4512e7..a03323e56 100644 --- a/glfw/wl_init.c +++ b/glfw/wl_init.c @@ -56,6 +56,7 @@ #include #endif +#define debug debug_rendering static int min(int n1, int n2) { diff --git a/glfw/wl_platform.h b/glfw/wl_platform.h index 5bd8c034b..0c7c20db8 100644 --- a/glfw/wl_platform.h +++ b/glfw/wl_platform.h @@ -413,7 +413,6 @@ int _glfwWaylandIntegerWindowScale(_GLFWwindow*); void animateCursorImage(id_type timer_id, void *data); struct wl_cursor* _glfwLoadCursor(GLFWCursorShape, struct wl_cursor_theme*); void destroy_data_offer(_GLFWWaylandDataOffer*); -#define debug(...) if (_glfw.hints.init.debugRendering) { fprintf(stderr, "[%.3f] ", monotonic_t_to_s_double(monotonic())); fprintf(stderr, __VA_ARGS__); } typedef struct wayland_cursor_shape { int which; const char *name; diff --git a/glfw/wl_text_input.c b/glfw/wl_text_input.c index 76b30f9bd..5c999a512 100644 --- a/glfw/wl_text_input.c +++ b/glfw/wl_text_input.c @@ -10,8 +10,7 @@ #include "wayland-text-input-unstable-v3-client-protocol.h" #include #include -#undef debug -#define debug(...) if (_glfw.hints.init.debugKeyboard) printf(__VA_ARGS__); +#define debug debug_input static struct zwp_text_input_v3* text_input; static struct zwp_text_input_manager_v3* text_input_manager; diff --git a/glfw/wl_window.c b/glfw/wl_window.c index da68dd94f..d33de77e7 100644 --- a/glfw/wl_window.c +++ b/glfw/wl_window.c @@ -41,6 +41,7 @@ #include #include +#define debug debug_rendering static GLFWLayerShellConfig layer_shell_config_for_next_window = {0}; @@ -636,7 +637,7 @@ xdgToplevelHandleConfigure(void* data, wl_array_for_each(state, states) { switch (*state) { -#define C(x) case XDG_##x: new_states |= x; if (_glfw.hints.init.debugRendering) fprintf(stderr, "%s ", #x); break +#define C(x) case XDG_##x: new_states |= x; debug("%s ", #x); break C(TOPLEVEL_STATE_RESIZING); C(TOPLEVEL_STATE_MAXIMIZED); C(TOPLEVEL_STATE_FULLSCREEN); @@ -651,7 +652,7 @@ xdgToplevelHandleConfigure(void* data, #undef C } } - if (_glfw.hints.init.debugRendering) fprintf(stderr, "\n"); + debug("\n"); if (new_states & TOPLEVEL_STATE_RESIZING) { if (width) window->wl.user_requested_content_size.width = width; if (height) window->wl.user_requested_content_size.height = height; diff --git a/glfw/xkb_glfw.c b/glfw/xkb_glfw.c index 2fa129753..7bd3186d3 100644 --- a/glfw/xkb_glfw.c +++ b/glfw/xkb_glfw.c @@ -33,8 +33,7 @@ #include #endif -#undef debug -#define debug(...) if (_glfw.hints.init.debugKeyboard) fprintf(stderr, __VA_ARGS__); +#define debug debug_input #ifdef XKB_HAS_NO_UTF32 #include "xkb-compat-shim.h" @@ -940,7 +939,7 @@ glfw_xkb_handle_key_event(_GLFWwindow *window, _GLFWXKBData *xkb, xkb_keycode_t glfw_ev.alternate_key = glfw_key_for_sym(alternate_xkb_sym); if (glfw_ev.alternate_key) debug(" alternate_key: %d (%s)", glfw_ev.alternate_key, _glfwGetKeyName(glfw_ev.alternate_key)) } - debug("%s", "\n"); + debug("\n"); // NOTE: On linux, the reported native key identifier is the XKB keysym value. // Do not confuse `native_key` with `xkb_keycode` (the native keycode reported for the diff --git a/kitty/boss.py b/kitty/boss.py index 5957cb23c..91aef822b 100644 --- a/kitty/boss.py +++ b/kitty/boss.py @@ -150,6 +150,7 @@ from .utils import ( sanitize_url_for_dispay_to_user, single_instance, startup_notification_handler, + timed_debug_print, which, ) from .window import CommandOutput, CwdRequest, Window @@ -1518,7 +1519,7 @@ class Boss: if self.args.debug_keyboard: prefix = '\n' if dispatch_type == 'KeyPress' else '' end = ', ' if dispatch_type == 'KeyPress' else '\n' - print(f'{prefix}\x1b[35m{dispatch_type}\x1b[m matched action:', func_name(f), end=end, flush=True) + timed_debug_print(f'{prefix}\x1b[35m{dispatch_type}\x1b[m matched action:', func_name(f), end=end) if key_action is not None: f = getattr(self, key_action.func, None) diff --git a/kitty/child-monitor.c b/kitty/child-monitor.c index 42ac96215..c847978f5 100644 --- a/kitty/child-monitor.c +++ b/kitty/child-monitor.c @@ -27,7 +27,7 @@ extern PyTypeObject Screen_Type; #endif #ifdef DEBUG_EVENT_LOOP -#define EVDBG(...) log_event(__VA_ARGS__) +#define EVDBG(...) timed_debug_print(__VA_ARGS__) #else #define EVDBG(...) #endif diff --git a/kitty/core_text.m b/kitty/core_text.m index d9fda023d..5fa6b3551 100644 --- a/kitty/core_text.m +++ b/kitty/core_text.m @@ -21,7 +21,7 @@ #import #import -#define debug(...) if (global_state.debug_font_fallback) { fprintf(stderr, __VA_ARGS__); fflush(stderr); } +#define debug debug_fonts typedef struct { PyObject_HEAD diff --git a/kitty/data-types.c b/kitty/data-types.c index fb868e18e..b1d20c39e 100644 --- a/kitty/data-types.c +++ b/kitty/data-types.c @@ -416,6 +416,17 @@ py_monotonic(PyObject *self UNUSED, PyObject *args UNUSED) { return PyFloat_FromDouble(monotonic_t_to_s_double(monotonic())); } +static PyObject* +py_timed_debug_print(PyObject *self UNUSED, PyObject *args) { + const char *payload; Py_ssize_t sz; + if (!PyArg_ParseTuple(args, "s#", &payload, &sz)) return NULL; + const char *fmt = "%.*s"; + if (sz && payload[sz-1] == '\n') { fmt = "%.*s\n"; sz--; } + timed_debug_print(fmt, sz, payload); + Py_RETURN_NONE; +} + + static PyMethodDef module_methods[] = { METHODB(replace_c0_codes_except_nl_space_tab, METH_O), {"wcwidth", (PyCFunction)wcwidth_wrap, METH_O, ""}, @@ -439,6 +450,7 @@ static PyMethodDef module_methods[] = { {"wrapped_kitten_names", (PyCFunction)wrapped_kittens, METH_NOARGS, ""}, {"terminfo_data", (PyCFunction)py_terminfo_data, METH_NOARGS, ""}, {"monotonic", (PyCFunction)py_monotonic, METH_NOARGS, ""}, + {"timed_debug_print", (PyCFunction)py_timed_debug_print, METH_VARARGS, ""}, {"find_in_memoryview", (PyCFunction)find_in_memoryview, METH_VARARGS, ""}, #ifdef __APPLE__ METHODB(user_cache_dir, METH_NOARGS), diff --git a/kitty/data-types.h b/kitty/data-types.h index d8108780e..64bc30fa9 100644 --- a/kitty/data-types.h +++ b/kitty/data-types.h @@ -426,7 +426,6 @@ void play_canberra_sound(const char *which_sound, const char *event_id, bool is_ SPRITE_MAP_HANDLE alloc_sprite_map(unsigned int, unsigned int); SPRITE_MAP_HANDLE free_sprite_map(SPRITE_MAP_HANDLE); const char* get_hyperlink_for_id(const HYPERLINK_POOL_HANDLE, hyperlink_id_type id, bool only_url); -void log_event(const char *format, ...) __attribute__((format(printf, 1, 2))); #define memset_array(array, val, count) if ((count) > 0) { \ (array)[0] = (val); \ diff --git a/kitty/fast_data_types.pyi b/kitty/fast_data_types.pyi index c7c226313..d75dad48b 100644 --- a/kitty/fast_data_types.pyi +++ b/kitty/fast_data_types.pyi @@ -1578,3 +1578,4 @@ def replace_c0_codes_except_nl_space_tab(text: Union[bytes, memoryview, bytearra def terminfo_data() -> bytes:... def wayland_compositor_data() -> Tuple[int, Optional[str]]:... def monotonic() -> float: ... +def timed_debug_print(x: str) -> None: ... diff --git a/kitty/fonts.c b/kitty/fonts.c index a6cf63919..573521293 100644 --- a/kitty/fonts.c +++ b/kitty/fonts.c @@ -15,7 +15,7 @@ #define MISSING_GLYPH (NUM_UNDERLINE_STYLES + 2) #define MAX_NUM_EXTRA_GLYPHS_PUA 4u -#define debug(...) if (global_state.debug_font_fallback) { fprintf(stderr, __VA_ARGS__); fflush(stderr); } +#define debug debug_fonts static PyObject *python_send_to_gpu_impl = NULL; #define current_send_sprite_to_gpu(...) (python_send_to_gpu_impl ? python_send_to_gpu(__VA_ARGS__) : send_sprite_to_gpu(__VA_ARGS__)) @@ -455,16 +455,16 @@ has_cell_text(PyObject *face, CPUCell *cell) { static void output_cell_fallback_data(CPUCell *cell, bool bold, bool italic, bool emoji_presentation, PyObject *face) { - printf("U+%x ", cell->ch); + debug("U+%x ", cell->ch); for (unsigned i = 0; i < arraysz(cell->cc_idx) && cell->cc_idx[i]; i++) { - printf("U+%x ", codepoint_for_mark(cell->cc_idx[i])); + debug("U+%x ", codepoint_for_mark(cell->cc_idx[i])); } - if (bold) printf("bold "); - if (italic) printf("italic "); - if (emoji_presentation) printf("emoji_presentation "); - if (PyLong_Check(face)) printf("using previous fallback font at index: "); - PyObject_Print(face, stdout, 0); - printf("\n"); + if (bold) debug("bold "); + if (italic) debug("italic "); + if (emoji_presentation) debug("emoji_presentation "); + if (PyLong_Check(face)) debug("using previous fallback font at index: "); + PyObject_Print(face, stderr, 0); + debug("\n"); } PyObject* diff --git a/kitty/glfw.c b/kitty/glfw.c index e0743ab1b..22e1c9c85 100644 --- a/kitty/glfw.c +++ b/kitty/glfw.c @@ -31,7 +31,7 @@ extern void cocoa_update_menu_bar_title(PyObject*); extern size_t cocoa_get_workspace_ids(void *w, size_t *workspace_ids, size_t array_sz); extern monotonic_t cocoa_cursor_blink_interval(void); -#define debug(...) if (global_state.debug_rendering) { fprintf(stderr, "[%.3f] ", monotonic_t_to_s_double(monotonic())); fprintf(stderr, __VA_ARGS__); } +#define debug debug_rendering typedef struct mouse_cursor { GLFWcursor *glfw; @@ -168,22 +168,6 @@ update_os_window_viewport(OSWindow *window, bool notify_boss) { } } -void -log_event(const char *format, ...) { - if (format) - { - va_list vl; - - fprintf(stderr, "[%.3f] ", monotonic_t_to_s_double(monotonic())); - va_start(vl, format); - vfprintf(stderr, format, vl); - va_end(vl); - fprintf(stderr, "\n"); - } - -} - - // callbacks {{{ void @@ -512,9 +496,7 @@ static id_type focus_counter = 0; static void window_focus_callback(GLFWwindow *w, int focused) { if (!set_callback_window(w)) return; - if (OPT(debug_keyboard)) { - fprintf(stderr, "\x1b[35mon_focus_change\x1b[m: window id: 0x%llu focused: %d\n", global_state.callback_os_window->id, focused); - } + debug_input("\x1b[35mon_focus_change\x1b[m: window id: 0x%llu focused: %d\n", global_state.callback_os_window->id, focused); // There exist some numbnut Wayland compositors, like kwin, that send mouse // press events before focus gained events. So only clear the active drag // window if it is not the focused window. See https://github.com/kovidgoyal/kitty/issues/6095 diff --git a/kitty/keys.h b/kitty/keys.h index 2f70ca6d6..43a0e5307 100644 --- a/kitty/keys.h +++ b/kitty/keys.h @@ -13,7 +13,7 @@ #define KEY_BUFFER_SIZE 128 #define SEND_TEXT_TO_CHILD INT_MIN -#define debug(...) if (OPT(debug_keyboard)) { fprintf(stderr, __VA_ARGS__); fflush(stderr); } +#define debug debug_input int encode_glfw_key_event(const GLFWkeyevent *e, const bool cursor_key_mode, const unsigned flags, char *output); diff --git a/kitty/monotonic.h b/kitty/monotonic.h index cb91dcb3f..0b8b26e8e 100644 --- a/kitty/monotonic.h +++ b/kitty/monotonic.h @@ -67,8 +67,14 @@ init_monotonic(void) { monotonic_start_time = monotonic_(); } +extern int timed_debug_print(const char *fmt, ...) __attribute__((format(printf, 1, 2))); + #ifdef MONOTONIC_IMPLEMENTATION #include +#include +#include +#include + monotonic_t monotonic_start_time = 0; static inline monotonic_t @@ -88,4 +94,17 @@ monotonic_(void) { #endif return calc_nano_time(ts); } + +int +timed_debug_print(const char *fmt, ...) { + int result; + static int starting_print = 1; + if (starting_print) fprintf(stderr, "[%.3f] ", monotonic_t_to_s_double(monotonic())); + va_list args; + va_start(args, fmt); + result = vfprintf(stderr, fmt, args); + va_end(args); + starting_print = fmt && strchr(fmt, '\n') != NULL; + return result; +} #endif diff --git a/kitty/mouse.c b/kitty/mouse.c index 4920ccebd..d4cbc140b 100644 --- a/kitty/mouse.c +++ b/kitty/mouse.c @@ -18,7 +18,7 @@ extern PyTypeObject Screen_Type; static MouseShape mouse_cursor_shape = TEXT_POINTER; typedef enum MouseActions { PRESS, RELEASE, DRAG, MOVE } MouseAction; -#define debug(...) if (OPT(debug_keyboard)) printf(__VA_ARGS__); +#define debug debug_input // Encoding of mouse events {{{ #define SHIFT_INDICATOR (1 << 2) diff --git a/kitty/screen.c b/kitty/screen.c index 612ad277e..695899263 100644 --- a/kitty/screen.c +++ b/kitty/screen.c @@ -1168,9 +1168,7 @@ screen_current_key_encoding_flags(Screen *self) { void screen_report_key_encoding_flags(Screen *self) { char buf[16] = {0}; - if (OPT(debug_keyboard)) { - debug("\x1b[35mReporting key encoding flags: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); - } + debug_input("\x1b[35mReporting key encoding flags: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); snprintf(buf, sizeof(buf), "?%uu", screen_current_key_encoding_flags(self)); write_escape_code_to_child(self, ESC_CSI, buf); } @@ -1186,9 +1184,7 @@ screen_set_key_encoding_flags(Screen *self, uint32_t val, uint32_t how) { else if (how == 2) self->key_encoding_flags[idx] |= q; else if (how == 3) self->key_encoding_flags[idx] &= ~q; self->key_encoding_flags[idx] |= 0x80; - if (OPT(debug_keyboard)) { - debug("\x1b[35mSet key encoding flags to: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); - } + debug_input("\x1b[35mSet key encoding flags to: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); } void @@ -1202,9 +1198,7 @@ screen_push_key_encoding_flags(Screen *self, uint32_t val) { if (current_idx == sz - 1) memmove(self->key_encoding_flags, self->key_encoding_flags + 1, (sz - 1) * sizeof(self->main_key_encoding_flags[0])); else self->key_encoding_flags[current_idx++] |= 0x80; self->key_encoding_flags[current_idx] = 0x80 | q; - if (OPT(debug_keyboard)) { - debug("\x1b[35mPushed key encoding flags to: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); - } + debug_input("\x1b[35mPushed key encoding flags to: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); } void @@ -1212,9 +1206,7 @@ screen_pop_key_encoding_flags(Screen *self, uint32_t num) { for (unsigned i = arraysz(self->main_key_encoding_flags); num && i-- > 0; ) { if (self->key_encoding_flags[i] & 0x80) { num--; self->key_encoding_flags[i] = 0; } } - if (OPT(debug_keyboard)) { - debug("\x1b[35mPopped key encoding flags to: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); - } + debug_input("\x1b[35mPopped key encoding flags to: %u\x1b[39m\n", screen_current_key_encoding_flags(self)); } // }}} diff --git a/kitty/state.h b/kitty/state.h index ec7c74035..a1d1c2b84 100644 --- a/kitty/state.h +++ b/kitty/state.h @@ -11,6 +11,9 @@ #include "window_logo.h" #define OPT(name) global_state.opts.name +#define debug_rendering(...) if (global_state.debug_rendering) { timed_debug_print(__VA_ARGS__); } +#define debug_input(...) if (OPT(debug_keyboard)) { timed_debug_print(__VA_ARGS__); } +#define debug_fonts(...) if (global_state.debug_font_fallback) { timed_debug_print(__VA_ARGS__); } typedef enum { LEFT_EDGE, TOP_EDGE, RIGHT_EDGE, BOTTOM_EDGE } Edge; typedef enum { REPEAT_MIRROR, REPEAT_CLAMP, REPEAT_DEFAULT } RepeatStrategy; diff --git a/kitty/utils.py b/kitty/utils.py index 29916c09a..13169bd93 100644 --- a/kitty/utils.py +++ b/kitty/utils.py @@ -43,6 +43,7 @@ from .constants import ( ssh_control_master_template, ) from .fast_data_types import WINDOW_FULLSCREEN, WINDOW_MAXIMIZED, WINDOW_MINIMIZED, WINDOW_NORMAL, Color, Shlex, get_options, monotonic, open_tty +from .fast_data_types import timed_debug_print as _timed_debug_print from .rgb import to_color from .types import run_once from .typing import AddressFamily, PopenType, Socket, StartupCtx @@ -1236,3 +1237,7 @@ def shlex_split_with_positions(text: str) -> Iterator[Tuple[int, str]]: s = Shlex(text) while (q := s.next_word())[0] > -1: yield q + + +def timed_debug_print(*a: Any, sep: str = ' ', end: str = '\n') -> None: + _timed_debug_print(sep.join(map(str, a)) + end)