Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Open
SolidHal opened this issue Jul 3, 2024 · 2 comments
Open

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

SolidHal opened this issue Jul 3, 2024 · 2 comments

Comments

@SolidHal
Copy link

SolidHal commented Jul 3, 2024

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
Copy link
Author

SolidHal commented Jul 3, 2024

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 added a commit to SolidHal/zmk that referenced this issue Jul 3, 2024
@SolidHal
fix(macro): set the macro release states wait_ms
d6924ef 
when we create a release trigger state for each press state
we miss setting the releases wait_ms field, resulting in
key releases all occuring instantaneously

this can result in lost key release commands
see issue zmkfirmware#2356
SolidHal added a commit to SolidHal/zmk that referenced this issue Jul 3, 2024
@SolidHal
fix(macro): set the macro release states wait_ms
9595896 
when we create a release trigger state for each press state
we miss setting the releases wait_ms field, resulting in
key releases all occuring instantaneously

this can result in lost key release commands
see issue zmkfirmware#2356
@SolidHal SolidHal mentioned this issue Jul 3, 2024
Open
@SolidHal
Copy link
Author

SolidHal commented Jul 3, 2024

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

lesshonor pushed a commit to lesshonor/zmk that referenced this issue Jul 6, 2024
@SolidHal @lesshonor
fix(macro): set the macro release states wait_ms
a0d0dea 
when we create a release trigger state for each press state
we miss setting the releases wait_ms field, resulting in
key releases all occuring instantaneously

this can result in lost key release commands
see issue zmkfirmware#2356
lesshonor pushed a commit to lesshonor/zmk that referenced this issue Jul 6, 2024
@SolidHal @lesshonor
fix(macro): set the macro release states wait_ms
0008fe5 
when we create a release trigger state for each press state
we miss setting the releases wait_ms field, resulting in
key releases all occuring instantaneously

this can result in lost key release commands
see issue zmkfirmware#2356
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@SolidHal