search

zmkfirmware / zmk

ZMK Firmware Repository
https://zmk.dev/
MIT License
2.48k stars 2.55k forks source link

`&macro_release` do not repsect the macros `wait-ms` resulting in lost keystrokes #2356

Open SolidHal opened 2 days ago

SolidHal commented 2 days ago

while messing around with midi support and macros, i noticed that &macro_release and &macro_press handle the wait-ms parameter differently.

example macro:

        ma_Eb: major_Eb {
            compatible = "zmk,behavior-macro";
            wait-ms = <2>;
            tap-ms = <0>;
            #binding-cells = <0>;
            bindings
            = <&macro_press &mo MA_Eb>
            , <&macro_press &midi NOTE_Eb_4>
            , <&macro_press &midi NOTE_G_4>
            , <&macro_press &midi NOTE_Bb_4>
            , <&macro_pause_for_release>
            , <&macro_release &mo MA_Eb>
            , <&macro_release &midi NOTE_Eb_4>
            , <&macro_release &midi NOTE_G_4>
            , <&macro_release &midi NOTE_Bb_4>
            ;
        };

i would expect that when this macro is pressed there is a 2ms wait between each press, and then a 2ms wait between each release.

but in midisnoop i observed the presses each has a 2ms wait, the releases do not. in the following example we can see that one of the releases aka Note Off events gets missed entirely.

image

i put some debug prints into behavior_macro.c and confirmed the key release events were being queued with a wait_ms of 0 and the presses were being queud with a wait_ms of 2

static void queue_macro(uint32_t position, const struct zmk_behavior_binding bindings[],
                        struct behavior_macro_trigger_state state,
                        const struct zmk_behavior_binding *macro_binding) {
    LOG_DBG("Iterating macro bindings - starting: %d, count: %d", state.start_index, state.count);
    for (int i = state.start_index; i < state.start_index + state.count; i++) {
        if (!handle_control_binding(&state, &bindings[i])) {
            struct zmk_behavior_binding binding = bindings[i];
            replace_params(&state, &binding, macro_binding);

            switch (state.mode) {
            case MACRO_MODE_TAP:
                zmk_behavior_queue_add(position, binding, true, state.tap_ms);
                zmk_behavior_queue_add(position, binding, false, state.wait_ms);
                break;
            case MACRO_MODE_PRESS:
              LOG_ERR("MACRO MODE PRESS wait_ms: %d", state.wait_ms);
                zmk_behavior_queue_add(position, binding, true, state.wait_ms);
                break;
            case MACRO_MODE_RELEASE:
                LOG_ERR("MACRO MODE RELEASE wait_ms: %d", state.wait_ms);
                zmk_behavior_queue_add(position, binding, false, state.wait_ms);
                break;
            default:
                LOG_ERR("Unknown macro mode: %d", state.mode);
                break;
            }
        }
    }
}

logs:

