All of lore.kernel.org
 help / color / mirror / Atom feed
* PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
@ 2020-05-11  6:18 Yariv
  2020-05-11 20:11 ` Dmitry Torokhov
  0 siblings, 1 reply; 9+ messages in thread
From: Yariv @ 2020-05-11  6:18 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: linux-input

Using a vanilla installation of Ubuntu 20.04 (kernel v5.4), the
timestamps of input events from my Apple "Magic Trackpad" - 1st
generation, connected over Bluetooth - are jittery.
This is a kernel regression. I bisected the bug.

- The problem starts with upstream kernel commit 3b51c44bd693 ("Input:
allow drivers specify timestamp for input events"). After that commit,
the same timestamp is always emitted.
- This was partially fixed in commit 4370b231d100 ("Input: reset
device timestamp on sync"), however ever since then the timestamps are
jittery.

The problem still exists in the current upstream 'master' (commit c45e8bccecaf).

The following patch fixes the bug, however this is obviously a hack.
It effectively reverts commit 3b51c44bd693:

diff --git a/drivers/input/input.c b/drivers/input/input.c
index 3cfd2c18eebd..8890195547d6 100644
--- a/drivers/input/input.c
+++ b/drivers/input/input.c
@@ -1958,7 +1958,7 @@ ktime_t *input_get_timestamp(struct input_dev *dev)
 {
        const ktime_t invalid_timestamp = ktime_set(0, 0);

- if (!ktime_compare(dev->timestamp[INPUT_CLK_MONO], invalid_timestamp))
+ // if (!ktime_compare(dev->timestamp[INPUT_CLK_MONO], invalid_timestamp))
                input_set_timestamp(dev, ktime_get());

        return dev->timestamp;


Reproducing the bug
----------------------------

I used the following script as a reproducer. It relies on
libinput-debug-events. This script measures the time delta between
consecutive input events, then prints a "histogram" of these deltas.

#!/bin/bash

# log file name
logFile=${1:-~/Downloads/`uname -r`}
echo logFile=$logFile

if [[ "$1" == '' ]]; then
  echo record

  # log some events
  sudo libinput debug-events | grep POINTER | tee $logFile
fi

# process the results
lastN=0
for f in `cat $logFile | awk '{print $3}' | sed "s/s//g" | sed "s/+//g"`;
do
  echo "$f-$lastN" | bc;
  lastN=$f;
done | sort | uniq -c


Steps to reproduce
-------------------------

1. Pair an external Apple Trackpad over Bluetooth.
2. Run the above script
3. Move your finger in circles on the external trackpad for a few seconds
4. Press ctrl+c

An example output of this script before the regression
-----------------------------------------------------------------------

      2 .010
    371 .011
    127 .012
      1 .876

The above output means that: 2 times the delta was 10ms, 371 times
11ms, 127 times 12ms and 1 time 876ms. This corresponds well with the
Trackpad's ~90Hz polling rate.

An example output of this script after the regression
---------------------------------------------------------------------

      3 .003
     12 .004
     16 .005
     14 .006
     21 .007
     16 .008
     20 .009
     13 .010
    359 .011
     47 .012
     20 .013
     17 .014
     21 .015
     14 .016
     16 .017
     15 .018
      2 .019
      1 .020
     38 .022
     21 .023
      1 1.060

I suspect that other input devices might be affected as well.

The bug was reported downstream at
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1876449

Please let me know if you prefer that I open a corresponding issue in
the kernel bugzilla.

Best regards,
Yariv

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-11  6:18 PROBLEM: Apple external Trackpad event timestamps are jittery (regression) Yariv
@ 2020-05-11 20:11 ` Dmitry Torokhov
  2020-05-12  5:19   ` Peter Hutterer
  0 siblings, 1 reply; 9+ messages in thread
From: Dmitry Torokhov @ 2020-05-11 20:11 UTC (permalink / raw)
  To: Yariv; +Cc: linux-input

Hi,

On Mon, May 11, 2020 at 09:18:15AM +0300, Yariv wrote:
> Using a vanilla installation of Ubuntu 20.04 (kernel v5.4), the
> timestamps of input events from my Apple "Magic Trackpad" - 1st
> generation, connected over Bluetooth - are jittery.
> This is a kernel regression. I bisected the bug.

Do you see the same jitter when connected over USB? Can you also see if
there is similar jitter when you parse timestamps of SYN_RPEORT events
from "evtest"?

Could you post a sample of events generated by device (via evtest)?

Thanks!

-- 
Dmitry

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-11 20:11 ` Dmitry Torokhov
@ 2020-05-12  5:19   ` Peter Hutterer
  2020-05-12 19:54     ` Yariv
  0 siblings, 1 reply; 9+ messages in thread
