search

mooz / xkeysnail

Yet another keyboard remapping tool for X environment
890 stars 112 forks source link

Making multi-keystroke macros more reliable? #150

Open RedBearAK opened 2 years ago

RedBearAK commented 2 years ago

I've noticed that when trying to use macros they have a tendency to somehow crash or just stop outputting in the middle. Specifically this is with a multi-keystroke type of macro, like: 

[K("x"), K("y"), K("z"), K("Space"), K("x"), K("y"), K("z"), K("Enter")],

Ordinarily I would expect this to output: 

xyz xyz
xyz xyz
xyz xyz
xyz xyz

With one line for each time I trigger the shortcut.

But what often happens, even if I wait a second between each trigger of the shortcut, is things like this: 

xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xxyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xx
xyz xyz
xyz xyz
xyz xyz
xyz xyz
xxyz xyz
xyz xyz
xyz xyz
xyz xyz
xyxyz xyz
xyz xyz
xyz xyz
xyzxyz xyz
xyz xyz
xy
xyz xyz
xyz xyz
xyz xyz

I thought maybe the more keys in the macro, the more likely one of these hiccups will happen. But it actually often seems to happen right near the beginning of the macro sequence, if it's going to happen at all. Notice how there are a number of lines where the macro stopped after the first, second or third character, but really no lines that stop near the end.

Is there any way to tighten up the code to keep this from happening? Seems like the function responsible just develops a poor working memory at times. Or a buffer is getting overwhelmed with keystrokes coming in too fast? Maybe the keystrokes need a few milliseconds of delay before the next one?

I don't know, I'm just throwing out ideas here.

@mooz @Lenbok @rbreaves

joshgoebel commented 2 years ago

Maybe the keystrokes need a few milliseconds of delay before the next one?

It would be something if you could actually confirm that hypothesis... the code you're looking for is in transform.py#handle_commands... you want the for command in commands loop which is sending the array of "commands" to the output... it'd be easy to add a delay there.

Otherwise that sounds very strange behavior indeed.

RedBearAK commented 2 years ago

@joshgoebel

I've tried putting many instances of sleep(1) throughout that loop in handle_commmands. Other than the fact that I have to do a second import time to keep from producing a crash when I start xkeysnail, the sleep lines seem to have no effect on how a macro gets sent to an application. The fact that there is a crash when I get the syntax wrong means I'm editing the right file, but nothing I do changes the speed of the macro.

/usr/local/lib/python3.10/dist-packages/xkeysnail/transform.py is the file I'm editing.

I use this somewhat lengthy macro in Firefox to test: 

define_keymap(re.compile("Firefox", re.IGNORECASE),{
    K("C-comma"): [
        K("C-T"),K("a"),K("b"),K("o"),K("u"),K("t"),
        K("Shift-SEMICOLON"),K("p"),K("r"),K("e"),K("f"),
        K("e"),K("r"),K("e"),K("n"),K("c"),K("e"),K("s"),K("Enter")
    ],
})

When this works it seems to type at about the speed of someone typing at maybe 500 wpm. But it only works properly about 50% of the time.

joshgoebel commented 2 years ago

And what does the console say... does it log all the keys there despite them not seeming to get all the way to Firefox?

the sleep lines seem to have no effect on how a macro gets sent to an application.

Can you show me where exactly you're adding the delays?

joshgoebel commented 2 years ago

Other than the fact that I have to do a second import time to keep from producing a crash when I start xkeysnail

Do you have an isuse for that? That sounds strange - perhaps something is weird with your system... I'd try to figure out the simpel things first before delving into key delay issues. :)

RedBearAK commented 2 years ago

@joshgoebel

The crash was probably down to some misuse of python syntax, like using sleep instead of time.sleep.

I've seen the same results on multiple different computers and multiple unrelated Linux distros over the course of the last couple of years. I don't think it has anything to do with my system.

Do you not have any issues with macros at all? Or have you not run the kind of test I ran that started this thread?

If you can do the same sort of test with perfect results 100% of the time, then maybe this is actually a problem with the specific config from Kinto.sh or the patched branch of xkeysnail that Kinto.sh uses to support "held keys" combos like Alt+Tab-Tab-Tab...

The view in the terminal when I remove --quiet is just showing the key combo I'm using, such as RC-Comma. I don't know how to see what xkeysnail is actually trying to send to the application.

As for where I tried to put the sleep(1) lines, I put one right after every line in handle_commands with a colon at the end of the line. All the if/elif lines inside the for loop. None of them seemed to have any effect on anything.

