blender
/
blender
136
406
Fork 588
Code Issues 6.2k Pull Requests 750 Projects 19 Wiki Activity

WM: improve logging for handling operators 

- Add logging for CLICK_DRAG event handling to debug drag events.
- Use logging API for reporting the key-map, operator and event.

This command now prints useful information for investigating
key-map and event handling issues:

  blender --log "wm.handler.*" --log-level 4
This commit is contained in:
Campbell Barton 2022-04-13 15:40:58 +10:00
parent 02de1bff1e
commit 9a659f2573
1 changed files with 82 additions and 42 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

124
source/blender/windowmanager/intern/wm_event_system.c
View File

@ -2691,6 +2691,51 @@ static int wm_action_not_handled(int action)
return action == WM_HANDLER_CONTINUE || action == (WM_HANDLER_BREAK | WM_HANDLER_MODAL);
}
static const char *keymap_handler_log_action_str(const int action)
{
if (action & WM_HANDLER_BREAK) {
return "handled";
}
if (action & WM_HANDLER_HANDLED) {
return "handled (and pass on)";
}
return "un-handled";
}
static const char *keymap_handler_log_kmi_event_str(const wmKeyMapItem *kmi,
char *buf,
size_t buf_maxlen)
{
/* Short representation of the key that was pressed,
* include this since it may differ from the event in minor details
* which can help looking up the key-map definition. */
WM_keymap_item_to_string(kmi, false, buf, buf_maxlen);
return buf;
}
static const char *keymap_handler_log_kmi_op_str(bContext *C,
const wmKeyMapItem *kmi,
char *buf,
size_t buf_maxlen)
{
/* The key-map item properties can further help distinguish this item from others. */
char *kmi_props = NULL;
if (kmi->properties != NULL) {
wmOperatorType *ot = WM_operatortype_find(kmi->idname, 0);
if (ot) {
kmi_props = RNA_pointer_as_string_keywords(C, kmi->ptr, false, false, true, 512);
}
else { /* Fallback. */
kmi_props = IDP_reprN(kmi->properties, NULL);
}
}
BLI_snprintf(buf, buf_maxlen, "%s(%s)", kmi->idname, kmi_props ? kmi_props : "");
if (kmi_props != NULL) {
MEM_freeN(kmi_props);
}
return buf;
}
#define PRINT \
if (do_debug_handler) \
printf
@ -2722,52 +2767,26 @@ static int wm_handlers_do_keymap_with_keymap_handler(
if (wm_eventmatch(event, kmi)) {
struct wmEventHandler_KeymapPost keymap_post = handler->post;
if (do_debug_handler) {
/* Short representation of the key that was pressed,
* include this since it may differ from the event in minor details
* which can help looking up the key-map definition. */
char kmi_buf[256];
WM_keymap_item_to_string(kmi, false, kmi_buf, sizeof(kmi_buf));
/* The key-map item properties can further help distinguish this item from others. */
char *kmi_props = NULL;
if (kmi->properties != NULL) {
wmOperatorType *ot = WM_operatortype_find(kmi->idname, 0);
if (ot) {
kmi_props = RNA_pointer_as_string_keywords(C, kmi->ptr, false, false, true, 512);
}
else { /* Fallback. */
kmi_props = IDP_reprN(kmi->properties, NULL);
}
}
printf("%s: item matched: \"%s\", %s(%s)\n",
__func__,
kmi_buf,
kmi->idname,
kmi_props ? kmi_props : "");
if (kmi_props != NULL) {
MEM_freeN(kmi_props);
}
}
action |= wm_handler_operator_call(
C, handlers, &handler->head, event, kmi->ptr, kmi->idname);
char op_buf[512];
char kmi_buf[128];
CLOG_INFO(WM_LOG_HANDLERS,
2,
"keymap '%s', %s, %s, event: %s",
keymap->idname,
keymap_handler_log_kmi_op_str(C, kmi, op_buf, sizeof(op_buf)),
keymap_handler_log_action_str(action),
keymap_handler_log_kmi_event_str(kmi, kmi_buf, sizeof(kmi_buf)));
if (action & WM_HANDLER_BREAK) {
/* Not always_pass here, it denotes removed handler_base. */
CLOG_INFO(WM_LOG_HANDLERS, 2, "handled! '%s'", kmi->idname);
if (keymap_post.post_fn != NULL) {
keymap_post.post_fn(keymap, kmi, keymap_post.user_data);
}
break;
}
if (action & WM_HANDLER_HANDLED) {
CLOG_INFO(WM_LOG_HANDLERS, 2, "handled - and pass on! '%s'", kmi->idname);
}
else {
CLOG_INFO(WM_LOG_HANDLERS, 2, "un-handled '%s'", kmi->idname);
}
}
}
}
@ -3249,7 +3268,7 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
event->keymodifier = event->prev_press_keymodifier;
event->direction = direction;
CLOG_INFO(WM_LOG_HANDLERS, 1, "handling PRESS_DRAG");
CLOG_INFO(WM_LOG_HANDLERS, 1, "handling CLICK_DRAG");
action |= wm_handlers_do_intern(C, win, event, handlers);
@ -3262,13 +3281,17 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
win->event_queue_check_click = false;
if (!((action & WM_HANDLER_BREAK) == 0 || wm_action_not_handled(action))) {
/* Only disable when handled as other handlers may use this drag event. */
CLOG_INFO(WM_LOG_HANDLERS, 3, "canceling CLICK_DRAG: drag was generated & handled");
win->event_queue_check_drag = false;
}
}
}
}
else {
win->event_queue_check_drag = false;
if (win->event_queue_check_drag) {
CLOG_INFO(WM_LOG_HANDLERS, 3, "canceling CLICK_DRAG: motion event was handled");
win->event_queue_check_drag = false;
}
}
}
else if (ISKEYBOARD_OR_BUTTON(event->type)) {
@ -3282,7 +3305,10 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
if (event->val == KM_PRESS) {
if ((event->flag & WM_EVENT_IS_REPEAT) == 0) {
win->event_queue_check_click = true;
CLOG_INFO(WM_LOG_HANDLERS, 3, "detecting CLICK_DRAG: press event detected");
win->event_queue_check_drag = true;
win->event_queue_check_drag_handled = false;
}
}
@ -3293,6 +3319,8 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
/* Support releasing modifier keys without canceling the drag event, see T89989. */
}
else {
CLOG_INFO(
WM_LOG_HANDLERS, 3, "CLICK_DRAG: canceling (release event didn't match press)");
win->event_queue_check_drag = false;
}
}
@ -3305,7 +3333,12 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
if (win->event_queue_check_click == true) {
if (WM_event_drag_test(event, event->prev_press_xy)) {
win->event_queue_check_click = false;
win->event_queue_check_drag = false;
if (win->event_queue_check_drag) {
CLOG_INFO(WM_LOG_HANDLERS,
3,
"CLICK_DRAG: canceling (key-release exceeds drag threshold)");
win->event_queue_check_drag = false;
}
}
else {
/* Position is where the actual click happens, for more
@ -3315,7 +3348,7 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
copy_v2_v2_int(event->xy, event->prev_press_xy);
event->val = KM_CLICK;
CLOG_INFO(WM_LOG_HANDLERS, 1, "handling CLICK");
CLOG_INFO(WM_LOG_HANDLERS, 1, "CLICK: handling");
action |= wm_handlers_do_intern(C, win, event, handlers);
@ -3339,7 +3372,14 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
}
else {
win->event_queue_check_click = false;
win->event_queue_check_drag = false;
if (win->event_queue_check_drag) {
CLOG_INFO(WM_LOG_HANDLERS,
3,
"CLICK_DRAG: canceling (button event was handled: value=%d)",
event->val);
win->event_queue_check_drag = false;
}
}
}
else if (ISMOUSE_WHEEL(event->type) || ISMOUSE_GESTURE(event->type)) {
@ -4932,7 +4972,7 @@ static void wm_event_state_update_and_click_set(const GHOST_TEventType type,
/* Double click test. */
if (wm_event_is_double_click(event)) {
CLOG_INFO(WM_LOG_HANDLERS, 1, "Send double click");
CLOG_INFO(WM_LOG_HANDLERS, 1, "DBL_CLICK: detected");
event->val = KM_DBL_CLICK;
}
else if (event->val == KM_PRESS) {