What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Everything about latency. Tips, testing methods, mouse lag, display lag, game engine lag, network lag, whole input lag chain, VSYNC OFF vs VSYNC ON, and more! Input Lag Articles on Blur Busters.
Vocaleyes
Posts: 296
Joined: 09 Nov 2021, 18:10

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by Vocaleyes » 02 Oct 2023, 04:04

You sir, are doing the lords work.

If there’s anything that can be done in the future to assist, let me know.

timecard
Posts: 66
Joined: 25 Jan 2020, 01:10

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by timecard » 02 Oct 2023, 10:08

TooManyPixels wrote:
02 Oct 2023, 02:12
The periodic "+1ms" that happens to incoming HID reports seems to be because Windows is sending out two USB SOF token packets when it should only be sending out only one (the traces also show my USB devices returning NAK more often that I'd expect). I'm still trying to find out why Windows is doing that. This seems to happen whenever a computer has at least 1 USB 3.0 (XHCI) controller, even if the device is connected to a USB 2.0-only controller.
Not sure if it's related but 3 years ago I was messing around with a PCIE USB card (USB 2.0) and had USB 3.0 motherboard controller running at the same time, I found that all DPCs were being doubled e.g I saw near equal DPCs for usbport.sys (USB2.0) and the WDF driver (Intel USB XHCI 3.0). However just having one controller should eliminate that as a variable in your tests.

TooManyPixels
Posts: 52
Joined: 07 Apr 2020, 21:39

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by TooManyPixels » 16 Oct 2023, 08:19

I was able to record a trace on my AMD Ryzen box with my $expensive USB protocol analyzer that I had previously believed did not suffer from the "floaty" or imprecise mouse-pointer problem - but not before installing a load of pending Windows Updates - and to my surprise, the trace showed that the AMD machine also sent the extraneous USB SOF packets (with the blocking HID reports and surprise NAK responses) - which made me think I've been wasting my time on a red-herring but that AMD machine now does seem to exhibit the same "floaty" pointer behaviour as my Intel boxen.

Either the world's gone mad, or the problem is in my own central-nervous system.

...so to test that hypothesis, over the past couple of weeks, I was able to convince three different friends/associates/random-strangers into my house and asked them to use the mouse on my computer to grab the (inaccessibly thin!) scrollbar in Slack and they all agreed that "something is wrong with your mouse/pointer/cursor/computer, dude" - so that eliminates the "am I going mad?" option.

-----

Taking a step back for a wider view (for once!), I recognize a huge part of my problem with trying to diagnose this issue is that I don't actually have any computers in my possession that can be trusted to not have a floaty / imprecise / annoying / bloody-irritating mouse pointer.

At this point, I'm starting to think the issue might be a consequence of the SPECTRE/MELTDOWN hotfixes that were issued - especially as the AMD Ryzen machine seems to exhibit the same problem as my Intel boxes after those Windows Updates (and yes, I'm kicking myself for not running a trace before installing the Windows Updates).

---

