Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
flat view
From: Yariv <hidden>
Date: 2020-05-22 05:28:22
Hi, I just noticed that I replied to the wrong mail, sorry for the mess. My original reply (from May 12th) is at the bottom. In it I created some logs using "libinput record", as suggested by Peter Hutterer. I also did some fresh recordings using evtest. First, some timestamp deltas. These were taken using an external Apple Trackpad, 1st generation, over Bluetooth. I simply moved a single finger in circles on the trackpad in order to generate the events. ... 0.0212481 0.011559 0.00718999 0 0.0157909 0.010725 0.0117009 0.00179601 0 0.0209122 0.0104909 0.00858903 ... Note that sometimes we get about 20ms between events. This device usually sends an event about once per 11ms - i.e. around 90Hz. Log snippet: ... Event: time 1590122452.417506, -------------- SYN_REPORT ------------ Event: time 1590122452.425271, type 1 (EV_KEY), code 325 (BTN_TOOL_FINGER), value 2 Event: time 1590122452.425271, -------------- SYN_REPORT ------------ Event: time 1590122452.425271, type 3 (EV_ABS), code 48 (ABS_MT_TOUCH_MAJOR), value 156 Event: time 1590122452.425271, type 3 (EV_ABS), code 49 (ABS_MT_TOUCH_MINOR), value 188 Event: time 1590122452.425271, type 3 (EV_ABS), code 53 (ABS_MT_POSITION_X), value -659 Event: time 1590122452.425271, type 3 (EV_ABS), code 54 (ABS_MT_POSITION_Y), value -423 Event: time 1590122452.425271, type 3 (EV_ABS), code 0 (ABS_X), value -659 Event: time 1590122452.425271, type 3 (EV_ABS), code 1 (ABS_Y), value -423 Event: time 1590122452.425271, -------------- SYN_REPORT ------------ Event: time 1590122452.440511, type 3 (EV_ABS), code 48 (ABS_MT_TOUCH_MAJOR), value 132 Event: time 1590122452.440511, type 3 (EV_ABS), code 49 (ABS_MT_TOUCH_MINOR), value 180 Event: time 1590122452.440511, type 3 (EV_ABS), code 53 (ABS_MT_POSITION_X), value -625 Event: time 1590122452.440511, type 3 (EV_ABS), code 54 (ABS_MT_POSITION_Y), value -344 Event: time 1590122452.440511, type 3 (EV_ABS), code 0 (ABS_X), value -625 Event: time 1590122452.440511, type 3 (EV_ABS), code 1 (ABS_Y), value -344 Event: time 1590122452.440511, -------------- SYN_REPORT ------------ ... Same device, over a "good" kernel: ... 0.0112979 0.00781107 0.00329399 0.011565 0.0115449 0.0114291 0.00219297 0.00830007 0.011518 0.011142 ... Here the timestamps are around 11ms as expected. log snippet: ... Event: time 1590123185.781886, -------------- SYN_REPORT ------------ Event: time 1590123185.793357, type 3 (EV_ABS), code 48 (ABS_MT_TOUCH_MAJOR), value 92 Event: time 1590123185.793357, type 3 (EV_ABS), code 49 (ABS_MT_TOUCH_MINOR), value 116 Event: time 1590123185.793357, type 3 (EV_ABS), code 53 (ABS_MT_POSITION_X), value -147 Event: time 1590123185.793357, type 3 (EV_ABS), code 54 (ABS_MT_POSITION_Y), value -360 Event: time 1590123185.793357, type 3 (EV_ABS), code 0 (ABS_X), value -147 Event: time 1590123185.793357, type 3 (EV_ABS), code 1 (ABS_Y), value -360 Event: time 1590123185.793357, -------------- SYN_REPORT ------------ Event: time 1590123185.797932, type 1 (EV_KEY), code 325 (BTN_TOOL_FINGER), value 2 Event: time 1590123185.797932, -------------- SYN_REPORT ------------ Event: time 1590123185.803851, type 3 (EV_ABS), code 48 (ABS_MT_TOUCH_MAJOR), value 90 Event: time 1590123185.803851, type 3 (EV_ABS), code 49 (ABS_MT_TOUCH_MINOR), value 132 Event: time 1590123185.803851, type 3 (EV_ABS), code 53 (ABS_MT_POSITION_X), value -116 Event: time 1590123185.803851, type 3 (EV_ABS), code 54 (ABS_MT_POSITION_Y), value -288 Event: time 1590123185.803851, type 3 (EV_ABS), code 0 (ABS_X), value -116 Event: time 1590123185.803851, type 3 (EV_ABS), code 1 (ABS_Y), value -288 Event: time 1590123185.803851, -------------- SYN_REPORT ------------ ... I also tested the 2nd generation of the Apple external trackpad. This device had the correct timestamps, regardless if used over USB or Bluetooth. Timestamps from a 2nd gen device (these were ok both before and after the regression, both over USB and Bluetooth): ... 0.011441 0.0105031 0.0118241 0.0114589 0.011461 0.0107341 0.0114439 0.0113852 ... log snippet: ... Event: time 1590122942.746610, -------------- SYN_REPORT ------------ Event: time 1590122942.758101, type 3 (EV_ABS), code 48 (ABS_MT_TOUCH_MAJOR), value 340 Event: time 1590122942.758101, type 3 (EV_ABS), code 49 (ABS_MT_TOUCH_MINOR), value 416 Event: time 1590122942.758101, type 3 (EV_ABS), code 53 (ABS_MT_POSITION_X), value -318 Event: time 1590122942.758101, type 3 (EV_ABS), code 54 (ABS_MT_POSITION_Y), value 364 Event: time 1590122942.758101, type 3 (EV_ABS), code 0 (ABS_X), value -318 Event: time 1590122942.758101, type 3 (EV_ABS), code 1 (ABS_Y), value 364 Event: time 1590122942.758101, -------------- SYN_REPORT ------------ Event: time 1590122942.769358, type 3 (EV_ABS), code 48 (ABS_MT_TOUCH_MAJOR), value 332 Event: time 1590122942.769358, type 3 (EV_ABS), code 49 (ABS_MT_TOUCH_MINOR), value 408 Event: time 1590122942.769358, type 3 (EV_ABS), code 53 (ABS_MT_POSITION_X), value -293 Event: time 1590122942.769358, type 3 (EV_ABS), code 54 (ABS_MT_POSITION_Y), value 434 Event: time 1590122942.769358, type 3 (EV_ABS), code 58 (ABS_MT_PRESSURE), value 18 Event: time 1590122942.769358, type 3 (EV_ABS), code 0 (ABS_X), value -293 Event: time 1590122942.769358, type 3 (EV_ABS), code 1 (ABS_Y), value 434 Event: time 1590122942.769358, type 3 (EV_ABS), code 24 (ABS_PRESSURE), value 18 Event: time 1590122942.769358, -------------- SYN_REPORT ------------ ... Some things I noticed: Gen2 didn't send "BTN_TOOL_FINGER" events, while Gen1 did, even though I did not press any button. Note that Gen1 still had correct timestamps before the regression, even though it sent these events. Another difference (maybe it's the same one..): if you take a look at the logs from my previous mail, you'll notice that Gen1 Trackpads always send both SYN_REPORT (0) as well as SYN_REPORT (1), while 2nd Gen Trackpads only sends SYN_REPORT (0). GMail botched my links to the full logs from the previous mail, I hope it will turn out correct here: Gen1, before regression https://drive.google.com/open?id=1W0XekSNyf1i-Um-VqxDJuMmJoWAGXIG5 Gen1, after regression: https://drive.google.com/open?id=1nUNf2uOQPvFw_kE8h4mZB0c80kj3hu4F Gen2, after regression: https://drive.google.com/open?id=1pr508bqeax1Csle2HQuLcuXwinWksdjo Thanks, Yariv (Original reply below) On Tue, May 12, 2020 at 10:54 PM Yariv [off-list ref] wrote:
Thanks for following up!
I took Peter's advice and used 'libinput recrod' to get some logs.
I tested both a 1st gen as well as a 2nd gen Apple external trackpads.
While the 1st gen is Bluetooth-only, the 2nd gen can be connected over
both Bluetooth and USB.
The 2nd gen external trackpad had no jitter, regardless if used over
Bluetooth or USB.
Following is a snippet of a 1st gen touchpad, showing only SYN_REPORT
lines for brevity.
This was taken on a kernel with the regression:
- [ 7, 526745, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 7, 537376, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 7, 540141, 0, 0, 1] # ------------ SYN_REPORT (1)
---------- +3ms
- [ 7, 540141, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +0ms
- [ 7, 560065, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +20ms
- [ 7, 571556, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 7, 580125, 0, 0, 1] # ------------ SYN_REPORT (1)
---------- +9ms
- [ 7, 580125, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +0ms
- [ 7, 594466, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +14ms
- [ 7, 604987, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +10ms
- [ 7, 616458, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 7, 624124, 0, 0, 1] # ------------ SYN_REPORT (1)
---------- +8ms
- [ 7, 624124, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +0ms
- [ 7, 639259, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +15ms
- [ 7, 650772, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 7, 660130, 0, 0, 1] # ------------ SYN_REPORT (1)
---------- +10ms
- [ 7, 660130, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +0ms
Now a snippet of the 2nd gen trackpad, over Bluetooth, same kernel:
- [ 9, 584965, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 9, 595860, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 9, 607147, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 9, 618610, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 9, 630279, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 9, 641047, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 9, 652429, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 9, 664148, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 9, 674600, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +10ms
- [ 9, 686040, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 9, 697808, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 9, 709277, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 9, 719649, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +10ms
I'm entirely clueless with regard to the input device protocols,
however it is apparent that the 2nd gen trackpad has only SYN_REPORT
(0) in its log, while the 1st gen has both SYN_REPORT (0) and
SYN_REPORT (1).
Last is a snippet of the 1st gen, this time on a kernel with my hack -
so should behave as before the regression:
- [ 6, 243965, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 6, 254576, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 6, 257637, 0, 0, 1] # ------------ SYN_REPORT (1)
---------- +3ms
- [ 6, 265675, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +8ms
- [ 6, 277512, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 6, 288059, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 6, 297642, 0, 0, 1] # ------------ SYN_REPORT (1)
---------- +9ms
- [ 6, 299646, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +2ms
- [ 6, 310849, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 6, 322000, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 6, 333265, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +11ms
- [ 6, 337681, 0, 0, 1] # ------------ SYN_REPORT (1)
---------- +4ms
- [ 6, 344588, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +7ms
- [ 6, 356921, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +12ms
- [ 6, 366979, 0, 0, 0] # ------------ SYN_REPORT (0)
---------- +10ms
Here it seems that if we add the delta from each SYN_REPORT (1) to the
delta of the following SYN_REPORT (0) we get sane timestamps.
I also tested a USB mouse, and the timestamps were Ok.
So to summarize my limited finding, only the 1st gen Apple external
touchpad seems to be affected.
Entire logs:
https://drive.google.com/open?id=1nUNf2uOQPvFw_kE8h4mZB0c80kj3hu4F
Gen1, after regression
https://drive.google.com/open?id=1pr508bqeax1Csle2HQuLcuXwinWksdjo
Gen2, after regression
https://drive.google.com/open?id=1W0XekSNyf1i-Um-VqxDJuMmJoWAGXIG5
Gen1, before regression
Please let me know if I there is anything else I can do to help.
Best regards,
Yariv