joshgoebel commented 2 years ago

Do you not have any issues with macros at all? Or have you not run the kind of test I ran that started this thread?

I'm new here. Haven't used the software much trying to decide if it's right for me and if I want to step up as part of a new small team to fork and continue development, respond and fix issues like these, etc. :-)

the patched branch of xkeysnail that Kinto.sh uses

Possibly but his changes to output have more to do with modifier states than plain keys... actually the plain key stuff is pretty boring which is why these glitches are surprising to me.

I don't know how to see what xkeysnail is actually trying to send to the application.

Ah, you're right... i was thinking of poiting you d7901ecf but that's only logging in the transform, what you want is some logging in the output.

using sleep instead of time.sleep.

Yeah it's time.sleep... and you'd need to import time of course...

I put one right after every line in handle_commands

That'd be hard to miss but you only really need one at the top of the main loop:

for command in command_list:
  # add a delay

But see my next message about adding this to output itself, I think that'd be better.

joshgoebel commented 2 years ago

I don't know how to see what xkeysnail is actually trying to send to the application.

You'd want to add logging to send_key_action and send_combo, just a print at the top to print the argument should be sufficient to give you some workable output... if you see the output on the console but the keystrokes aren't coming thru then something most be gummed up in uinput... perhaps adding a small delay there... since all output goes thru send_sync() perhaps try:

def send_sync():
    _uinput.syn()
    time.sleep(0.1)

You shouldn't need anything crazy like sleeping for a whole second.

joshgoebel commented 2 years ago

@rbreaves Have you heard of any similar bug reports?

joshgoebel commented 2 years ago

https://stackoverflow.com/questions/70324709/uinput-seems-to-break-while-sending-inputs-in-quick-succession

This seems super relevant... (though no answer), but it's the same problem you're describing... So perhaps even a 25 ms sleep in sync would help.

output.py

def send_sync():
    _uinput.syn()
    time.sleep(25/1000) # sleep 25ms

That would kind of suck for typing out long macros though if true... maybe play with a delay before or after sync and if it makes a difference...

joshgoebel commented 2 years ago

I use this somewhat lengthy macro in Firefox to test:

I just ran this 20-30 times in rapid succession doing:

Every once in a blue moon Firefox would lag on the input a hair, but it worked every time, 100% consistently. I definitely think you're experience some type of edge case that not everyone is running into.

Note: This using 0.4.0/master... if you think the problem is the kinto version you'd need to test on the mainline version to confirm whether the issue persists or not. Should be easy to rule kinto in or out as the source of the trouble with that one test.

RedBearAK commented 2 years ago

@joshgoebel

Of course I know just enough about how a for loop works that I put a sleep line right at the beginning of the loop. The use of one second was just because smaller values seemed to have no effect. I like to make things blindingly obvious when I'm troubleshooting. 

def send_sync():
    _uinput.syn()
    time.sleep(25/1000) # sleep 25ms

Alright, so I found this in output.py, and wow, that's something to be really careful with. Finally had an effect, at least. But 25ms is quite a long delay, and it puts that delay between every key press or combo you type. EVERY key press. So 25ms delay before Alt+Tab switches to another app, etc.

BTW, had to do another import time in that file above the def send_sync to avoid an error when trying this.

I shortened it down to 5ms (5/1000) and that's short enough to not interfere much with regular typing and shortcuts, but it definitely still has a strong effect on how quickly the macro gets entered.

And, even that very short delay seems to make the macro a lot more reliable for me. I just did the Firefox prefs shortcut like 30 times in a row without a failure. There are the usual variations in how fast it seems to happen, even appearing to enter all the text almost instantaneously at times, while other times it's slow enough to look like someone "typing" really fast. But it worked 100% of the time for as long as I had the patience to test it.

If I do it so fast that another tab opens before the first is finished, the full text will now always be there in the URL bar but sometimes it apparently loses keyboard focus at the point where it would have sent the Enter key to finish the macro, so the tab is just sitting there with about:preferences in the URL bar, but a blank window and the generic "New Tab" Firefox icon instead of the Preferences gear icon. Obviously this is not a normal thing the user would do.

Now to tune the delay. I'm kind of surprised that such a short delay is already effective. The 25ms that the person was talking about in the link about uinput is almost an order of magnitude longer delay. That would indicate a rather severe problem with uinput receiving mouse clicks.