I also recently purchased a new Logitech G502 X mouse - which (as it's under warranty) gives me the excuse to reach-out to Logitech to see if they're familiar with the issue at all and if they know of any workarounds/solutions. Their chat-support was no help (the first-line rep had no idea what any of USBUCX, ETW, or USB SOF was) but they did escalate my ticket to the next level up - now we play the waiting game...

--

So here's the rundown:
  • Every machine of mine that exhibits this issue (which is also every machine that I own...) exhibits the extraneous USB SOF packet, which causes NAKs from the mouse/HID-device until the next SOF, which explains the delayed HID reports, which might explain the imprecise / "floaty" mouse pointer movement.
  • I'm ashamed to admit that I still haven't tried booting into an alternative OS (such as a Linux live-USB-stick). I can't explain why my brain just won't let me try a Ubuntu USB stick, but I guess it's because of past trauma I suffered trying to get Slackware to work back in 2006.
  • This perfect storm of a difficult-to-diagnose, difficult-to-quantify, and difficult-to-explain issue leads me to believe that we're doomed as a species.

*

ahead
Posts: 47
Joined: 21 Jun 2023, 02:15

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by ahead » 17 Oct 2023, 00:21

You need to use microframe, 8 times faster (every 125uS). developers should rewrite a mouse firmware, but this is not real.

MIETAS
Posts: 18
Joined: 08 Dec 2020, 06:14

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by MIETAS » 17 Oct 2023, 04:13

Very interesting read, thank you for all the effort.
From my own experience it would be really convenient to relate that mitigations are the main cause of weird/imprecise mouse movement.
Even if I really want to believe this since I've been dealing with very similar stuff over the years (Intel/AMD platforms) its probably highly unlikely. There are people with modern hardware without single issue.

Could be worth trying to completely diable all mitigations and im not talking about the common methods like using inspectre but like disabling every single mitigation patch/microcode (except the oldest microcode ofc, otherwise it wont even boot).

Question is if anyone knows how to do so? There are also microcode patches... Not disabling 100% of these wont guarantee any results to test accurately.

Anyway, this thread describes very precisely what I've been dealing with for over 6 years or even more. I have minor to literally zero latency / desync / networking / hardware issues BUT what I do have is completely inconsistent mouse input which makes impossible to build muscle memory and every gaming session is random fest of what can happen. I've learned to live with it and not overthink this, but its bugging me from time to time cause i remember my good old gaming days when PC was completely trash but playing was nothing but pure fun ( and that muscle memory, always on point...).

It is how it is...

Vocaleyes
Posts: 296
Joined: 09 Nov 2021, 18:10

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by Vocaleyes » 17 Oct 2023, 13:50

I feel exactly the same way.


Can i ask you, do you also feel as if gameplay isn't as smooth as someone streaming without this issue btw? Or compared to when your mouse used to feel better? I'd like to know if there's any correlation there, as i remember when my mouse worked correctly, the games i was playing also appeared much smoother than they have done since this issue started. Now it's very micro-stuttery for lack of a better word.

I used to play cod ghosts in 2010 on a 60hz screen, and it looked and felt better than games to today on a 240hz monitor (also the old 60hz monitor i used to have, so 100% a monitor issue)

User avatar
kyube
Posts: 129
Joined: 29 Jan 2018, 12:03

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by kyube » 17 Oct 2023, 17:56

It definitely is not EMI or anything like that (because it also happens on my XPS laptop when I'm in the outdoors, or anywhere)
If I may ask, how long did you test it on your laptop to have verified this? Since you're getting this periodically, surely getting it to stuter like this would take a few weeks? I'm curious.

Also, LatencyMon and DPC latency checker are a unreliable metric for testing DPC & ISR latency, try using xperf next time.
https://github.com/amitxv/PC-Tuning/blo ... dpcisr.bat (5s test, try this one first)
https://github.com/djdallmann/GamingPCS ... dpcisr.ps1 (longer test)

How have you tweaked your Windows installs and BIOS'? What settings have you disabled/enabled?
What movements have you used when doing these MouseTester graphs? What version of MouseTester are you using?
What other devices do you have plugged in while testing this? Have you had these devices plugged in constantly throughout other builds, they could be a potential culprit.

Adding older USB 2.0 PCI-E USB cards can amplify the issue, as it can cause a driver stutter in the background.

User avatar
Chief Blur Buster
Site Admin
Posts: 11653
Joined: 05 Dec 2013, 15:44
Location: Toronto / Hamilton, Ontario, Canada
Contact:

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by Chief Blur Buster » 17 Oct 2023, 19:51

See: viewtopic.php?t=6658&start=10#p60855

Play USB roulette with the existing ports as well as a PCIe USB card. It can reduce jitter by 2x-10x in some cases.

TLDR: Sharing the same USB root hub on a high-Hz keyboard and high-Hz mouse, can interfere with each others' performance.
Head of Blur Busters - BlurBusters.com | TestUFO.com | Follow @BlurBusters on Twitter

Image
Forum Rules wrote:  1. Rule #1: Be Nice. This is published forum rule #1. Even To Newbies & People You Disagree With!
  2. Please report rule violations If you see a post that violates forum rules, then report the post.
  3. ALWAYS respect indie testers here. See how indies are bootstrapping Blur Busters research!

TooManyPixels
Posts: 52
Joined: 07 Apr 2020, 21:39

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by TooManyPixels » 20 Oct 2023, 01:19

(No announcements yet, but I just want to show what I was seeing in WPA from my ETW trace)

For this trace, when I had my Arudino-based USB HID "re-player" running, I had it sending USB HID mouse-movements at 1ms intervals (i.e. 1000Hz). Each vertical column of diamonds in the chart represents the exact point-in-time when Windows' USB stack (specifically Ucx01000.sys) reported receiving the URB completing.

If the HID reports were being requested/received at regular 1ms intervals then those diamonds would be evenly distributed - instead we see that they're being clumped into groups of 9 with gaps between the groups. Those gaps should not be there.

(The good news, if any, from this is that all subsequent processing of USB HID input (i.e. how a the HID report eventually ends-up as a WM_INPUT (Win32 Raw Input API) in MouseTester and other programs) is **ultra fast** with no real latency to speak-of, which is why I'm focused on trying to understand what's going on inside Windows' USB stack).
Screenshot.png
Screenshot.png (876.64 KiB) Viewed 3658 times
----------

Here's where I'm seeing the double-SOF messages in the (hardware) USB trace from my Beagle analyzer. These double-SOFs (and the NAKs sent by the Arduino) correspond with the delayed events seen in the ETW trace.
Screenshot-Beagle-Annotated.png
Screenshot-Beagle-Annotated.png (403.26 KiB) Viewed 3658 times
-------------

Here's the money-shot in WPA that shows that the URB transfers' win:Stop events (i.e. when Ucx01000.sys reports receiving the HID report's packet) are being received with exactly 1ms between them, except for these gaps of 2ms, caused by the Arduino's NAK responses caused by the unexpected SOF.
screenshot-wpa-money-shot.png
screenshot-wpa-money-shot.png (240.16 KiB) Viewed 3644 times

TooManyPixels
Posts: 52
Joined: 07 Apr 2020, 21:39

Re: What causes a 500Hz mouse to sometimes report at 250Hz or 125 Hz?

Post by TooManyPixels » 20 Oct 2023, 03:11

Of course, this data (in my previous post) is useless without comparing it to a known good computer - and none of my computers seem unaffected, except for my old Windows 7 laptop from 2010 - I've dusted it off and confirmed that it still boots and Windows 7 SP1 just fine, and when I plug-in my current Logitech G502 X mouse it doesn't seem to have any immediate issues (I could certainly feel some "jank" but it's definitely different to what I get on my desktop).

I'll attempt to record a USB trace and ETW trace from there on Friday - but because ETW/WPP story was less advanced before Windows 8 came out I can't say in-advance what kind of detail I'll get from there. I'm going to be a mental wreck if it turns out these 1ms delayed HID reports also happen on there and it turns out they aren't the problem at all - fml.

-----

After identiftying that something's up with those SOF packets, I searched through the XHCI documentation (as I had it lying around) and noticed this:
4.14.3.1 If an IN transaction is NAKed, then the Interrupt TD will be retried in the next ESIT.
(An ESIT is "Endpoint Service Interval Time: The service period of an Interrupt or an Isochronous Endpoint. An ESIT defines a period of one or more microframes.")

...so this seems to match what I'm seeing - so (assuming this is the case) then for some reason the "next ESIT" is being snapped to the next 1ms instead of the next FS microframe (+0.125ms).

I searched through the XHCI interface documentation for more discussion of how ESIT is set or declared for an Interrupt endpoint but found nothing too enlightening (as the XHCI docs on ESTI are focused on Isochronous entpoint, not Interrupt endpoints). I'll re-review the USB 2.0 documentation tomorrow too, I guess.

Post Reply