[00:01:36.425,445] <dbg> zmk: queue_macro: Iterating macro bindings - starting: 0, count: 8
[00:01:36.425,476] <dbg> zmk: handle_control_binding: macro mode set: press
[00:01:36.425,476] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:01:36.425,537] <dbg> zmk: behavior_queue_process_next: Invoking momentary_layer: 0x07 0x00
[00:01:36.425,537] <dbg> zmk: mo_keymap_binding_pressed: position 0 layer 7
[00:01:36.425,567] <dbg> zmk: set_layer_state: layer_changed: layer 7 state 1
[00:01:36.425,598] <dbg> zmk: conditional_layer_activate: layer 12
[00:01:36.425,628] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:01:36.425,628] <dbg> zmk: handle_control_binding: macro mode set: press
[00:01:36.425,659] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:01:36.425,689] <dbg> zmk: handle_control_binding: macro mode set: press
[00:01:36.425,720] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:01:36.425,720] <dbg> zmk: handle_control_binding: macro mode set: press
[00:01:36.425,750] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:01:36.427,734] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x33 0x00
[00:01:36.427,764] <dbg> zmk: on_keymap_binding_pressed: position 0 keycode 0x33
[00:01:36.427,764] <dbg> zmk: listener_midi_key_pressed: midi key: 0x0033
[00:01:36.427,795] <inf> zmk: zmk_midi_key_press received: 0x0033 aka 51
[00:01:36.427,795] <inf> zmk: body cin = 144, key = 51, key_value = 63
[00:01:36.427,825] <inf> zmk: Sending midi bytes 90 33 3f
[00:01:36.427,825] <inf> zmk: Sending midi packet 09 90 33 3f to endpoint 81
[00:01:36.427,856] <inf> zmk: doing midi usb_write
[00:01:36.427,886] <inf> zmk: completed midi usb write 0
[00:01:36.427,917] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:01:36.428,558] <dbg> zmk: midi_in_ep_cb: midi_in_ep_cb is not implemented
[00:01:36.430,023] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x37 0x00
[00:01:36.430,053] <dbg> zmk: on_keymap_binding_pressed: position 0 keycode 0x37
[00:01:36.430,084] <dbg> zmk: listener_midi_key_pressed: midi key: 0x0037
[00:01:36.430,084] <inf> zmk: zmk_midi_key_press received: 0x0037 aka 55
[00:01:36.430,114] <inf> zmk: body cin = 144, key = 55, key_value = 63
[00:01:36.430,114] <inf> zmk: Sending midi bytes 90 37 3f
[00:01:36.430,145] <inf> zmk: Sending midi packet 09 90 37 3f to endpoint 81
[00:01:36.430,145] <inf> zmk: doing midi usb_write
[00:01:36.430,206] <inf> zmk: completed midi usb write 0
[00:01:36.430,236] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:01:36.430,480] <dbg> zmk: midi_in_ep_cb: midi_in_ep_cb is not implemented
[00:01:36.432,342] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x3a 0x00
[00:01:36.432,373] <dbg> zmk: on_keymap_binding_pressed: position 0 keycode 0x3A
[00:01:36.432,373] <dbg> zmk: listener_midi_key_pressed: midi key: 0x003A
[00:01:36.432,403] <inf> zmk: zmk_midi_key_press received: 0x003a aka 58
[00:01:36.432,403] <inf> zmk: body cin = 144, key = 58, key_value = 63
[00:01:36.432,434] <inf> zmk: Sending midi bytes 90 3a 3f
[00:01:36.432,434] <inf> zmk: Sending midi packet 09 90 3a 3f to endpoint 81
[00:01:36.432,464] <inf> zmk: doing midi usb_write
[00:01:36.432,556] <inf> zmk: completed midi usb write 0
[00:01:36.432,586] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:01:36.432,617] <dbg> zmk: midi_in_ep_cb: midi_in_ep_cb is not implemented
[00:01:43.405,212] <dbg> zmk: kscan_matrix_read: Sending event at 0,0 state off
[00:01:43.405,395] <dbg> zmk: zmk_kscan_process_msgq: Row: 0, col: 0, position: 0, pressed: false
[00:01:43.405,395] <dbg> zmk: tap_dance_position_state_changed_listener: Ignore upstroke at position 0.
[00:01:43.405,456] <dbg> zmk: zmk_keymap_apply_position_state: layer: 11 position: 0, binding name: major_Eb
[00:01:43.405,517] <dbg> zmk: queue_macro: Iterating macro bindings - starting: 9, count: 8
[00:01:43.405,548] <dbg> zmk: handle_control_binding: macro mode set: release
[00:01:43.405,548] <err> zmk: MACRO MODE RELEASE wait_ms: 0
[00:01:43.405,609] <dbg> zmk: behavior_queue_process_next: Invoking momentary_layer: 0x07 0x00
[00:01:43.405,609] <dbg> zmk: mo_keymap_binding_released: position 0 layer 7
[00:01:43.405,639] <dbg> zmk: set_layer_state: layer_changed: layer 7 state 0
[00:01:43.405,670] <dbg> zmk: conditional_layer_activate: layer 12
[00:01:43.405,670] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 0ms
[00:01:43.405,700] <dbg> zmk: handle_control_binding: macro mode set: release
[00:01:43.405,731] <err> zmk: MACRO MODE RELEASE wait_ms: 0
[00:01:43.405,761] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x33 0x00
[00:01:43.405,792] <dbg> zmk: on_keymap_binding_released: position 0 keycode 0x33
[00:01:43.405,822] <dbg> zmk: listener_midi_key_released: midi key: 0x0033
[00:01:43.405,822] <inf> zmk: zmk_midi_key_release received: 0x0033 aka 51
[00:01:43.405,853] <inf> zmk: body cin = 128, key = 51, key_value = 100
[00:01:43.405,853] <inf> zmk: Sending midi bytes 80 33 64
[00:01:43.405,883] <inf> zmk: Sending midi packet 08 80 33 64 to endpoint 81
[00:01:43.405,883] <inf> zmk: doing midi usb_write
[00:01:43.405,975] <inf> zmk: completed midi usb write 0
[00:01:43.406,005] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 0ms
[00:01:43.406,005] <dbg> zmk: handle_control_binding: macro mode set: release
[00:01:43.406,036] <err> zmk: MACRO MODE RELEASE wait_ms: 0
[00:01:43.406,066] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x37 0x00
[00:01:43.406,097] <dbg> zmk: on_keymap_binding_released: position 0 keycode 0x37
[00:01:43.406,127] <dbg> zmk: listener_midi_key_released: midi key: 0x0037
[00:01:43.406,127] <inf> zmk: zmk_midi_key_release received: 0x0037 aka 55
[00:01:43.406,158] <inf> zmk: body cin = 128, key = 55, key_value = 100
[00:01:43.406,158] <inf> zmk: Sending midi bytes 80 37 64
[00:01:43.406,188] <inf> zmk: Sending midi packet 08 80 37 64 to endpoint 81
[00:01:43.406,188] <inf> zmk: doing midi usb_write
[00:01:43.406,250] <inf> zmk: completed midi usb write 0
[00:01:43.406,280] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 0ms
[00:01:43.406,280] <dbg> zmk: handle_control_binding: macro mode set: release
[00:01:43.406,311] <err> zmk: MACRO MODE RELEASE wait_ms: 0
SolidHal commented 2 days ago