I still would like to understand why none of my attempts to insert a delay in the for loop amounted to anything. Don't understand that at all.

...

Still working with as little as 1ms as a value. Still seeing an extraordinary amount of variability in terms of how fast the macro actually seems to get sent to the app. Sometimes too fast to see anything, as if the full text was just pasted all at once. Other times, almost as slow as my fastest typing speed on a good day. Very visibly "typing" each individual letter slowly enough for me to watch it.

But, it's still succeeding at actually completing the entire macro without errors or missing characters, even after doing about 50 preferences tabs. Even when it acts much more slowly on occasion.

I think maybe the variability is simply down to the reliance on the system sleep command, which isn't real-time accurate in any way, from what I understand. And it looks like 1ms is actually the minimum possible value that would be meaningful.

It looks like my supposition that some kind of input buffer was failing must be correct, in a way. The question is what, and where.

I've even had a lowlatency kernel installed on Ubuntu for a while now, just for kicks. It appeared to have no effect on this issue.

joshgoebel commented 2 years ago

The use of one second was just because smaller values seemed to have no effect.

Yeah I understand, just with 1 second you're starting to get into the area where the delay could cause it's own kind of problems is all. :-)

Still working with as little as 1ms as a value.

Unfortunately I don't know what to tell you - or where we'd go from here... I don't think adding a 1ms sleep here when no one else is reporting any issues is the correct solution, but I'm also not sure exactly how we'd go about gathering additional data.

Still seeing an extraordinary amount of variability in terms of how fast the macro actually seems to get sent to the app.

That seems strange to me since all that is happening on the Python side is a tight loop and a tiny amount of I/O... I saw some variability but I'd assume it was the Firefox UI, not xkeysnail.

It looks like my supposition that some kind of input buffer was failing must be correct,

You'd think... but we're talking a buffer with almost 0 capacity? Since it short circuits right away in so many of your tests it would seem the buffer is almost non-existant, which is weird.

joshgoebel commented 2 years ago

It looks like time.sleep() only has millisecond resolution. Though it could range between a few milliseconds to over 20 milliseconds (best case scenarios), based on what OS you are using, it does not look like you will get accurate microsecond sleep execution from it.

https://stackoverflow.com/questions/58553072/how-to-make-a-delay-at-100-200us

Could by Python itself that's the issue as evidentally this isn't what sleep was designed to do...

joshgoebel commented 2 years ago

https://github.com/torvalds/linux/blob/master/drivers/input/misc/uinput.c

Looks like uinput doesn't change that much and the buffer size is 16... 16 events I'm assuming...

RedBearAK commented 2 years ago

@joshgoebel

Yeah I understand, just with 1 second you're starting to get into the area where the delay could cause it's own kind of problems is all. :-)

Hey, when you're not catching any fish the usual way, a round stick of material capable of rapidly oxidizing after ignition can come in handy. 🤘

Unfortunately I don't know what to tell you - or where we'd go from here... I don't think adding a 1ms sleep here when no one else is reporting any issues is the correct solution, but I'm also not sure exactly how we'd go about gathering additional data.

I find it very strange that nobody else has seemingly ever had this issue. I would attribute that to most users simply not using macros much, and an even smaller percentage attempting to use long macros with a higher probability of failing. Unless it really is somehow the Kinto branch that has this issue, but in that case I would expect other Kinto users to complain, especially about the Firefox preferences shortcut. But it's not even limited to Firefox, I had a similar issue with Chrome at times when I tried to use a similar macro to get to settings. And of course the testing in the text editor from the first post.

I don't see adding a 1ms delay to be harmful, but that's just my perspective. The question is why does such a ridiculously short delay, apparently the absolute minimum possible with time.sleep, seem to completely fix this. I literally haven't been able to get macros to fail since this change. I just did 100 lines of this text with a macro in the new GNOME Text Editor app, with no failures: 

now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
...

There is a significant delay when I try to hit the shortcut multiple times, but when the entire buffered output (could be many lines, nothing shows up as long as I keep tapping the shortcut too quickly) finally shows up in the app, there are never any errors. No missing Enter at the end of line, no incomplete lines. Nothing. Works perfectly. (Well, see below.)

I just held Ctrl+Shift+Alt and "buzzed" the "t" as fast as I could, to do this macro. Nothing shows up for at least 5 seconds, then I get 25 new perfect lines of the same text. No problems other than the delayed output.

