Improve responsiveness of input and focus by pumping immediately instead of after a delay.

[jcsteh]

Link to issue number:

None.

Summary of the issue:

Currently, everything in NVDA, including responding to keyboard input and focus changes, goes through the core pump. The core pump is always run with a slight delay. Assuming nothing else is already queued, any input or focus change will not be processed for a minimum of 10 ms. In reality, it's potentially longer due to the system timer resolution and the fact that timers are low priority messages. We should be aiming for the fastest possible response to user input and focus changes.

Description of user facing changes

NVDA will respond slightly faster to commands and focus changes.

Description of development approach

1. The core pump has been refactored.
   • Rather than using NonReEntrantTimer, it now uses wx.Timer directly and guards re-entry itself for better control.
   • There is a method (queueRequest) which uses wx.CallAfter to execute the request on the main thread if necessary, avoiding recursion. However, if a delayed pump is requested on the main thread, starting the timer will happen there, rather than being queued via the window message.
   • A main thread method triggered by wx.CallAfter (processRequest) manages scheduling/executing the pump to make state management easier.
   • The pump always queues a subsequent request using wx.CallAfter rather than executing it directly to avoid recursion and to ensure that other window messages have a chance to execute.
2. requestPump has a new immediate argument which specifies whether the pump should happen as soon as possible or after the delay. Delayed pumps are still useful in most cases for rate limiting and filtering, so this defaults to False.
3. queueHandler.queueFunction has an _immediate argument which is passed to requestPump. It is _ prefixed to mitigate conflicts with keyword arguments intended for queued functions.
4. inputCore, scriptHandler, focus changes and live text output all request an immediate core pump.
5. As an exception, a gesture can set the private _immediate attribute to False to prevent immediate pumps. This is set on all touch hover gestures to avoid exhausting the window message queue, since hover gestures are queued every pump if there is an active hover.

Testing strategy:

I used "time since input" logging to measure the differences in times before and after the change in various situations:

• Report time (NVDA+f12) and input help took ~10 ms before the patch, ~0 ms after.
• Navigating in the NVDA menu took > 20 ms before the change, ~10 ms after.
• Moving the caret in Firefox took ~35 ms before the change, ~20 ms after.

This can be quite variable, so it's only a rough guide, but the results are pretty suggestive.

I also verified that touch hovering works as expected even when my finger remains in contact with the screen for 30 seconds. I tested that turning on input help and holding down two fingers for 10 seconds doesn't break input help.

Known issues with pull request:

None.

Change log entries:

Bug fixes
NVDA now responds slightly faster to commands and focus changes.

Code Review Checklist:

• Pull Request description:
  • description is up to date
  • change log entries
• Testing:
  • Unit tests
  • System (end to end) tests
  • Manual testing
• API is compatible with existing add-ons.
• Documentation:
  • User Documentation
  • Developer / Technical Documentation
  • Context sensitive help for GUI changes
• UX of all users considered:
  • Speech
  • Braille
  • Low Vision
  • Different web browsers
  • Localization in other languages / culture than English
• Security precautions taken.

[michaelDCurran]

Touch exploration in input help lasts a great deal longer now. However, after between 10 and 30 seconds, or much sooner if you add a second finger, eventually it still ends up producing:

ERROR - extensionPoints.Action.notify (08:02:42.243) - MainThread (8432):
Error running handler <bound method main.<locals>.CorePump.handleWindowMessage of <core.main.<locals>.CorePump object at 0x06D14670>> for <extensionPoints.Action object at 0x043AE2F0>
Traceback (most recent call last):
  File "extensionPoints\__init__.pyc", line 55, in notify
  File "extensionPoints\util.pyc", line 216, in callWithSupportedKwargs
  File "core.pyc", line 745, in handleWindowMessage
  File "core.pyc", line 753, in processRequest
  File "core.pyc", line 788, in Notify
  File "core.pyc", line 741, in queueRequest
  File "winUser.pyc", line 654, in PostMessage
OSError: [WinError 1816] Not enough quota is available to process this command.

The OS already floods our message queue with touch messages. It has probably always been on the edge. I think we should add an attribute to scripts that say if they are immediate or not, setting hover's to false. And then honoring this attribute all places in executeGesture, and in queueScript.

[jcsteh]

This feels like the wrong solution to me and I'm not sure it will fix it completely. We should now only be adding two extra window messages to the queue per tick: one for touch to request a delayed pump and one for the (immediate) script. Furthermore, we should be processing all of the messages each tick, so there shouldn't be a backlog like this. Does touch exploration for more than 10 seconds even work in current alphas?

[jcsteh]

If we do want to go down the path you suggest, I wonder whether it'd be easier to just catch OSError 1816 and change it to a delayed pump if that occurs.

[jcsteh]

The other thing worth noting is that currently, requesting a pump uses a window message even for a delayed pump requested on the main thread. I did that for simplicity, but I could avoid that message for delayed pumps by reinstating the main thread check and just starting the timer inline in that case.

[amirsol81]

@jcsteh @michaelDCurran Considering the obstacles, do you think this PR will be part of NVDA 2023.2?

[jcsteh]

I think we should add an attribute to scripts that say if they are immediate or not, setting hover's to false. And then honoring this attribute all places in executeGesture, and in queueScript.

I've done this now, though I haven't tested it with touch yet. It feels kinda hacky, but I don't have a better solution and I think the gain outweighs the hackiness. I've underscore prefixed the attribute so it's clear it's private and not part of the public API, so we can remove it without breaking the API if we come up with a better solution.

In future, I think we should consider making touchHandler or touchTracker limit these hover actions itself; e.g. by using a timeout like we do for other touch tracker stuff. I think that should be handled separately though, as there are more unknowns there.

[jcsteh]

I've tested with touch and everything seems to work as expected. I updated the PR description accordingly.

[michaelDCurran]

I'm still seeing an OSError in the capter func when doing a multi-finger hover for several seconds. I.e. ts:2finger_hold+hover.
Note that script_hover_explore is only bound to hover, not hover with held fingers. Thus those gestures, when in input help, are still going to queue for logging with as immediate.
I think rather than checking for _immediate on the script, it should be checked for on the gesture. And, TouchInputGesture should expose _immediate as False if self.tracker.action is ACTION_HOVER.

[jcsteh]

Thanks. I was able to reproduce that and have fixed it now. Sorry, I misunderstood how to test the two finger thing; I was adding a second finger while hovering, but not for long enough to trigger the problem. Much easier just to put two fingers on the screen and wait.

[jcsteh]

Asdflksjdflkj. Nope, now seeing OSErrors when hovering for a while.

[AppVeyorBot]

• PASS: Translation comments check.
• PASS: Unit tests.
• PASS: Lint check.
• FAIL: System tests (tags: installer NVDA). See test results for more information.
• Build (for testing PR): https://ci.appveyor.com/api/buildjobs/vmvgl509ydcqjppu/artifacts/output/nvda_snapshot_pr14928-28393,6b6dcb4f.exe
• CI timing (mins):
  INIT 0.0,
  INSTALL_START 0.9,
  INSTALL_END 1.0,
  BUILD_START 0.0,
  BUILD_END 24.3,
  TESTSETUP_START 0.0,
  TESTSETUP_END 0.3,
  TEST_START 0.0,
  TEST_END 19.2,
  FINISH_END 0.1

See test results for failed build of commit 6b6dcb4fc6

[jcsteh]

Okay. Hopefully this is really, really fixed this time.