when we precompute the release state, we don't properly fill in the wait_ms

[00:00:00.313,629] <err> zmk: BEHAVIOR_MARO_INIT cfg default = 2
[00:00:00.313,659] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:00.313,659] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:00.313,690] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:00.313,720] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:00.313,781] <dbg> zmk: behavior_macro_init: Release will resume at 9
[00:00:00.313,781] <err> zmk: BEHAVIOR_MARO_INIT state->release_state.wait_ms = 0
SolidHal commented 2 days ago

with the fix we can see the releases properly get 2ms of wait time

[00:00:34.730,468] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:34.730,468] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:00:34.730,529] <dbg> zmk: behavior_queue_process_next: Invoking momentary_layer: 0x07 0x00
[00:00:34.730,560] <dbg> zmk: mo_keymap_binding_pressed: position 0 layer 7
[00:00:34.730,560] <dbg> zmk: set_layer_state: layer_changed: layer 7 state 1
[00:00:34.730,590] <dbg> zmk: conditional_layer_activate: layer 12
[00:00:34.730,621] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:00:34.730,621] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:34.730,651] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:00:34.730,682] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:34.730,712] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:00:34.730,712] <dbg> zmk: handle_control_binding: macro mode set: press
[00:00:34.730,743] <err> zmk: MACRO MODE PRESS wait_ms: 2
[00:00:34.732,757] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x33 0x00
[00:00:34.732,788] <dbg> zmk: on_keymap_binding_pressed: position 0 keycode 0x33
[00:00:34.732,788] <dbg> zmk: listener_midi_key_pressed: midi key: 0x0033
[00:00:34.732,818] <inf> zmk: zmk_midi_key_press received: 0x0033 aka 51
[00:00:34.732,818] <inf> zmk: body cin = 144, key = 51, key_value = 63
[00:00:34.732,849] <inf> zmk: Sending midi bytes 90 33 3f
[00:00:34.732,849] <inf> zmk: Sending midi packet 09 90 33 3f to endpoint 81
[00:00:34.732,879] <inf> zmk: doing midi usb_write
[00:00:34.732,910] <inf> zmk: completed midi usb write 0
[00:00:34.732,940] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:00:34.733,612] <dbg> zmk: midi_in_ep_cb: midi_in_ep_cb is not implemented
[00:00:34.735,046] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x37 0x00
[00:00:34.735,076] <dbg> zmk: on_keymap_binding_pressed: position 0 keycode 0x37
[00:00:34.735,107] <dbg> zmk: listener_midi_key_pressed: midi key: 0x0037
[00:00:34.735,107] <inf> zmk: zmk_midi_key_press received: 0x0037 aka 55
[00:00:34.735,137] <inf> zmk: body cin = 144, key = 55, key_value = 63
[00:00:34.735,137] <inf> zmk: Sending midi bytes 90 37 3f
[00:00:34.735,168] <inf> zmk: Sending midi packet 09 90 37 3f to endpoint 81
[00:00:34.735,168] <inf> zmk: doing midi usb_write
[00:00:34.735,229] <inf> zmk: completed midi usb write 0
[00:00:34.735,260] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:00:34.735,626] <dbg> zmk: midi_in_ep_cb: midi_in_ep_cb is not implemented
[00:00:34.737,365] <dbg> zmk: behavior_queue_process_next: Invoking midi_key_press: 0x3a 0x00
[00:00:34.737,396] <dbg> zmk: on_keymap_binding_pressed: position 0 keycode 0x3A
[00:00:34.737,396] <dbg> zmk: listener_midi_key_pressed: midi key: 0x003A
[00:00:34.737,426] <inf> zmk: zmk_midi_key_press received: 0x003a aka 58
[00:00:34.737,426] <inf> zmk: body cin = 144, key = 58, key_value = 63
[00:00:34.737,457] <inf> zmk: Sending midi bytes 90 3a 3f
[00:00:34.737,457] <inf> zmk: Sending midi packet 09 90 3a 3f to endpoint 81
[00:00:34.737,487] <inf> zmk: doing midi usb_write
[00:00:34.737,518] <inf> zmk: completed midi usb write 0
[00:00:34.737,548] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:00:34.737,640] <dbg> zmk: midi_in_ep_cb: midi_in_ep_cb is not implemented
[00:00:35.705,200] <dbg> zmk: kscan_matrix_read: Sending event at 0,0 state off
[00:00:35.705,383] <dbg> zmk: zmk_kscan_process_msgq: Row: 0, col: 0, position: 0, pressed: false
[00:00:35.705,383] <dbg> zmk: tap_dance_position_state_changed_listener: Ignore upstroke at position 0.
[00:00:35.705,444] <dbg> zmk: zmk_keymap_apply_position_state: layer: 11 position: 0, binding name: major_Eb
[00:00:35.705,505] <dbg> zmk: queue_macro: Iterating macro bindings - starting: 9, count: 8
[00:00:35.705,535] <dbg> zmk: handle_control_binding: macro mode set: release
[00:00:35.705,535] <err> zmk: MACRO MODE RELEASE wait_ms: 2
[00:00:35.705,596] <dbg> zmk: behavior_queue_process_next: Invoking momentary_layer: 0x07 0x00
[00:00:35.705,596] <dbg> zmk: mo_keymap_binding_released: position 0 layer 7
[00:00:35.705,627] <dbg> zmk: set_layer_state: layer_changed: layer 7 state 0
[00:00:35.705,657] <dbg> zmk: conditional_layer_activate: layer 12
[00:00:35.705,657] <dbg> zmk: behavior_queue_process_next: Processing next queued behavior in 2ms
[00:00:35.705,718] <dbg> zmk: handle_control_binding: macro mode set: release
[00:00:35.705,718] <err> zmk: MACRO MODE RELEASE wait_ms: 2
[00:00:35.705,749] <dbg> zmk: handle_control_binding: macro mode set: release
[00:00:35.705,780] <err> zmk: MACRO MODE RELEASE wait_ms: 2
[00:00:35.705,810] <dbg> zmk: handle_control_binding: macro mode set: release
[00:00:35.705,841] <err> zmk: MACRO MODE RELEASE wait_ms: 2

image