I can't even pretend to understand exactly what is failing without the delay. The buffered macro lines I'm inserting into the text editor are obviously WAY more than 16 characters, yet they never have errors. So the uinput buffer would not appear to be the problem... unless it really doesn't like receiving characters too fast, maybe?

I need the patched 0.3.0 xkeysnail to make things like Alt+Grave and Alt+Tab work correctly, so I'm not sure how to safely test the 0.4.0 branch, but I might do it sometime. I really would like to get this permanently solved.

Uh oh, looks like I was too optimistic. I finally got a couple of lines to show up in the text editor with missing characters. Haven't changed anything since previous testing. 

now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of tntry.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of theountry.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.
now is the time for all good men to come to the aid of their country.

This is doing it slowly, letting each line appear before trying to do it again.

Interesting that these failures are near the end, where testing in the first post almost exclusively saw failures near the beginning of the macro.

Doing dozens more lines in the same way results in no other errors.

I don't know what to tell me either.

joshgoebel commented 2 years ago

I find it very strange that nobody else has seemingly ever had this issue.

Well so far that's the data... and for absolute empirical reported data we have only our individual experiences... mine is rock solid with no delay added... so that paired with no other reports make me think you're the outlier - though your points about not everyone using long macros is definitely worthy of note.

The buffered macro lines I'm inserting into the text editor are obviously WAY more than 16 characters, yet they never have errors. So the uinput buffer would not appear to be the problem...

You lost me here... I thought you were saying it was working so well only AFTER you had applied the delay... I'm not sure what data point you're trying to explain in this paragraph.

RedBearAK commented 2 years ago

@joshgoebel

You lost me here... I thought you were saying it was working so well only AFTER you had applied the delay... I'm not sure what data point you're trying to explain in this paragraph.

You said uinput had a buffer of 16. Assumedly, 16 characters? When I trigger the macro shortcut rapidly before the first output appears, nothing appears until I pause for a while. Then the whole thing shows up. Could be hundreds of characters of output that was successfully assembled behind the scenes as I repeatedly tap the main macro key while holding the modifiers. And it pops into place in the app almost instantly.

So, somehow something is holding onto all those characters in memory and then finally inserting them into the app. A lot more than 16 characters worth. I'm just saying I don't really understand what relationship the small uinput buffer has to the overall issue.

And yes, this is only working with 99% reliability after inserting the delay. Before that it really was about 50/50 as a long term average. Sometimes it seemed to work pretty well, other times it was even worse than usual.

Data point: Happens in Ubuntu 22.04 (and previous iterations going back to 20.04 on the same machine). Also happens inside a VM running KDE Neon, where Kinto/xkeysnail is disabled on the Ubuntu host while using GNOME Boxes, and Kinto/xkeysnail is installed inside the VM.

joshgoebel commented 2 years ago

You said uinput had a buffer of 16. Assumedly, 16 characters?

No, events. A key press is typically 3 events, the scancode, the key event and then a SYN... our artificial output is usually just two events, but that's 4 events if you're counting key up and key down. So a single letter is often 4-6 input events.

Could be hundreds of characters of output that was successfully assembled

But if this was with the 1ms delay added then you aren't really stressing the buffer much at all since you're giving it time to drain...

Anyways if processes are waiting on keyboard input then putting anything into the buffer should wake those processes up... allowing them to read the keyboard before the buffer fills - that's how it's supposed to work.

joshgoebel commented 2 years ago

I need the patched 0.3.0 xkeysnail to make things like Alt+Grave and Alt+Tab work correctly,

You'd just have to "suffer" with the normal linux keystrokes when testing 0.4.0.... you can do all the same things, you just have to hit the REAL keys linux wants. But I don't really think that's your issue.

RedBearAK commented 2 years ago

@joshgoebel

Data point: 2007 MacBook running recent install of Fedora 36 KDE spin. Core 2 Duo, 6GB mem.

Even without the delay added, inserts output in Firefox relatively slowly. More reliable than the other machine but I was able to get it to fail several times out of about a hundred tries. More frequently as the machine struggled to keep up with so many tab being opened. Most commonly it just wouldn’t hit Enter at the end of the macro, but partial insertions of text also occurred.

Another: Machine almost identical to the main system, but slightly slower CPU (Ryzen 3500u, 4c, 8t) and half the RAM (16GB). Running Fedora 36 (GNOME 42, like Ubuntu 22.04).

No delay added, has a macro error about 5% of around a hundred test tries.

Add the 1ms delay, can’t produce a failure in at least two hundred preferences tabs.

