wxasync icon indicating copy to clipboard operation
wxasync copied to clipboard

Sluggishness while using a screenreader (NVDA)

Open vincent-lg opened this issue 3 years ago • 17 comments

Hi,

I'm grateful for your work. Allowing async/await in wxPython is great.

Unfortunately, while testing, I find a pretty strange sluggishness which I'm unable to explain. Is it because I'm running on Windows? Or because I'm using only the keyboard (as a screen reader users)? Keyboard events would generate and I can understand, for every key I press, four or five events could be sent... actually more than that. Still, that doesn't sound like a lot of event. Yet, I find a performance of about 200ms each time I press a key, enough to be perceptible. I've simplified your example to a very simple window with only three widgets (two list boxes and one text entry). You can see the problem when typing quickly in the text area, or when changing from widget to widget using the tab key (not the mouse).

import wx
import time

from wxasync import AsyncBind, WxAsyncApp, StartCoroutine
import asyncio
from asyncio.events import get_event_loop

ASYNC_VERSION = True

class BasicFrame(wx.Frame):
    def __init__(self, parent=None, id=-1, title=""):
        wx.Frame.__init__(self, parent, id, title, size=(800,800))
        self.wx_panel = wx.Panel(self)
        self.wx_sizer = wx.BoxSizer(wx.VERTICAL)
        self.left = wx.ListBox(self.wx_panel, name="list1")
        self.wx_sizer.Add(self.left)
        self.right = wx.ListBox(self.wx_panel, name="list2")
        self.wx_sizer.Add(self.right)
        self.text = wx.TextCtrl(self.wx_panel, name="Username")
        self.wx_sizer.Add(self.text)
        self.wx_panel.SetSizerAndFit(self.wx_sizer)

        # Fills the lists
        self.left.Append("One")
        self.left.Append("Two")
        self.left.Append("Three")
        self.right.Append("First")
        self.right.Append("Second")

def main():
    class MyApp(wx.App):

        def OnInit(self):
            frame = BasicFrame(title="test")
            frame.Show(True)
            self.SetTopWindow(frame)

            return True

    app = MyApp(0)
    app.MainLoop()
    # del app

def main_async():
    # see https://github.com/sirk390/wxasync
    app = WxAsyncApp()
    frame = BasicFrame(title="test")
    frame.Show(True)
    app.SetTopWindow(frame)
    loop = get_event_loop()
    loop.run_until_complete(app.MainLoop())

if __name__ == "__main__":
    if ASYNC_VERSION:
        main_async()
    else:
        main()

What's causing this delay? I'm not sure. Obviously, if decreasing asyncio.sleep in the main loop to something smaller, this lag decreases and slowly (incredibly slowly) disappears if a small value is set. But then the problem of a small value is the CPU goes up and up to compensate. Lots of overhead. So I was puzzling over this problem and I still don't find a solution. Obviously, it would be helpful if the loop could instead send its events to be processed to an asynchronous loop, for instance. The coroutine responsible for reading the loop would just block until an event is available. But we're still dealing with the same problem: wxPython and another event loop don't get along so well, except if you don't mind the CPU overhead.

But from seeing the code I can't decide what's causing the delay in particular. 5ms for a sleep is definitely not huge. Again, a key press (particularly the tab key which encourages to switch between widgets, hence triggering lots of events) might fire tens of events... but that's still not enough, in theory, to be perceptible by the user. Any help on this would be appreciated!

Thanks in advance,

Vincent

vincent-lg avatar Sep 19 '20 12:09 vincent-lg

Hi Vincent,

Thanks for reporting this. I tried it on my computer (windows also) and I don't see a difference between the async and non-async even with keyboard. Would it be caused by the screen reader? Could you measure the time spent in "evtloop.Pending()" "evtloop.Dispatch()" , the "while loop", "self.ProcessPendingEvents()" and "evtloop.ProcessIdle()" ? Just by adding some prints, it would be possible to see which part is causing the delay.

Christian

sirk390 avatar Sep 19 '20 13:09 sirk390

I don't think the delay is caused by the screen reader. But I do allow, it's kind of hard to see and probably depends on the machine. My machine isn't slow, but it might be slower than yours.

I will run the performance tests on this, to try and see what is causing the delay. I'll post it quickly, depending on the time I have this weekend.

Thanks,

vincent-lg avatar Sep 19 '20 13:09 vincent-lg

I have a fast machine but it shouldn't change it so much. It might take some time in the Dispatch? This is the slowest on my side. See my results: idle 0.0000038 s pending 0.0001031 s dispatch 0.0016159 s while 0.0021363 s process-pending 0.0 s idle 0.0000042 s

sirk390 avatar Sep 19 '20 13:09 sirk390

I've run a lot of testing with no great success. At first glance, the call to self.Dispatch in the event loop could freeze for a long time. But while replacing it with Dispatchtimeout like for Mac OS, I didn't notice any different. And if I diminish asyncio.sleep from 0.005 to 0.000001, I see no difference in the lag. I have to specify 0 altogether. And when I do so, obviously, the CPU overloads after a bit.