From: Peter Hutterer @ 2020-05-12  5:19 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: Yariv, linux-input

On Mon, May 11, 2020 at 01:11:18PM -0700, Dmitry Torokhov wrote:
> Hi,
> 
> On Mon, May 11, 2020 at 09:18:15AM +0300, Yariv wrote:
> > Using a vanilla installation of Ubuntu 20.04 (kernel v5.4), the
> > timestamps of input events from my Apple "Magic Trackpad" - 1st
> > generation, connected over Bluetooth - are jittery.
> > This is a kernel regression. I bisected the bug.
> 
> Do you see the same jitter when connected over USB? Can you also see if
> there is similar jitter when you parse timestamps of SYN_RPEORT events
> from "evtest"?
> 
> Could you post a sample of events generated by device (via evtest)?

unrelated, but I really recommend using 'libinput record' these days since
it can be replayed (libinput replay) or analysed easier (it's YAML).
Also, it prints delta times into the recording so you can immediately check
those without having to parse them, e.g.:

  - evdev:
    - [  0, 375974,   2,   0,       5] # EV_REL / REL_X                     5
    - [  0, 375974,   2,   1,      -2] # EV_REL / REL_Y                    -2
    - [  0, 375974,   0,   0,       0] # ------------ SYN_REPORT (0) ---------- +8ms

Cheers,
   Peter


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-12  5:19   ` Peter Hutterer
@ 2020-05-12 19:54     ` Yariv
  2020-05-22  5:27       ` Yariv
  0 siblings, 1 reply; 9+ messages in thread
From: Yariv @ 2020-05-12 19:54 UTC (permalink / raw)
  To: Peter Hutterer; +Cc: Dmitry Torokhov, linux-input

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

On Tue, May 12, 2020 at 8:19 AM Peter Hutterer <peter.hutterer@who-t.net> wrote:
>
> On Mon, May 11, 2020 at 01:11:18PM -0700, Dmitry Torokhov wrote:
> > Hi,
> >
> > On Mon, May 11, 2020 at 09:18:15AM +0300, Yariv wrote:
> > > Using a vanilla installation of Ubuntu 20.04 (kernel v5.4), the
> > > timestamps of input events from my Apple "Magic Trackpad" - 1st
> > > generation, connected over Bluetooth - are jittery.
> > > This is a kernel regression. I bisected the bug.
> >
> > Do you see the same jitter when connected over USB? Can you also see if
> > there is similar jitter when you parse timestamps of SYN_RPEORT events
> > from "evtest"?
> >
> > Could you post a sample of events generated by device (via evtest)?
>
> unrelated, but I really recommend using 'libinput record' these days since
> it can be replayed (libinput replay) or analysed easier (it's YAML).
> Also, it prints delta times into the recording so you can immediately check
> those without having to parse them, e.g.:
>
>   - evdev:
>     - [  0, 375974,   2,   0,       5] # EV_REL / REL_X                     5
>     - [  0, 375974,   2,   1,      -2] # EV_REL / REL_Y                    -2
>     - [  0, 375974,   0,   0,       0] # ------------ SYN_REPORT (0) ---------- +8ms
>
> Cheers,
>    Peter
>

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-12 19:54     ` Yariv
@ 2020-05-22  5:27       ` Yariv
  2020-05-23 18:37         ` Dmitry Torokhov
  0 siblings, 1 reply; 9+ messages in thread
From: Yariv @ 2020-05-22  5:27 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: linux-input

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 <oigevald+kernel@gmail.com> 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

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-22  5:27       ` Yariv
@ 2020-05-23 18:37         ` Dmitry Torokhov
  2020-05-23 19:11           ` Yariv
  0 siblings, 1 reply; 9+ messages in thread
From: Dmitry Torokhov @ 2020-05-23 18:37 UTC (permalink / raw)
  To: Yariv; +Cc: linux-input

Hi,

On Fri, May 22, 2020 at 08:27:43AM +0300, Yariv wrote:
> 
> 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).

So it looks like for Gen1 touchpads we set autorepeat, and it is that
autorepeat on BTN_TOOL_FINGER that gives what you consider jitter.

  - evdev:
    - [  0, 293648,   1, 325,       2] # EV_KEY / BTN_TOOL_FINGER           2
    - [  0, 293648,   0,   0,       1] # ------------ SYN_REPORT (1) ---------- +1ms
  - evdev:
    - [  0, 303026,   3,  48,      88] # EV_ABS / ABS_MT_TOUCH_MAJOR       88 (-12)
    - [  0, 303026,   3,  53,    -232] # EV_ABS / ABS_MT_POSITION_X      -232 (-22)
    - [  0, 303026,   3,  54,     291] # EV_ABS / ABS_MT_POSITION_Y       291 (+60)
    - [  0, 303026,   3,   0,    -232] # EV_ABS / ABS_X                  -232 (-22)
    - [  0, 303026,   3,   1,     291] # EV_ABS / ABS_Y                   291 (+60)
    - [  0, 303026,   0,   0,       0] # ------------ SYN_REPORT (0) ---------- +10ms

Can you please tell me what drivers are used by the 2 trackpads when they
are connected via Bluetooth? I think we should stop setting autorepeat in
the driver that handles Gen 1.

Also, can you post /proc/bus/input/devices?

Thanks.

-- 
Dmitry

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-23 18:37         ` Dmitry Torokhov
@ 2020-05-23 19:11           ` Yariv
  2020-05-23 21:18             ` Dmitry Torokhov
  0 siblings, 1 reply; 9+ messages in thread
From: Yariv @ 2020-05-23 19:11 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: linux-input

Hi,

I omitted what looks unrelated, please let me know if you need other
details or the full content.
Also I wasn't sure how to find the relevant driver, so I pasted the
relevant dmesg snippets. If there is a more precise way to identify
the driver please let me know and I'll send the missing items.

Gen1:

dmesg

[   11.307056] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[   11.307060] Bluetooth: HIDP socket layer initialized
[   11.310541] magicmouse 0005:05AC:030E.0005: unknown main item tag 0x0
[   11.310657] input: john’s Trackpad as
/devices/pci0000:00/0000:00:14.0/usb1/1-13/1-13:1.0/bluetooth/hci0/hci0:70/0005:05AC:030E.0005/input/input21
[   11.310776] magicmouse 0005:05AC:030E.0005: input,hidraw4:
BLUETOOTH HID v1.60 Mouse [john’s Trackpad] on 00:1a:7d:da:71:09

/proc/bus/input/devices

I: Bus=0005 Vendor=05ac Product=030e Version=0160
N: Name="john’s Trackpad"
P: Phys=00:1a:7d:da:71:09
S: Sysfs=/devices/pci0000:00/0000:00:14.0/usb1/1-13/1-13:1.0/bluetooth/hci0/hci0:70/0005:05AC:030E.0005/input/input21
U: Uniq=d0:a6:37:f2:c3:af
H: Handlers=mouse1 event21
B: PROP=5
B: EV=10001b
B: KEY=e520 10000 0 0 0 0
B: ABS=273800000000003
B: MSC=10

Gen2:

dmesg

[13777.762475] magicmouse 0005:004C:0265.0008: unknown main item tag 0x0
[13777.762721] input: Apple Inc. Magic Trackpad 2 as
/devices/pci0000:00/0000:00:14.0/usb1/1-13/1-13:1.0/bluetooth/hci0/hci0:65/0005:004C:0265.0008/input/input24
[13777.763419] magicmouse 0005:004C:0265.0008: input,hidraw5:
BLUETOOTH HID v1.00 Mouse [Julo’s Trackpad] on 00:1a:7d:da:71:09

/proc/bus/input/devices

I: Bus=0005 Vendor=004c Product=0265 Version=0100
N: Name="Apple Inc. Magic Trackpad 2"
P: Phys=00:1a:7d:da:71:09
S: Sysfs=/devices/pci0000:00/0000:00:14.0/usb1/1-13/1-13:1.0/bluetooth/hci0/hci0:65/0005:004C:0265.0008/input/input24
U: Uniq=04:4b:ed:ec:b3:9c
H: Handlers=mouse2 event22
B: PROP=5
B: EV=b
B: KEY=e520 10000 0 0 0 0
B: ABS=673810001000003

Best regards,
Yariv

On Sat, May 23, 2020 at 9:37 PM Dmitry Torokhov
<dmitry.torokhov@gmail.com> wrote:
>
> Hi,
>
> On Fri, May 22, 2020 at 08:27:43AM +0300, Yariv wrote:
> >
> > 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).
>
> So it looks like for Gen1 touchpads we set autorepeat, and it is that
> autorepeat on BTN_TOOL_FINGER that gives what you consider jitter.
>
>   - evdev:
>     - [  0, 293648,   1, 325,       2] # EV_KEY / BTN_TOOL_FINGER           2
>     - [  0, 293648,   0,   0,       1] # ------------ SYN_REPORT (1) ---------- +1ms
>   - evdev:
>     - [  0, 303026,   3,  48,      88] # EV_ABS / ABS_MT_TOUCH_MAJOR       88 (-12)
>     - [  0, 303026,   3,  53,    -232] # EV_ABS / ABS_MT_POSITION_X      -232 (-22)
>     - [  0, 303026,   3,  54,     291] # EV_ABS / ABS_MT_POSITION_Y       291 (+60)
>     - [  0, 303026,   3,   0,    -232] # EV_ABS / ABS_X                  -232 (-22)
>     - [  0, 303026,   3,   1,     291] # EV_ABS / ABS_Y                   291 (+60)
>     - [  0, 303026,   0,   0,       0] # ------------ SYN_REPORT (0) ---------- +10ms
>
> Can you please tell me what drivers are used by the 2 trackpads when they
> are connected via Bluetooth? I think we should stop setting autorepeat in
> the driver that handles Gen 1.
>
> Also, can you post /proc/bus/input/devices?
>
> Thanks.
>
> --
> Dmitry

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-23 19:11           ` Yariv
@ 2020-05-23 21:18             ` Dmitry Torokhov
  2020-05-24 11:36               ` Yariv
  0 siblings, 1 reply; 9+ messages in thread
From: Dmitry Torokhov @ 2020-05-23 21:18 UTC (permalink / raw)
  To: Yariv; +Cc: linux-input

On Sat, May 23, 2020 at 10:11:50PM +0300, Yariv wrote:
> Hi,
> 
> I omitted what looks unrelated, please let me know if you need other
> details or the full content.
> Also I wasn't sure how to find the relevant driver, so I pasted the
> relevant dmesg snippets. If there is a more precise way to identify
> the driver please let me know and I'll send the missing items.
> 
> Gen1:
> 
> dmesg
> 
> [   11.307056] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
> [   11.307060] Bluetooth: HIDP socket layer initialized
> [   11.310541] magicmouse 0005:05AC:030E.0005: unknown main item tag 0x0
> [   11.310657] input: john’s Trackpad as
> /devices/pci0000:00/0000:00:14.0/usb1/1-13/1-13:1.0/bluetooth/hci0/hci0:70/0005:05AC:030E.0005/input/input21
> [   11.310776] magicmouse 0005:05AC:030E.0005: input,hidraw4:
> BLUETOOTH HID v1.60 Mouse [john’s Trackpad] on 00:1a:7d:da:71:09

Ok, awesome. Can you please try the patch below?

-- 
Dmitry

HID: magicmouse: do not set up autorepeat

From: Dmitry Torokhov <dmitry.torokhov@gmail.com>

Neither trackpad, nor the mouse want input core to generate autorepeat
events for their buttons, so let's reset the bit (as hid-input sets it
for these devices based on the usage vendor code).

Reported-by: Yariv <oigevald+kernel@gmail.com>
Signed-off-by: Dmitry Torokhov <dmitry.torokhov@gmail.com>
---
 drivers/hid/hid-magicmouse.c |    6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/drivers/hid/hid-magicmouse.c b/drivers/hid/hid-magicmouse.c
index 34138667f8af..7ea78be11c84 100644
--- a/drivers/hid/hid-magicmouse.c
+++ b/drivers/hid/hid-magicmouse.c
@@ -535,6 +535,12 @@ static int magicmouse_setup_input(struct input_dev *input, struct hid_device *hd
 		__set_bit(MSC_RAW, input->mscbit);
 	}
 
+	/*
+	 * hit-input may mark device as using autorepeat, but neither
+	 * the trackpad, nor the mouse actually want it.
+	 */
+	__clear_bit(EV_REP, input->evbit);
+
 	return 0;
 }
 

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* Re: PROBLEM: Apple external Trackpad event timestamps are jittery (regression)
  2020-05-23 21:18             ` Dmitry Torokhov