No, events. A key press is typically 3 events, the scancode, the key event and then a SYN... our artificial output is usually just two events, but that's 4 events if you're counting key up and key down. So a single letter is often 4-6 input events.

I see. So just a couple of characters really.

RedBearAK commented 2 years ago

@joshgoebel

Did a sudo pip3 install —upgrade xkeysnail on the Fedora system to get the unpatched 0.4.0 installed.

After opening probably at least two hundred prefs tabs I haven’t had a single failure. Just the usual momentary delays at times when the machine can’t quite dedicate enough cycles to the xkeysnail process (as I open ridiculous numbers of new tabs each minute without bothering to close any). But no actual failure to complete the macro.

So something related to the Kinto patch?

RedBearAK commented 2 years ago

@joshgoebel

Thanks for all the input, by the way. At least it led to finding a 99% reliable mitigation solution. A vast improvement for my daily driver system.

joshgoebel commented 2 years ago

something related to the Kinto patch?

You'd think that if you can jump back and forth between "have problems" and "zero problems" just by using kinto or mainline... but damn it's hard to say where... they honestly aren't THAT different...

Ideas:

RedBearAK commented 2 years ago

@joshgoebel

No, adding those lines from the commit and removing the delay line results in nothing good. Back to frequent partial failures of the Firefox macro.

As always, I don't really know how to implement the logging commands. I tried print() on every other line but of course that just produced blank lines.

Ah, things like print(key) and print(action) produce... a lot. But I'm not actually sure what kind of "output differences" you're referring to. Like, between when a macro works and when it doesn't? That's a lot of lines of output in the terminal, unless I can figure out how to keep everything from coming out on a new line.

RedBearAK commented 2 years ago

@joshgoebel

Did some reformatting of the output. Still trying to figure out which parts are truly irrelevant and can be left out.

This feels kind of odd. I'm seeing two release events every time I press and release Right Ctrl, Left Ctrl, or Alt, but only one release event for Shift. Is that normal for mainline xkeysnail? 

Watching keyboard devices plug in
=================================================================================================
send_key_action:key Key.LEFT_SHIFT                  send_key_action:action Action.PRESS
update_modifier_key_pressed:key Key.LEFT_SHIFT      update_modifier_key_pressed:action Action.PRESS
update_pressed_keys:key Key.LEFT_SHIFT              update_pressed_keys:action Action.PRESS

=================================================================================================
send_key_action:key Key.LEFT_SHIFT                  send_key_action:action Action.RELEASE
update_modifier_key_pressed:key Key.LEFT_SHIFT      update_modifier_key_pressed:action Action.RELEASE
update_pressed_keys:key Key.LEFT_SHIFT              update_pressed_keys:action Action.RELEASE

=================================================================================================
send_key_action:key Key.LEFT_CTRL                  send_key_action:action Action.PRESS
update_modifier_key_pressed:key Key.LEFT_CTRL      update_modifier_key_pressed:action Action.PRESS
update_pressed_keys:key Key.LEFT_CTRL              update_pressed_keys:action Action.PRESS

=================================================================================================
send_key_action:key Key.LEFT_CTRL                  send_key_action:action Action.RELEASE
update_modifier_key_pressed:key Key.LEFT_CTRL      update_modifier_key_pressed:action Action.RELEASE
update_pressed_keys:key Key.LEFT_CTRL              update_pressed_keys:action Action.RELEASE

=================================================================================================
send_key_action:key Key.LEFT_CTRL                  send_key_action:action Action.RELEASE
update_modifier_key_pressed:key Key.LEFT_CTRL      update_modifier_key_pressed:action Action.RELEASE
update_pressed_keys:key Key.LEFT_CTRL              update_pressed_keys:action Action.RELEASE

=================================================================================================
send_key_action:key Key.LEFT_ALT                  send_key_action:action Action.PRESS
update_modifier_key_pressed:key Key.LEFT_ALT      update_modifier_key_pressed:action Action.PRESS
update_pressed_keys:key Key.LEFT_ALT              update_pressed_keys:action Action.PRESS

=================================================================================================
send_key_action:key Key.LEFT_ALT                  send_key_action:action Action.RELEASE
update_modifier_key_pressed:key Key.LEFT_ALT      update_modifier_key_pressed:action Action.RELEASE
update_pressed_keys:key Key.LEFT_ALT              update_pressed_keys:action Action.RELEASE