So I must assume something is definitely wrong with my approach. I'm still not sure what's causing the delay and you might be right, it might be Dispatch, but we don't really have a way to shorten it, do we? I was looking into placing WX events into an asynchronous queue, and having an async call waiting for this queue and processing events only when they arrive to relieve my CPU without needing to pause, but so far I've been unable to code it. I'll try again, just not sure if I can manage it.

So feel free to close this issue. However if you do have ideas about the reason for the delay, even though it's mostly perceptible with a screen reader, I'll appreciate the thought.

Have a good Sunday,

vincent-lg avatar Sep 20 '20 11:09 vincent-lg

I tried on my laptop and didn't see the issue. I would need an easy way to reproduce it or some details on the function that is slowed down. Any idea how many times per second you call the MainLoop's code?

sirk390 avatar Sep 20 '20 12:09 sirk390

This isn't just a Windows issue, it happens on Linux as well. The root cause is BaseEventLoop.Dispatch blocking at times for a somewhat random amount (100-1000 ms). This then causes a delay in resuming runnable coroutines.

As a workaround using DispatchTimeout(1) (DispatchTimeout(0) does not work on Linux and never processes any events) instead of Dispatch() in the main loop works. Alternatively, as a downstream application adding a wx.Timer that fires an event every 5-30 ms or so also works. I can send a PR for this if you want.

When using background threads and then using asyncio.Futures to communicate between background threads and UI coroutines: Something that may seem like it fixes the issue but doesn't is to use wx.CallAfter instead of call_soon_threadsafe to call Future.set_result from the thread it belongs to. The reason it sort of appears to fix the problem is because CallAfter sends an event, so guarantees the event loop will wake-up. But it actually doesn't fix the problem, it's just slightly rarer, because Dispatch() may still block for some time, so control does not return to asyncio to resume the coroutine(s).

This would be very easy to fix if asyncio would expose a run_once function as part of the event loop interface, which it doesn't. (Most asyncio event loops do have that as a private method though).

enkore avatar Nov 16 '20 11:11 enkore

DispatchTimeout(1) doesn't actually fix it, either. Less frequent, but will still randomly hang for a couple hundred ms inside while evtloop.Pending(): evtloop.DispatchTimeout(1).

enkore avatar Nov 16 '20 16:11 enkore

Do you have any code to reproduce? I just tested on Linux under VMWare and measured evtloop.Pending() + evtloop.Dispatch() loop. The worst I can see is once 30ms at startup. Then, sometimes 4ms, but the average is< 0.3ms.

sirk390 avatar Nov 19 '20 07:11 sirk390

I opened #10 since it seems like a separate problem from what Vincent has described here.

enkore avatar Nov 19 '20 17:11 enkore

I'm fully able to reproduce this. Using the NVDA screen reader on Windows 10 20h2.

It's not my processor either, Intel core I7 7700k at 4.2 GHZ.

TheQuinbox avatar Mar 25 '22 16:03 TheQuinbox

Thanks, are you able to debug and investigate the issue? I think it's related to the screen reader but i can't really buy a a screen reader just to investigate it. Another possibility would be a simulator but i don't know if that's possible

sirk390 avatar Mar 25 '22 16:03 sirk390

@sirk390: NVDA is a free and open-source screen reader, so you can definitely install (or even run it in the portable version without installing it) to identify the issue. HTH,

vincent-lg avatar Mar 25 '22 17:03 vincent-lg

This is a very tricky issue. Adding a "evtloop.DispatchTimeout(10)" before the while loop (the value is in milliseconds) improves it, but it will reduce the performances globally.

I have the impression that "Pending()" returns False, while there are messages. It feels like NVDA is doing some unconventional things, like intercepting the messages and reposting them.

When using GetQueueStatus(QS_ALLEVENTS) instead of Pending , the problem shows up even worse (sometimes hangs for multiple seconds).

We would need to check what NVDA is doing exactly in the source to understand better what is happening.

sirk390 avatar Mar 26 '22 11:03 sirk390

You can always open an issue against github.com/nvaccess/nvda

TheQuinbox avatar Mar 26 '22 13:03 TheQuinbox

I've created these two gifs to capture the slowdown with NVDA although I if you are using a screen reader maybe you will not be able to verify this is the same issue. I see the issue with backspace in the TextCtrl. There is also a small slowdown when typing characters, but I don't see the slowdown when using Tab to switch between controls.

normal: normal

while using NVDA:

with_NVDA

sirk390 avatar Mar 28 '22 10:03 sirk390

I've created this issue here: https://github.com/nvaccess/nvda/issues/13556 to see if I can get some help with investigation

sirk390 avatar Mar 29 '22 07:03 sirk390

To explain the gifs above, I'm seeing this issue mostly when I hit "backspace" and keep it pressed to erase text. It's like 100ms-200ms lag (just a guess). But no big issue with tab or typing letters. Typing is slightly slower.

sirk390 avatar Apr 12 '22 22:04 sirk390