@ 2020-05-24 11:36               ` Yariv
  0 siblings, 0 replies; 9+ messages in thread
From: Yariv @ 2020-05-24 11:36 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: linux-input

Yep, that solved the problem.
I also verified that there are no apparent regressions.

Thanks!

On Sun, May 24, 2020 at 12:18 AM Dmitry Torokhov
<dmitry.torokhov@gmail.com> wrote:
>
> On Sat, May 23, 2020 at 10:11:50PM +0300, Yariv wrote:
> > Hi,
> >
> > I omitted what looks unrelated, please let me know if you need other
> > details or the full content.
> > Also I wasn't sure how to find the relevant driver, so I pasted the
> > relevant dmesg snippets. If there is a more precise way to identify
> > the driver please let me know and I'll send the missing items.
> >
> > Gen1:
> >
> > dmesg
> >
> > [   11.307056] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
> > [   11.307060] Bluetooth: HIDP socket layer initialized
> > [   11.310541] magicmouse 0005:05AC:030E.0005: unknown main item tag 0x0
> > [   11.310657] input: john’s Trackpad as
> > /devices/pci0000:00/0000:00:14.0/usb1/1-13/1-13:1.0/bluetooth/hci0/hci0:70/0005:05AC:030E.0005/input/input21
> > [   11.310776] magicmouse 0005:05AC:030E.0005: input,hidraw4:
> > BLUETOOTH HID v1.60 Mouse [john’s Trackpad] on 00:1a:7d:da:71:09
>
> Ok, awesome. Can you please try the patch below?
>
> --
> Dmitry
>
> HID: magicmouse: do not set up autorepeat
>
> From: Dmitry Torokhov <dmitry.torokhov@gmail.com>
>
> Neither trackpad, nor the mouse want input core to generate autorepeat
> events for their buttons, so let's reset the bit (as hid-input sets it
> for these devices based on the usage vendor code).
>
> Reported-by: Yariv <oigevald+kernel@gmail.com>
> Signed-off-by: Dmitry Torokhov <dmitry.torokhov@gmail.com>
> ---
>  drivers/hid/hid-magicmouse.c |    6 ++++++
>  1 file changed, 6 insertions(+)
>
> diff --git a/drivers/hid/hid-magicmouse.c b/drivers/hid/hid-magicmouse.c
> index 34138667f8af..7ea78be11c84 100644
> --- a/drivers/hid/hid-magicmouse.c
> +++ b/drivers/hid/hid-magicmouse.c
> @@ -535,6 +535,12 @@ static int magicmouse_setup_input(struct input_dev *input, struct hid_device *hd
>                 __set_bit(MSC_RAW, input->mscbit);
>         }
>
> +       /*
> +        * hit-input may mark device as using autorepeat, but neither
> +        * the trackpad, nor the mouse actually want it.
> +        */
> +       __clear_bit(EV_REP, input->evbit);
> +
>         return 0;
>  }
>

^ permalink raw reply	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2020-05-24 11:37 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-05-11  6:18 PROBLEM: Apple external Trackpad event timestamps are jittery (regression) Yariv
2020-05-11 20:11 ` Dmitry Torokhov
2020-05-12  5:19   ` Peter Hutterer
2020-05-12 19:54     ` Yariv
2020-05-22  5:27       ` Yariv
2020-05-23 18:37         ` Dmitry Torokhov
2020-05-23 19:11           ` Yariv
2020-05-23 21:18             ` Dmitry Torokhov
2020-05-24 11:36               ` Yariv

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.