=================================================================================================
send_key_action:key Key.LEFT_ALT                  send_key_action:action Action.RELEASE
update_modifier_key_pressed:key Key.LEFT_ALT      update_modifier_key_pressed:action Action.RELEASE
update_pressed_keys:key Key.LEFT_ALT              update_pressed_keys:action Action.RELEASE

=================================================================================================
send_key_action:key Key.RIGHT_CTRL                  send_key_action:action Action.PRESS
update_modifier_key_pressed:key Key.RIGHT_CTRL      update_modifier_key_pressed:action Action.PRESS
update_pressed_keys:key Key.RIGHT_CTRL              update_pressed_keys:action Action.PRESS

=================================================================================================
send_key_action:key Key.RIGHT_CTRL                  send_key_action:action Action.RELEASE
update_modifier_key_pressed:key Key.RIGHT_CTRL      update_modifier_key_pressed:action Action.RELEASE
update_pressed_keys:key Key.RIGHT_CTRL              update_pressed_keys:action Action.RELEASE

=================================================================================================
send_key_action:key Key.RIGHT_CTRL                  send_key_action:action Action.RELEASE
update_modifier_key_pressed:key Key.RIGHT_CTRL      update_modifier_key_pressed:action Action.RELEASE
update_pressed_keys:key Key.RIGHT_CTRL              update_pressed_keys:action Action.RELEASE
RedBearAK commented 2 years ago

@joshgoebel

Wonder if this has anything to do with anything.

I see a ton of press/release events for RIGHT_CTRL during the whole macro, even if I make a point of hitting Ctrl+Comma and releasing the Ctrl key as quickly as possible. 

Watching keyboard devices plug in
Key.RIGHT_CTRL             Action.PRESS       #####      
WM_CLASS 'firefox' | active keymaps = [Anonymous keymap, General Web Browsers, Anonymous keymap, General GUI, Wordwise - not vscode]
RC-COMMA
Key.T             Action.PRESS       #####      
Key.T             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.A             Action.PRESS       #####      
Key.A             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.B             Action.PRESS       #####      
Key.B             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.O             Action.PRESS       #####      
Key.O             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.U             Action.PRESS       #####      
Key.U             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.T             Action.PRESS       #####      
Key.T             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.SEMICOLON             Action.PRESS       #####      
Key.SEMICOLON             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.P             Action.PRESS       #####      
Key.P             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.R             Action.PRESS       #####      
Key.R             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.E             Action.PRESS       #####      
Key.E             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.F             Action.PRESS       #####      
Key.F             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.E             Action.PRESS       #####      
Key.E             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.R             Action.PRESS       #####      
Key.R             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.E             Action.PRESS       #####      
Key.E             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.N             Action.PRESS       #####      
Key.N             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.C             Action.PRESS       #####      
Key.C             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.E             Action.PRESS       #####      
Key.E             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.S             Action.PRESS       #####      
Key.S             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.ENTER             Action.PRESS       #####      
Key.ENTER             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.PRESS       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.RELEASE       #####      
Key.LEFT_SHIFT             Action.RELEASE       #####      
Key.RIGHT_CTRL             Action.PRESS       #####

Without the delay there was quickly a failure in Firefox, but I can't see any corresponding failure in this log output. It seems to always show the full macro in the terminal even if it didn't actually work in the application.

joshgoebel commented 2 years ago

It seems to always show the full macro in the terminal even if it didn't actually work in the application.

Expected.

I see a ton of press/release events for RIGHT_CTRL during the whole macro,

Yep, you've found it. And look at shift also... this would seem to be a bug/flaw in the design of how Kinto's handling keystate and how it wants to persist the modifiers until the full combo ends - shift getting "stuck" half on/off is definitely a bug. The buffer just can't handle all that [unnecessary] data being thrown at it so very fast. If you added more modifiers (right shift, alt) I'd imagine you'd see things get progressively worse and worse.

@rbreaves

This might point out an overall flaw in the overall engine as well... that holding and reasserting the original "real" input state should perhaps be handled differently across large sequences of combos/keys:

joshgoebel commented 2 years ago

Even then I wonder if we might find that in SOME legit edge cases one could kill the buffer in NORMAL usage and that we might need to build in a throttle so that if we detect we're pushing too much data we handle flow control ourselves.

@RedBearAK Your welcome - and thanks for putting in the time to do the testing, it was great to just toss you ideas and then you come back with test results. I've learned a lot here about the underlying engine and input processing.

joshgoebel commented 2 years ago

