Re: [PATCH] media: rc: double keypresses due to timeout expiring to early

[Sean Young]

On Fri, Nov 17, 2017 at 03:52:50PM +0100, Matthias Reichl wrote:
> Hi Sean!
> 
> On Thu, Nov 16, 2017 at 09:54:51PM +0000, Sean Young wrote:
> > Since commit d57ea877af38 ("media: rc: per-protocol repeat period"),
> > double keypresses are reported on the ite-cir driver. This is due
> > two factors: that commit reduced the timeout used for some protocols
> > (it became protocol dependant) and the high default IR timeout used
> > by the ite-cir driver.
> > 
> > Some of the IR decoders wait for a trailing space, as that is
> > the only way to know if the bit stream has ended (e.g. rc-6 can be
> > 16, 20 or 32 bits). The longer the IR timeout, the longer it will take
> > to receive the trailing space, delaying decoding and pushing it past the
> > keyup timeout.
> > 
> > So, add the IR timeout to the keyup timeout.
> 
> Thanks a lot for the patch, I've asked the people with ite-cir
> receivers to test it.
> 
> In the meanwhile I ran some tests with gpio-ir-recv and timeout
> set to 200ms with a rc-5 remote (that's as close to the original
> setup as I can test right now).
> 
> While the patch fixes the additional key down/up event on longer
> presses, I still get a repeated key event on a short button
> press - which makes it hard to do a single click with the
> remote.

Yes, I've started to notice that too.

> Test on kernel 4.14 with your patch:
> 1510927844.292126: event type EV_MSC(0x04): scancode = 0x1015
> 1510927844.292126: event type EV_KEY(0x01) key_down: KEY_ENTER(0x001c)
> 1510927844.292126: event type EV_SYN(0x00).
> 1510927844.498773: event type EV_MSC(0x04): scancode = 0x1015
> 1510927844.498773: event type EV_SYN(0x00).
> 1510927844.795410: event type EV_KEY(0x01) key_down: KEY_ENTER(0x001c)
> 1510927844.795410: event type EV_SYN(0x00).
> 1510927844.875412: event type EV_KEY(0x01) key_up: KEY_ENTER(0x001c)
> 1510927844.875412: event type EV_SYN(0x00).

There is 875 - 498 = 378ms, which is 200ms IR timeout + 164ms protocol
repeat. This is so long that the repeat delay expired, and that's
where the second keydown comes from.

> Same signal received on kernel 4.9:
> 1510927844.280350: event type EV_MSC(0x04): scancode = 0x1015
> 1510927844.280350: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 1510927844.280350: event type EV_SYN(0x00).
> 1510927844.506477: event type EV_MSC(0x04): scancode = 0x1015
> 1510927844.506477: event type EV_SYN(0x00).
> 1510927844.763111: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 1510927844.763111: event type EV_SYN(0x00).

There it is simply 763 - 506 = 250ms.

> If I understand it correctly it's the input layer repeat (500ms delay)
> kicking in, because time between initial scancode and timeout is
> now signal time + 200ms + 164ms + 200ms (about 570-580ms).
> On older kernels this was signal time + 200ms + 250ms, so typically
> just below the 500ms default repeat delay.
> 
> I'm still trying to wrap my head around the timeout code in the
> rc layer. One problem seems to be that we apply the rather large
> timeout twice. Maybe detecting scancodes generated via timeout
> (sth like timestamp - last_timestamp > protocol_repeat_period)
> and in that case immediately signalling keyup could help? Could well
> be that I'm missing somehting important and this is a bad idea.
> I guess I'd better let you figure something out :)

So there is a few complications. For rc-6, if you hold a button down,
there IR repeated every 110ms, which means there is a 69ms space between
the IR keypresses. The trailing space is needed for IR decode.

So with IR timeout of 200ms this will happen:

0.000 rc-6 IR message 1 begins
0.041 rc-6 IR message 1 ends
space
0.110 rc-6 IR message 2 begins; this means that message 1 is decoded now
0.151 rc-6 IR message 2 ends;
space
0.220 rc-6 IR message 3 begins; this means that message 2 is decoded now
0.261 rc-6 IR message 3 ends 
space
0.461 IR timeout occurs; this means that message 3 is decoded now

So really the timeout should be length of IR message + IR timeout + error 
margin (e.g. rc thread scheduling), unless that is less than the repeat
time.

But this only applies for raw IR decoding; different rules apply for
hardware decoders.

I think for now the best solution is to revert to 250ms for all protocols
(except for cec which needs 550ms), and reconsider for another kernel.

Thanks,
Sean
----