@RedBearAK You might have better luck with a throttle.... so have a global counter, and you count the writes to uinput... when you get close to the buffer size, you add a LONGER delay (now we can afford more time because we're doing it less often)... then reset the counter. This is a stop gap solution though - really the engine needs to just not send all the raise/press keystrokes.

joshgoebel commented 2 years ago

I was having issues that reminded me of this... the Cmd-, for preferences was inconsistently working in Chrome... but it seems the problem is that Chrome is too slow... The ALT-E happens, then IF the s enter happens a fraction of a second before the menu opens you can submit a search or have some other weird behavior and then menu just hangs open.

Often it's fast enough, but not always. I wonder if we might always need a small delay between long sequences of keystrokes...

This is kind of a problem with feeding input to apps when we have no idea if they are truly ready for that input or not.

RedBearAK commented 2 years ago

@joshgoebel

This is kind of a problem with feeding input to apps when we have no idea if they are truly ready for that input or not.

That is definitely an issue, not knowing if you're going to be typing in the right place.

preferences was inconsistently working in Chrome

I had that very same trouble with Chrome, and only on one machine if I remember right. Other machines would seem to work perfectly with that same macro. I'll bet it was the same laptop that gave me so much trouble with macros in general.

I remember that I changed the Chrome prefs macro to be more like the Firefox prefs macro. In other words I made it open a new tab and type "chrome://settings" instead of trying to use the quicker keyboard shortcut. It seemed to work a lot better for me. Now I realize that was probably just because it took a fraction of a second longer to operate.

Most likely with the artificial sleep delay I have on that machine now, even the original Chrome prefs macro would work reliably.

Between cutting out some of the redundant key press events and adding the 1ms delay in the output loop, this issue could probably be solved in 99.99% of cases.

joshgoebel commented 2 years ago

Most likely with the artificial sleep delay I have on that machine now, even the original Chrome prefs macro would work reliably.

I forget how much delay you're using but I first tried a generic 1ms delay after ever command and that didn't fix it, that's when I just made a PR to add the 10ms delay in the config itself.

joshgoebel commented 2 years ago

Although your delay is per key, so that's entirely different I suppose.

RedBearAK commented 2 years ago

@joshgoebel

Although your delay is per key, so that's entirely different I suppose.

That's the only one that ever had an actual observable effect for me.

And I just had a thought that it could be even more effective if the sleep came first, instead of last. That way there's a tiny delay even before the very first event. 

def send_sync():
    time.sleep(1/1000) # sleep 1ms
    _uinput.syn()
joshgoebel commented 2 years ago

You wouldn't need a delay before the first event... that's the safest one, empty buffer.

RedBearAK commented 2 years ago

empty buffer

I was thinking more that it would give the receiving window another fraction of a second to be ready to receive input, but of course for the very first event the window wouldn't have received the shortcut yet to even trigger a new tab or something, so yeah. Silly idea.

joshgoebel commented 2 years ago

When it breaks I can see the events with evtest but not with xinput

I just noticed this (or for some reason it just clicked)... if the events make it to evdev then the problem isn't the uinput, it's higher up... can you test your broken setup again but (while also breaking it in the UI) have evtest running pointed at the virtal output device? py-evdev-uinput

If evtest shows the events but they don't make it thru this it's a higher-level issue like libinput or something.

RedBearAK commented 2 years ago

@joshgoebel

If evtest shows the events but they don't make it thru this it's a higher-level issue like libinput or something.

OK, I removed the sleep from output.py and did the test with evtest pointing at that device. I managed to get two FF preferences macro failures pretty quickly and each time I saw the full "about[Shift][Semicolon]preferences[Enter]" events reflected in the evtest output. No apparent interruption of the event sequence. Along with all the excessive RIGHTCTRL and LEFTSHIFT events. In one of the failures only "ab" made it into the URL bar. On the other it performed a web search for "abou" or something to that effect.

This is with the Kinto branch, as always.

joshgoebel commented 2 years ago

saw the full "about[Shift][Semicolon]preferences[Enter]" events reflected in the evtest output.

Could you run xev now and confirm they are missing from there (as the poster on Stack Overflow indicates it is for them)? If so perhaps then we raise this with the libinput people and see if they have any thoughts/suggests? They've been helpful in the past.

https://gitlab.freedesktop.org/libinput/libinput/

RedBearAK commented 2 years ago

@joshgoebel

I'm not immediately seeing exactly how to interpret this output. It seems much less chatty about individual key press events. I'll have to spend some time looking at it, but maybe you have better eyes. This is the full output of a run with sleep removed and a macro failure near the end that ended up doing a web search for "aces". LOL. That's an unusual one.

Actually this seems to be more talking about window/focus events, which might have been relevant to the poster having issues with clicks. Not so much missing keystrokes.

xev-output.txt

Yeah, I did xev -event keyboard and after messing around in FF for a while there's still only one keyboard event shown in the terminal. Don't think this is quite the right tool for catching what's going on with libinput, if that is where the problem lies.

joshgoebel commented 2 years ago

Oh sorry xev probably needs the focus when you run the macro, so you might have to tweak your config to allow that... it only shows events that go to it.

RedBearAK commented 2 years ago

@joshgoebel

Oh sorry xev probably needs the focus when you run the macro, so you might have to tweak your config to allow that... it only shows events that go to it.

Oh, so if I put a macro shortcut in the terminal block and run it while xev is active, all the keystrokes should show? Makes sense. I'll give that a try when I get a chance.

joshgoebel commented 2 years ago

Oh, so if I put a macro shortcut in the terminal block and run it while xev is active,

No, I think you need to do it on top of the xev window... so xprop it and make a macro just for it... then trigger the macro there... and we're wanting to see if xev drops the ball... in which case I think we can go to the libinput people.

RedBearAK commented 2 years ago

No, I think you need to do it on top of the xev window... so xprop it and make a macro just for it... then trigger the macro there... and we're wanting to see if xev drops the ball... in which case I think we can go to the libinput people.

Oh, the little window itself. Sure. Makes even more sense.

RedBearAK commented 2 years ago

@joshgoebel

Well, this is extremely contrived in order to get something human readable from the extensive output, but: 

Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisi.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
TSamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisao.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.

The xev window doesn't have a WM_CLASS attribute, so I had to go with a macro in the "general" block which will work even with windows without a WM_CLASS.

Saw the same kind of pattern of incomplete lines whether I held the modifier keys the whole time, or did each shortcut individually. 

    K("RC-Shift-Alt-t"):    [K("Shift-t"),K("h"),K("i"),K("s"),K("Space"),K("i"),K("s"),K("Space"),K("a"),K("Space"),K("m"),K("a"),K("c"),K("r"),K("o"),K("dot"),K("Space")],

The spaces were sedded out during the trimming process. Each character was originally on a separate line as part of the general output. 

xev -event keyboard | grep -i xmblookup | grep -v "gives 0 bytes" | sed ':a;N;$!ba;s/\n//g' | sed -e 's/XmbLookupString gives 1 bytes://g' | sed -e 's/     //g' | sed -e 's/(..)//g' | sed -e 's/"//g' | sed -e 's/ //g' | sed 's/T/\'$'\nT/g'

But... before doing all the filtering for readability I was unable to distinguish any instance of incomplete macros when everything was vertical. The output in the terminal window was strangely inconsistent, but whenever I would quit the xev window it would all end up looking complete in the terminal. I don't know what that means.

Of course, early on in the filtering it's grepping only for the "XmbLookup" lines, which seemed most relevant. There are other "XLookup" lines that are not in this output.

Without the filtering the output from even a single instance of the macro is quite extensive and difficult to sort through visually.

RedBearAK commented 2 years ago

@joshgoebel

There's the capital "S" in the output above, and then this capital "O":

Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Tmacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
ThisO.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisa.
Thisisamacro.
Thisisamacro.
Thismacro.
Thisisamacro.
Thisisamacro.

I find that very peculiar. Neither of those letters should be capitalized, and the "O" is separated from the capital "T" by multiple letters in between, yet somehow it got capitalized also.

RedBearAK commented 2 years ago

@joshgoebel

Just to be thorough (25 macros in each run) I put the sleep line back, and of course this is the predictable result: 

Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
Thisisamacro.
joshgoebel commented 2 years ago

Ok, so if I'm reading this right xev also has the input issue... lets file an issue with libinput and see what they say then... I'd reference this issue as well as the stack overflow report...

RedBearAK commented 2 years ago

@joshgoebel

I'm not even sure how to describe the issue, or how it relates to libinput. Any suggestions? I'm sure you'd have much better luck using terminology they might understand.

RedBearAK commented 2 years ago

@joshgoebel

And didn't we already figure out that this problem is basically nonexistent outside of the Kinto branch of xkeysnail? Maybe the Kinto branch is just using libinput wrong or breaking internally somehow.