* Re: Inconsistent RC5 ir-keytable events
[not found] <YdKdPosyzj2urFpS@jyty>
@ 2022-01-03 9:21 ` Sean Young
2022-01-03 10:35 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Sean Young @ 2022-01-03 9:21 UTC (permalink / raw)
To: Marko Mäkelä; +Cc: linux-media, Mauro Carvalho Chehab
Hi Marko,
Please send questions/responses to the linux-media list in future.
On Mon, Jan 03, 2022 at 08:52:46AM +0200, Marko Mäkelä wrote:
> Hi,
>
> Years ago, I was using the Hauppauge Nova-T PCI 90002 card that bundles a
> remote control unit that uses RC5 codes.
Would you mind sending the lspci output for this device? Then we know exactly
how the driver is handling this.
> I had patched the 2.6.15 kernel to
> make the usage experience smoother. I am attaching the two patches from
> https://www.iki.fi/~msmakela/software/vdr/ for reference.
That patches does some hacks which are just plain wrong.
> The problem that I am trying to solve is that when I press a button on the
> remote control unit (RCU), often two events will be generated in the
> software (Video Disk Recorder).
>
> I found an old note that the RCU sends bursts of signals roughly once every
> 110 milliseconds. Ideally, I would like the driver to generate key-down or
> key-repeat events at the same rate as the RC5 signals arrive.
That's not the way things should work. The speed at which the IR message gets
repeated depends on the IR protocol. You don't want a key down/up event for
each of those.
> Even with
> ir-keytable --period=0 --delay=0 that does not seem to happen.
You've turned off autorepeat with those options, so that's not going to
change anything. If you press a key, hold it for some time, and then release
you should get one key down, one key up and a few autorepeats depending on
the --delay/--period settings.
> On a 5.15.5 kernel, I installed ir-keytable and added the line
> * * hauppauge.toml
> to the start of the file /etc/rc_maps.cfg. This allows me to use that RCU
> with dvb_usb_rtl28xxu (Astrometa DVB-T2) instead of the default keymap
> rc-astrometa-t2hybrid.
>
> Here is some sample output to demonstrate the problem. I am pressing KEY_OK
> twice, and this is with --period=0 --repeat=0:
>
> sudo ir-keytable -t|grep rc5
> 4733.882120: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4734.094127: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4734.306107: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4734.942117: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4735.154093: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4735.366104: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4735.578100: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4735.790090: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 4736.818108: lirc protocol(rc5): scancode = 0x1e25
> 4737.030114: lirc protocol(rc5): scancode = 0x1e25
> 4737.242087: lirc protocol(rc5): scancode = 0x1e25
> 4737.454088: lirc protocol(rc5): scancode = 0x1e25
> 4737.666120: lirc protocol(rc5): scancode = 0x1e25
>
> As you can see, the messages arrive at somewhat intermittent intervals.
I think this is the issue you are having. Somehow there are gaps in reading
the IR, which are long enough to cause key up/down events.
> Most of the time, the interval is 212 milliseconds (so, apparently every
> second RC5 message is discarded, if my assumption about 110 ms interval is
> correct). But, between the 3rd and 4th line in the above output, there is a
> delay of 636 milliseconds (212*3). And after the last toggle=1 line there is
> a delay of 1 second, even though I probably released the button for at most
> half a second.
>
> Another problem is that I am seeing both key_down and key_up events for
> every key_down event. Here is an unfiltered sample to demonstrate it:
>
> 2928.450104: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 2928.450113: event type EV_MSC(0x04): scancode = 0x1e25
> 2928.450113: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 2928.450113: event type EV_SYN(0x00).
> 2928.580060: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 2928.580060: event type EV_SYN(0x00).
Each rc device has a timeout which determines how long after keydown event,
a key up event is sent as long as the same IR is not received again. This is
usually IR_DEFAULT_TIMEOUT (125ms). You can see the value with
`ir-ctl -f -d /dev/lirc0`
I think the problem is that the gaps in your IR is greater than this timeout.
Sean
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-03 9:21 ` Inconsistent RC5 ir-keytable events Sean Young
@ 2022-01-03 10:35 ` Marko Mäkelä
2022-01-03 11:07 ` Sean Young
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-01-03 10:35 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media, Mauro Carvalho Chehab
Hi Sean,
Thank you for your prompt and helpful reply.
Mon, Jan 03, 2022 at 09:21:23AM +0000, Sean Young wrote:
>On Mon, Jan 03, 2022 at 08:52:46AM +0200, Marko Mäkelä wrote:
>> Hi,
>>
>> Years ago, I was using the Hauppauge Nova-T PCI 90002 card that bundles a
>> remote control unit that uses RC5 codes.
>
>Would you mind sending the lspci output for this device? Then we know
>exactly how the driver is handling this.
I am no longer using the PCI (not PCIe) card, but only the remote
control unit. I still have the hardware sitting unused, but I do not
think that it is relevant to the problem when attempting to use the
remote control unit with the Astrometa DVB-T2 USB adapter.
>That's not the way things should work. The speed at which the IR
>message gets repeated depends on the IR protocol. You don't want a key
>down/up event for each of those.
There is a use case where I actually want that. When I press and hold
the volume-up button, or a button to scroll a list in a menu, I would
the user interface to update as frequently as possible.
Sure, an initial delay that would discard the 2nd..nth IR message could
be useful, so that when I press the channel+ button for less than half a
second, the channel would only change once. But still, it might be
better to filter out "premature repeats" for specific keycodes in the
application (possibly depending on context) and configure the driver to
pass everything through.
>You've turned off autorepeat with those options, so that's not going to
>change anything. If you press a key, hold it for some time, and then
>release you should get one key down, one key up and a few autorepeats
>depending on the --delay/--period settings.
You are right. I tested the bundled RCU of the adapter, and I am indeed
seeing such output. Here is the dmesg from 5.15.5:
[17984.345840] usb 2-6: Manufacturer: astrometadvbt2
[17984.352731] usb 2-6: dvb_usb_v2: found a 'Astrometa DVB-T2' in warm state
[17984.514105] dvbdev: DVB: registering new adapter (Astrometa DVB-T2)
[17984.545328] Registered IR keymap rc-astrometa-t2hybrid
And here is the ir-keymap -t output. It looks like what I would expect
(except maybe the key_up event should be sent after the sequence of
repeat events, not before them).
18022.134140: lirc protocol(nec): scancode = 0x40
18022.134157: event type EV_MSC(0x04): scancode = 0x40
18022.134157: event type EV_KEY(0x01) key_down: KEY_FULL_SCREEN(0x0174)
18022.134157: event type EV_SYN(0x00).
18022.260014: event type EV_KEY(0x01) key_up: KEY_FULL_SCREEN(0x0174)
18022.260014: event type EV_SYN(0x00).
18022.345513: lirc protocol(nec): scancode = 0x40 repeat
18022.345524: event type EV_MSC(0x04): scancode = 0x40
18022.345524: event type EV_SYN(0x00).
18022.561538: lirc protocol(nec): scancode = 0x40 repeat
18022.561549: event type EV_MSC(0x04): scancode = 0x40
18022.561549: event type EV_SYN(0x00).
...
18024.057680: lirc protocol(nec): scancode = 0x40 repeat
18024.057694: event type EV_MSC(0x04): scancode = 0x40
18024.057694: event type EV_SYN(0x00).
^C
>I think this is the issue you are having. Somehow there are gaps in
>reading the IR, which are long enough to cause key up/down events.
I watched the IR LED in the live viewfinder of a digital camera while
pressing a button, and you may be right: instead of seeing a constant
stream of pulses, I saw a few pulses followed by a pause, then again a
few pulses. After I replaced the batteries, I only saw a short pause
every couple of seconds, which probably was a sampling artifact of the
camera. But, this did not improve the situation on Linux yet.
>Each rc device has a timeout which determines how long after keydown
>event, a key up event is sent as long as the same IR is not received
>again. This is usually IR_DEFAULT_TIMEOUT (125ms). You can see the
>value with
>`ir-ctl -f -d /dev/lirc0`
>
>I think the problem is that the gaps in your IR is greater than this timeout.
Again, you seem to be right:
sudo apt install v4l-utils
ir-ctl -f -d /dev/lirc0
Receive features /dev/lirc0:
- Device can receive raw IR
- Can report decoded scancodes and protocol
- Receiving timeout 9741 microseconds
Send features /dev/lirc0:
- Device cannot send
How to increase the timeout from this less than 10ms to something closer
to 125ms?
Note: The bundled remote control unit uses the NEC protocol while the
one that I am attempting to use (hauppauge.toml) is RC-5.
Best regards,
Marko
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-03 10:35 ` Marko Mäkelä
@ 2022-01-03 11:07 ` Sean Young
2022-01-03 12:21 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Sean Young @ 2022-01-03 11:07 UTC (permalink / raw)
To: Marko Mäkelä; +Cc: linux-media, Mauro Carvalho Chehab
Hi Marko,
On Mon, Jan 03, 2022 at 12:35:23PM +0200, Marko Mäkelä wrote:
> Hi Sean,
>
> Thank you for your prompt and helpful reply.
>
> Mon, Jan 03, 2022 at 09:21:23AM +0000, Sean Young wrote:
> > On Mon, Jan 03, 2022 at 08:52:46AM +0200, Marko Mäkelä wrote:
> > > Hi,
> > >
> > > Years ago, I was using the Hauppauge Nova-T PCI 90002 card that bundles a
> > > remote control unit that uses RC5 codes.
> >
> > Would you mind sending the lspci output for this device? Then we know
> > exactly how the driver is handling this.
>
> I am no longer using the PCI (not PCIe) card, but only the remote control
> unit. I still have the hardware sitting unused, but I do not think that it
> is relevant to the problem when attempting to use the remote control unit
> with the Astrometa DVB-T2 USB adapter.
Ah yes.
> > That's not the way things should work. The speed at which the IR message
> > gets repeated depends on the IR protocol. You don't want a key down/up
> > event for each of those.
>
> There is a use case where I actually want that. When I press and hold the
> volume-up button, or a button to scroll a list in a menu, I would the user
> interface to update as frequently as possible.
There is a balance to be struck here. If the button gets repeated too
quickly, it becomes impossible to go up/down one item, for example.
The way to do this, is to set the autorepeat period/delay to settings to
what suits your likes/dislikes; it should not depend on the lower-level
IR message.
> > You've turned off autorepeat with those options, so that's not going to
> > change anything. If you press a key, hold it for some time, and then
> > release you should get one key down, one key up and a few autorepeats
> > depending on the --delay/--period settings.
>
> You are right. I tested the bundled RCU of the adapter, and I am indeed
> seeing such output. Here is the dmesg from 5.15.5:
>
> [17984.345840] usb 2-6: Manufacturer: astrometadvbt2
> [17984.352731] usb 2-6: dvb_usb_v2: found a 'Astrometa DVB-T2' in warm state
> [17984.514105] dvbdev: DVB: registering new adapter (Astrometa DVB-T2)
> [17984.545328] Registered IR keymap rc-astrometa-t2hybrid
>
> And here is the ir-keymap -t output. It looks like what I would expect
> (except maybe the key_up event should be sent after the sequence of repeat
> events, not before them).
>
> 18022.134140: lirc protocol(nec): scancode = 0x40
> 18022.134157: event type EV_MSC(0x04): scancode = 0x40
> 18022.134157: event type EV_KEY(0x01) key_down: KEY_FULL_SCREEN(0x0174)
> 18022.134157: event type EV_SYN(0x00).
> 18022.260014: event type EV_KEY(0x01) key_up: KEY_FULL_SCREEN(0x0174)
> 18022.260014: event type EV_SYN(0x00).
So the delay for the keyup is 125857us or about 125ms.
> 18022.345513: lirc protocol(nec): scancode = 0x40 repeat
> 18022.345524: event type EV_MSC(0x04): scancode = 0x40
> 18022.345524: event type EV_SYN(0x00).
However here the repeat gets reported too late. It gets reported 211373us
after the first scancode (about 211ms).
> 18022.561538: lirc protocol(nec): scancode = 0x40 repeat
> 18022.561549: event type EV_MSC(0x04): scancode = 0x40
> 18022.561549: event type EV_SYN(0x00).
> ...
> 18024.057680: lirc protocol(nec): scancode = 0x40 repeat
> 18024.057694: event type EV_MSC(0x04): scancode = 0x40
> 18024.057694: event type EV_SYN(0x00).
> ^C
>
> > I think this is the issue you are having. Somehow there are gaps in
> > reading the IR, which are long enough to cause key up/down events.
>
> I watched the IR LED in the live viewfinder of a digital camera while
> pressing a button, and you may be right: instead of seeing a constant stream
> of pulses, I saw a few pulses followed by a pause, then again a few pulses.
> After I replaced the batteries, I only saw a short pause every couple of
> seconds, which probably was a sampling artifact of the camera. But, this did
> not improve the situation on Linux yet.
I am not sure if the naked eye can observe a delay of 200ms rather than 100ms.
> > Each rc device has a timeout which determines how long after keydown
> > event, a key up event is sent as long as the same IR is not received
> > again. This is usually IR_DEFAULT_TIMEOUT (125ms). You can see the value
> > with
> > `ir-ctl -f -d /dev/lirc0`
> >
> > I think the problem is that the gaps in your IR is greater than this timeout.
>
> Again, you seem to be right:
>
> sudo apt install v4l-utils
> ir-ctl -f -d /dev/lirc0 Receive features /dev/lirc0:
> - Device can receive raw IR
> - Can report decoded scancodes and protocol
> - Receiving timeout 9741 microseconds
> Send features /dev/lirc0:
> - Device cannot send
>
> How to increase the timeout from this less than 10ms to something closer to
> 125ms?
This is the timeout field on rcdev. I think it is set here:
https://git.linuxtv.org/media_tree.git/tree/drivers/media/usb/dvb-usb-v2/rtl28xxu.c#n1810
I think the interval is to set to value which is much to high; I think the
211 ms comes from this 200 value here. So, I think if you lower this to
100 then your problems might go away.
I had forgotten that that for the delay between key down and key up, this
also adds the repeat period for the protocol, see
https://git.linuxtv.org/media_tree.git/tree/drivers/media/rc/rc-main.c#n857
So actually that is 110ms + 9741us ≈ 119m, which is near enough the values seen
above. I suspect the issue is the interval but please experiment.
Sean
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-03 11:07 ` Sean Young
@ 2022-01-03 12:21 ` Marko Mäkelä
2022-01-04 16:07 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-01-03 12:21 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media, Mauro Carvalho Chehab
Hi Sean,
Mon, Jan 03, 2022 at 11:07:43AM +0000, Sean Young wrote:
>I am not sure if the naked eye can observe a delay of 200ms rather than
>100ms.
I thought that I might be able to distinguish "fast blinking" (5Hz or
200ms) and "very fast blinking" (10Hz or 100ms), but I am not so sure
anymore.
>This is the timeout field on rcdev. I think it is set here:
>
>https://git.linuxtv.org/media_tree.git/tree/drivers/media/usb/dvb-usb-v2/rtl28xxu.c#n1810
>
>I think the interval is to set to value which is much to high; I think
>the 211 ms comes from this 200 value here. So, I think if you lower
>this to 100 then your problems might go away.
According to my old notes from this RCU, the repeat period was slightly
less than 110ms. In fact, the 212ms value from my output could be
2*106ms.
>I had forgotten that that for the delay between key down and key up,
>this also adds the repeat period for the protocol, see
>https://git.linuxtv.org/media_tree.git/tree/drivers/media/rc/rc-main.c#n857
>
>So actually that is 110ms + 9741us ≈ 119m, which is near enough the
>values seen above. I suspect the issue is the interval but please
>experiment.
If the correct threshold is 106ms and your suggestion of 100 does not
work, I will try a lower value, such as 94 or 95, to get 94+9.741 < 106.
I will get back to you once I have tested the change, hopefully during
this week.
Marko
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-03 12:21 ` Marko Mäkelä
@ 2022-01-04 16:07 ` Marko Mäkelä
2022-01-05 9:53 ` Sean Young
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-01-04 16:07 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media, Mauro Carvalho Chehab
[-- Attachment #1: Type: text/plain, Size: 6087 bytes --]
Mon, Jan 03, 2022 at 02:21:05PM +0200, Marko Mäkelä wrote:
>If the correct threshold is 106ms and your suggestion of 100 does not
>work, I will try a lower value, such as 94 or 95, to get 94+9.741 <
>106.
With the value 100, I got rather nice output from ir-keytable -t. Here
is a short press of OK followed by a long press:
Testing events. Please, press CTRL-C to abort.
85.406113: lirc protocol(rc5): scancode = 0x1e25
85.406129: event type EV_MSC(0x04): scancode = 0x1e25
85.406129: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
85.406129: event type EV_SYN(0x00).
85.536094: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
85.536094: event type EV_SYN(0x00).
87.286097: lirc protocol(rc5): scancode = 0x1e25 toggle=1
87.286108: event type EV_MSC(0x04): scancode = 0x1e25
87.286108: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
87.286108: event type EV_SYN(0x00).
87.398095: lirc protocol(rc5): scancode = 0x1e25 toggle=1
87.398103: event type EV_MSC(0x04): scancode = 0x1e25
87.398103: event type EV_SYN(0x00).
87.510073: lirc protocol(rc5): scancode = 0x1e25 toggle=1
87.510081: event type EV_MSC(0x04): scancode = 0x1e25
87.510081: event type EV_SYN(0x00).
87.622079: lirc protocol(rc5): scancode = 0x1e25 toggle=1
87.622088: event type EV_MSC(0x04): scancode = 0x1e25
87.622088: event type EV_SYN(0x00).
87.734090: lirc protocol(rc5): scancode = 0x1e25 toggle=1
87.734099: event type EV_MSC(0x04): scancode = 0x1e25
87.734099: event type EV_SYN(0x00).
87.804051: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
87.804051: event type EV_SYN(0x00).
[snip]
88.854090: lirc protocol(rc5): scancode = 0x1e25 toggle=1
88.854098: event type EV_MSC(0x04): scancode = 0x1e25
88.854098: event type EV_SYN(0x00).
88.860050: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
88.860050: event type EV_SYN(0x00).
88.860050: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
88.860050: event type EV_SYN(0x00).
There was no unexpected key_up during the long press.
I suppose that the key_down events are for the repeated keypresses. This
was with the default settings for the repeat.
Based on the timestamps, the RC5 messages would seem to arrive at
112-millisecond intervals.
I also tried smaller values (94, 90, 70), and it got worse. With 94, it
worked most of the time, but there were occasional glitches (key_up
events while the RC5 messages kept arriving) like this:
292.842137: lirc protocol(rc5): scancode = 0x1e25
292.776051: event type EV_MSC(0x04): scancode = 0x1e25
292.776051: event type EV_SYN(0x00).
292.908053: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
292.908053: event type EV_SYN(0x00).
292.954082: lirc protocol(rc5): scancode = 0x1e25
292.908053: event type EV_MSC(0x04): scancode = 0x1e25
292.908053: event type EV_SYN(0x00).
293.040051: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
293.040051: event type EV_SYN(0x00).
293.040051: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
293.040051: event type EV_SYN(0x00).
293.162075: lirc protocol(rc5): scancode = 0x1e25
293.162085: event type EV_MSC(0x04): scancode = 0x1e25
293.162085: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
293.162085: event type EV_SYN(0x00).
293.292069: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
293.292069: event type EV_SYN(0x00).
With the value 70, every single RC5 message would result in both
key_down and key_up events:
497.970089: lirc protocol(rc5): scancode = 0x1e0d
497.970104: event type EV_MSC(0x04): scancode = 0x1e0d
497.970104: event type EV_KEY(0x01) key_down: KEY_MENU(0x008b)
497.970104: event type EV_SYN(0x00).
498.100064: event type EV_KEY(0x01) key_up: KEY_MENU(0x008b)
498.100064: event type EV_SYN(0x00).
498.138082: lirc protocol(rc5): scancode = 0x1e0d
498.138096: event type EV_MSC(0x04): scancode = 0x1e0d
498.138096: event type EV_KEY(0x01) key_down: KEY_MENU(0x008b)
498.138096: event type EV_SYN(0x00).
498.268059: event type EV_KEY(0x01) key_up: KEY_MENU(0x008b)
498.268059: event type EV_SYN(0x00).
I got rather good volume+/volume- response in GNOME desktop when I used
the value 100 (as in the attached patch) and set the following:
ir-keytable --period=111 --delay=111
I tested once more without the patch (using the value 200), both with
the defaults (--period=125 --delay=500) and the 111ms values, and the
experience was bad (about half the speed, and frequent intermittent
pauses).
However, the patch breaks the NEC protocol. With the bundled remote
control unit of the adapter, I initially get some key_down and key_up,
but then I only get 'repeat' events if I hit the same (or even
different) button again. Here is a sample with almost 8 seconds of pause
in between:
2035.461973: lirc protocol(nec): scancode = 0x1e repeat
2035.461981: event type EV_MSC(0x04): scancode = 0x1e
2035.461981: event type EV_SYN(0x00).
2035.573955: lirc protocol(nec): scancode = 0x1e repeat
2035.573963: event type EV_MSC(0x04): scancode = 0x1e
2035.573963: event type EV_SYN(0x00).
2043.425920: lirc protocol(nec): scancode = 0x1e repeat
2043.425932: event type EV_MSC(0x04): scancode = 0x1e
2043.425932: event type EV_SYN(0x00).
I tested once more the stock driver (value=200) with the NEC protocol.
The GNOME volume control would only react to the initial press of the
button, not on the repeats. Also in ir-keytable -t, I only see one
key_down/key_up followed by LIRC-only messages:
2776.698529: lirc protocol(nec): scancode = 0x1e
2776.698539: event type EV_MSC(0x04): scancode = 0x1e
2776.698539: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
2776.698539: event type EV_SYN(0x00).
2776.824077: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
2776.824077: event type EV_SYN(0x00).
2776.909965: lirc protocol(nec): scancode = 0x1e repeat
2776.909973: event type EV_MSC(0x04): scancode = 0x1e
2776.909973: event type EV_SYN(0x00).
2777.121976: lirc protocol(nec): scancode = 0x1e repeat
2777.121983: event type EV_MSC(0x04): scancode = 0x1e
2777.121983: event type EV_SYN(0x00).
I am happy to test any patches, now that I have a compiled kernel where
I can easily rmmod and insmod the module.
Marko
[-- Attachment #2: rtl28xxu-rc5.patch --]
[-- Type: text/x-diff, Size: 566 bytes --]
diff --git a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
index 795a012d4020..9504d6f94a58 100644
--- a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
+++ b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
@@ -1807,7 +1807,7 @@ static int rtl2832u_get_rc_config(struct dvb_usb_device *d,
rc->allowed_protos = RC_PROTO_BIT_ALL_IR_DECODER;
rc->driver_type = RC_DRIVER_IR_RAW;
rc->query = rtl2832u_rc_query;
- rc->interval = 200;
+ rc->interval = 100;
/* we program idle len to 0xc0, set timeout to one less */
rc->timeout = 0xbf * 51;
^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-04 16:07 ` Marko Mäkelä
@ 2022-01-05 9:53 ` Sean Young
2022-01-06 11:41 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Sean Young @ 2022-01-05 9:53 UTC (permalink / raw)
To: Marko Mäkelä; +Cc: linux-media, Mauro Carvalho Chehab
On Tue, Jan 04, 2022 at 06:07:06PM +0200, Marko Mäkelä wrote:
> Mon, Jan 03, 2022 at 02:21:05PM +0200, Marko Mäkelä wrote:
> > If the correct threshold is 106ms and your suggestion of 100 does not
> > work, I will try a lower value, such as 94 or 95, to get 94+9.741 < 106.
>
> With the value 100, I got rather nice output from ir-keytable -t. Here is a
> short press of OK followed by a long press:
>
> Testing events. Please, press CTRL-C to abort.
> 85.406113: lirc protocol(rc5): scancode = 0x1e25
> 85.406129: event type EV_MSC(0x04): scancode = 0x1e25
> 85.406129: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 85.406129: event type EV_SYN(0x00).
> 85.536094: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 85.536094: event type EV_SYN(0x00).
> 87.286097: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 87.286108: event type EV_MSC(0x04): scancode = 0x1e25
> 87.286108: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 87.286108: event type EV_SYN(0x00).
> 87.398095: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 87.398103: event type EV_MSC(0x04): scancode = 0x1e25
> 87.398103: event type EV_SYN(0x00).
> 87.510073: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 87.510081: event type EV_MSC(0x04): scancode = 0x1e25
> 87.510081: event type EV_SYN(0x00).
> 87.622079: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 87.622088: event type EV_MSC(0x04): scancode = 0x1e25
> 87.622088: event type EV_SYN(0x00).
> 87.734090: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 87.734099: event type EV_MSC(0x04): scancode = 0x1e25
> 87.734099: event type EV_SYN(0x00).
> 87.804051: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 87.804051: event type EV_SYN(0x00).
> [snip]
> 88.854090: lirc protocol(rc5): scancode = 0x1e25 toggle=1
> 88.854098: event type EV_MSC(0x04): scancode = 0x1e25
> 88.854098: event type EV_SYN(0x00).
> 88.860050: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 88.860050: event type EV_SYN(0x00).
> 88.860050: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 88.860050: event type EV_SYN(0x00).
>
> There was no unexpected key_up during the long press.
This looks good.
> I suppose that the key_down events are for the repeated keypresses. This was
> with the default settings for the repeat.
>
> Based on the timestamps, the RC5 messages would seem to arrive at
> 112-millisecond intervals.
>
> I also tried smaller values (94, 90, 70), and it got worse. With 94, it
> worked most of the time, but there were occasional glitches (key_up events
> while the RC5 messages kept arriving) like this:
>
> 292.842137: lirc protocol(rc5): scancode = 0x1e25
> 292.776051: event type EV_MSC(0x04): scancode = 0x1e25
> 292.776051: event type EV_SYN(0x00).
> 292.908053: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 292.908053: event type EV_SYN(0x00).
> 292.954082: lirc protocol(rc5): scancode = 0x1e25
> 292.908053: event type EV_MSC(0x04): scancode = 0x1e25
> 292.908053: event type EV_SYN(0x00).
> 293.040051: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 293.040051: event type EV_SYN(0x00).
> 293.040051: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 293.040051: event type EV_SYN(0x00).
> 293.162075: lirc protocol(rc5): scancode = 0x1e25
> 293.162085: event type EV_MSC(0x04): scancode = 0x1e25
> 293.162085: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 293.162085: event type EV_SYN(0x00).
> 293.292069: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 293.292069: event type EV_SYN(0x00).
>
> With the value 70, every single RC5 message would result in both key_down
> and key_up events:
>
> 497.970089: lirc protocol(rc5): scancode = 0x1e0d
> 497.970104: event type EV_MSC(0x04): scancode = 0x1e0d
> 497.970104: event type EV_KEY(0x01) key_down: KEY_MENU(0x008b)
> 497.970104: event type EV_SYN(0x00).
> 498.100064: event type EV_KEY(0x01) key_up: KEY_MENU(0x008b)
> 498.100064: event type EV_SYN(0x00).
> 498.138082: lirc protocol(rc5): scancode = 0x1e0d
> 498.138096: event type EV_MSC(0x04): scancode = 0x1e0d
> 498.138096: event type EV_KEY(0x01) key_down: KEY_MENU(0x008b)
> 498.138096: event type EV_SYN(0x00).
> 498.268059: event type EV_KEY(0x01) key_up: KEY_MENU(0x008b)
> 498.268059: event type EV_SYN(0x00).
>
> I got rather good volume+/volume- response in GNOME desktop when I used the
> value 100 (as in the attached patch) and set the following:
> ir-keytable --period=111 --delay=111
>
> I tested once more without the patch (using the value 200), both with the
> defaults (--period=125 --delay=500) and the 111ms values, and the experience
> was bad (about half the speed, and frequent intermittent pauses).
>
> However, the patch breaks the NEC protocol. With the bundled remote control
> unit of the adapter, I initially get some key_down and key_up, but then I
> only get 'repeat' events if I hit the same (or even different) button again.
> Here is a sample with almost 8 seconds of pause in between:
>
> 2035.461973: lirc protocol(nec): scancode = 0x1e repeat
> 2035.461981: event type EV_MSC(0x04): scancode = 0x1e
> 2035.461981: event type EV_SYN(0x00).
> 2035.573955: lirc protocol(nec): scancode = 0x1e repeat
> 2035.573963: event type EV_MSC(0x04): scancode = 0x1e
> 2035.573963: event type EV_SYN(0x00).
> 2043.425920: lirc protocol(nec): scancode = 0x1e repeat
> 2043.425932: event type EV_MSC(0x04): scancode = 0x1e
> 2043.425932: event type EV_SYN(0x00).
>
> I tested once more the stock driver (value=200) with the NEC protocol. The
> GNOME volume control would only react to the initial press of the button,
> not on the repeats. Also in ir-keytable -t, I only see one key_down/key_up
> followed by LIRC-only messages:
>
> 2776.698529: lirc protocol(nec): scancode = 0x1e
> 2776.698539: event type EV_MSC(0x04): scancode = 0x1e
> 2776.698539: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
> 2776.698539: event type EV_SYN(0x00).
> 2776.824077: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
> 2776.824077: event type EV_SYN(0x00).
> 2776.909965: lirc protocol(nec): scancode = 0x1e repeat
> 2776.909973: event type EV_MSC(0x04): scancode = 0x1e
> 2776.909973: event type EV_SYN(0x00).
> 2777.121976: lirc protocol(nec): scancode = 0x1e repeat
> 2777.121983: event type EV_MSC(0x04): scancode = 0x1e
> 2777.121983: event type EV_SYN(0x00).
Here the is such a delay between the the first message and the repeat,
that rc-core does not honour the repeat any more.
> I am happy to test any patches, now that I have a compiled kernel where I
> can easily rmmod and insmod the module.
I don't quite understand why but clearly IR is being dropped.
So I suspect there is an issue with reading out the IR from the device. The
routine reads the IR buffer, and then sends commands, probably to clear
the IR buffer. It would be interesting to see the output of usbmon while
IR is being received when IR is being dropped, and also see if experimenting
with removing some entries from refresh_tab makes any difference (just a
guess).
Sean
> diff --git a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
> index 795a012d4020..9504d6f94a58 100644
> --- a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
> +++ b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
> @@ -1807,7 +1807,7 @@ static int rtl2832u_get_rc_config(struct dvb_usb_device *d,
> rc->allowed_protos = RC_PROTO_BIT_ALL_IR_DECODER;
> rc->driver_type = RC_DRIVER_IR_RAW;
> rc->query = rtl2832u_rc_query;
> - rc->interval = 200;
> + rc->interval = 100;
> /* we program idle len to 0xc0, set timeout to one less */
> rc->timeout = 0xbf * 51;
>
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-05 9:53 ` Sean Young
@ 2022-01-06 11:41 ` Marko Mäkelä
2022-01-13 16:55 ` Sean Young
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-01-06 11:41 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media, Mauro Carvalho Chehab
[-- Attachment #1: Type: text/plain, Size: 4174 bytes --]
Wed, Jan 05, 2022 at 09:53:55AM +0000, Sean Young wrote:
>On Tue, Jan 04, 2022 at 06:07:06PM +0200, Marko Mäkelä wrote:
>> I tested once more the stock driver (value=200) with the NEC
>> protocol. The GNOME volume control would only react to the initial
>> press of the button, not on the repeats. Also in ir-keytable -t, I
>> only see one key_down/key_up followed by LIRC-only messages:
>>
>> 2776.698529: lirc protocol(nec): scancode = 0x1e
>> 2776.698539: event type EV_MSC(0x04): scancode = 0x1e
>> 2776.698539: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>> 2776.698539: event type EV_SYN(0x00).
>> 2776.824077: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
>> 2776.824077: event type EV_SYN(0x00).
>> 2776.909965: lirc protocol(nec): scancode = 0x1e repeat
>> 2776.909973: event type EV_MSC(0x04): scancode = 0x1e
>> 2776.909973: event type EV_SYN(0x00).
>> 2777.121976: lirc protocol(nec): scancode = 0x1e repeat
>> 2777.121983: event type EV_MSC(0x04): scancode = 0x1e
>> 2777.121983: event type EV_SYN(0x00).
>
>Here the is such a delay between the the first message and the repeat,
>that rc-core does not honour the repeat any more.
I repeated the experiment with a stock Debian 5.15.0-2-amd64 kernel
(based on 5.15.5). First, I checked the RCU with a digital camera.
Because the blinking of the IR LED appeared a little erratic, I replaced
the CR2025 cell (voltage=3.25V) with a better one (voltage=3.3V). It got
brighter and better in the digital viewfinder, but there was no
improvement for ir-keytable -t:
Testing events. Please, press CTRL-C to abort.
25559.898935: lirc protocol(nec): scancode = 0x1e
25559.898948: event type EV_MSC(0x04): scancode = 0x1e
25559.898948: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
25559.898948: event type EV_SYN(0x00).
25560.024055: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
25560.024055: event type EV_SYN(0x00).
25560.110134: lirc protocol(nec): scancode = 0x1e repeat
25560.110141: event type EV_MSC(0x04): scancode = 0x1e
25560.110141: event type EV_SYN(0x00).
25560.322180: lirc protocol(nec): scancode = 0x1e repeat
25560.322188: event type EV_MSC(0x04): scancode = 0x1e
25560.322188: event type EV_SYN(0x00).
25560.534173: lirc protocol(nec): scancode = 0x1e repeat
25560.534180: event type EV_MSC(0x04): scancode = 0x1e
25560.534180: event type EV_SYN(0x00).
25560.746156: lirc protocol(nec): scancode = 0x1e repeat
25560.746163: event type EV_MSC(0x04): scancode = 0x1e
25560.746163: event type EV_SYN(0x00).
25560.958173: lirc protocol(nec): scancode = 0x1e repeat
25560.958181: event type EV_MSC(0x04): scancode = 0x1e
25560.958181: event type EV_SYN(0x00).
25997.954229: lirc protocol(nec): scancode = 0x1e repeat
25997.954241: event type EV_MSC(0x04): scancode = 0x1e
25997.954241: event type EV_SYN(0x00).
25998.166182: lirc protocol(nec): scancode = 0x1e repeat
25998.166189: event type EV_MSC(0x04): scancode = 0x1e
25998.166189: event type EV_SYN(0x00).
Note the very long delay between 25560 and 25997. For a couple of
minutes, after I had released the VOL+ button, I did not touch the
remote control unit. Then I pressed the FULL SCREEN button.
Despite the very long delay, no key_down or key_up event was being
generated. This would suggest a software bug and not an issue with the
coin battery voltage dropping too much due to the power draw.
Also, the scancode=0x1e of the VOL+ button appears to be wrongly
repeated for the FULL SCREEN button. According to the following
experiment (and the attachment), FULL SCREEN should be scancode=0x40.
>It would be interesting to see the output of usbmon while IR is being
>received when IR is being dropped
OK, https://docs.kernel.org/usb/usbmon.html was new to me.
I unplugged the device, plugged it in, then started the following and
started a long press of the FULL SCREEN button:
sudo cat /sys/kernel/debug/usb/usbmon/3u > 3u.out
sudo ir-keytable -t > ir-keytable.out
>and also see if experimenting with removing some entries from
>refresh_tab makes any difference (just a guess).
Can you give a more specific hint? I am not only a relative kernel
newbie, but also a USB newbie.
Marko
[-- Attachment #2: 3u.out --]
[-- Type: text/plain, Size: 25282 bytes --]
ffff8c7d7ce5d980 1465660083 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1465661736 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1465864064 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1465865701 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1466049753 C Ii:3:003:1 0:8 4 = 00010000
ffff8c89c3b34900 1466049775 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466057745 C Ii:3:003:1 0:8 4 = 0002ff00
ffff8c89c3b34900 1466057761 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1466068073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1466069716 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1466105747 C Ii:3:003:1 0:8 4 = 00fe0100
ffff8c89c3b34900 1466105763 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466113741 C Ii:3:003:1 0:8 4 = 00fb0200
ffff8c89c3b34900 1466113756 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466121747 C Ii:3:003:1 0:8 4 = 00f70200
ffff8c89c3b34900 1466121763 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466129744 C Ii:3:003:1 0:8 4 = 00f40100
ffff8c89c3b34900 1466129761 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466137746 C Ii:3:003:1 0:8 4 = 00f00000
ffff8c89c3b34900 1466137762 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466145743 C Ii:3:003:1 0:8 4 = 00f1ff00
ffff8c89c3b34900 1466145759 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466153745 C Ii:3:003:1 0:8 4 = 00eefd00
ffff8c89c3b34900 1466153761 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466161744 C Ii:3:003:1 0:8 4 = 00eefc00
ffff8c89c3b34900 1466161760 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466169746 C Ii:3:003:1 0:8 4 = 00f1fd00
ffff8c89c3b34900 1466169762 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466177743 C Ii:3:003:1 0:8 4 = 00f0fc00
ffff8c89c3b34900 1466177759 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466185744 C Ii:3:003:1 0:8 4 = 00f2fd00
ffff8c89c3b34900 1466185760 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466193746 C Ii:3:003:1 0:8 4 = 00f4fd00
ffff8c89c3b34900 1466193762 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466201747 C Ii:3:003:1 0:8 4 = 00f4fd00
ffff8c89c3b34900 1466201762 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466209743 C Ii:3:003:1 0:8 4 = 00f6fe00
ffff8c89c3b34900 1466209759 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466217740 C Ii:3:003:1 0:8 4 = 00f7fe00
ffff8c89c3b34900 1466217757 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466225743 C Ii:3:003:1 0:8 4 = 00f9fe00
ffff8c89c3b34900 1466225759 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466233741 C Ii:3:003:1 0:8 4 = 00fbff00
ffff8c89c3b34900 1466233757 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466241745 C Ii:3:003:1 0:8 4 = 00fc0000
ffff8c89c3b34900 1466241761 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466249746 C Ii:3:003:1 0:8 4 = 00fe0000
ffff8c89c3b34900 1466249762 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1466272073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1466273717 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1466305750 C Ii:3:003:1 0:8 4 = 00ff0000
ffff8c89c3b34900 1466305766 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466313741 C Ii:3:003:1 0:8 4 = 00fe0100
ffff8c89c3b34900 1466313759 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466321743 C Ii:3:003:1 0:8 4 = 00fd0000
ffff8c89c3b34900 1466321759 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466329748 C Ii:3:003:1 0:8 4 = 00fd0200
ffff8c89c3b34900 1466329764 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466337744 C Ii:3:003:1 0:8 4 = 00fd0100
ffff8c89c3b34900 1466337761 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466345744 C Ii:3:003:1 0:8 4 = 00ff0100
ffff8c89c3b34900 1466345760 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1466353742 C Ii:3:003:1 0:8 4 = 00ff0100
ffff8c89c3b34900 1466353758 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1466476071 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1466477703 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1466680070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1466681707 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1466884076 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1466885721 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1467088067 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1467089703 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1467292068 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1467293705 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1467496065 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1467497701 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1467700069 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1467701713 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1467904074 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1467905715 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1468108070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1468109719 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1468312075 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1468313713 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1468516073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1468517746 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1468720070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1468721710 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1468924064 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1468925711 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1469128072 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1469129718 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1469332069 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1469333705 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1469536071 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1469537709 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1469740075 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1469741714 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1469944060 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1469945691 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1470148065 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1470149700 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1470352073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1470353705 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1470353724 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1470355376 C Ci:3:006:0 0 1 = 46
ffff8c7d7ce5d980 1470355396 S Ci:3:006:0 s c0 00 fc00 0201 0046 70 <
ffff8c7d7ce5d980 1470357618 C Ci:3:006:0 0 70 = ffb5598c 0b8c0b8c 0b8c0b8c 0b8c0b8d 0a8d0a8d 208d208c 218d208d 208c218d
ffff8c7d7ce5d980 1470357639 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1470359235 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470359255 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1470360851 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470360872 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1470362466 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470564064 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1470565694 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1470565714 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1470567336 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1470567356 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1470569025 C Ci:3:006:0 0 6 = ffb42c8d 7f40
ffff8c7d7ce5d980 1470569045 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1470570644 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470570664 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1470572269 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470572289 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1470573885 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470776070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1470777708 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1470777727 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1470779382 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1470779401 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1470781069 C Ci:3:006:0 0 6 = ffb52b8d 7f40
ffff8c7d7ce5d980 1470781089 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1470782682 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470782702 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1470784297 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470784317 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1470785911 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470988073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1470989711 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1470989729 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1470991364 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1470991385 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1470993062 C Ci:3:006:0 0 6 = ffb42c8c 7f40
ffff8c7d7ce5d980 1470993083 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1470994678 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470994699 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1470996300 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1470996321 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1470997912 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471200070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1471201712 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1471201731 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1471203364 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1471203385 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1471205048 C Ci:3:006:0 0 6 = ffb42c8c 7f40
ffff8c7d7ce5d980 1471205069 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1471206664 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471206684 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1471208276 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471208296 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1471209895 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471412067 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1471413727 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1471413747 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1471415382 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1471415403 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1471417070 C Ci:3:006:0 0 6 = ffb42c8d 7f40
ffff8c7d7ce5d980 1471417091 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1471418693 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471418713 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1471420311 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471420331 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1471421927 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471624070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1471625720 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1471625739 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1471627383 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1471627405 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1471629084 C Ci:3:006:0 0 6 = ffb42c8d 7f40
ffff8c7d7ce5d980 1471629105 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1471630701 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471630721 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1471632320 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471632341 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1471633934 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471836075 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1471837735 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1471837754 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1471839387 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1471839407 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1471841083 C Ci:3:006:0 0 6 = ffb42b8d 7f40
ffff8c7d7ce5d980 1471841103 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1471842697 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471842718 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1471844319 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1471844340 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1471845937 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472048071 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1472049714 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1472049734 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1472051367 C Ci:3:006:0 0 1 = 06
ffff8c7d7ce5d980 1472051388 S Ci:3:006:0 s c0 00 fc00 0201 0006 6 <
ffff8c7d7ce5d980 1472053056 C Ci:3:006:0 0 6 = ffb42b8d 7f40
ffff8c7d7ce5d980 1472053078 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1472054673 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472054695 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1472056295 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472056316 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1472057913 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472260078 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1472261734 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1472261753 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1472263394 C Ci:3:006:0 0 1 = 03
ffff8c7d7ce5d980 1472263415 S Ci:3:006:0 s c0 00 fc00 0201 0003 3 <
ffff8c7d7ce5d980 1472265067 C Ci:3:006:0 0 3 = 8d7f40
ffff8c7d7ce5d980 1472265088 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1472266681 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472266702 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1472268300 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472268321 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1472269915 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472472070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1472473714 C Ci:3:006:0 0 1 = 83
ffff8c7d7ce5d980 1472473734 S Ci:3:006:0 s c0 00 fd0b 0201 0001 1 <
ffff8c7d7ce5d980 1472475383 C Ci:3:006:0 0 1 = 05
ffff8c7d7ce5d980 1472475404 S Ci:3:006:0 s c0 00 fc00 0201 0005 5 <
ffff8c7d7ce5d980 1472477081 C Ci:3:006:0 0 5 = 8a2c8d7f 40
ffff8c7d7ce5d980 1472477102 S Co:3:006:0 s 40 00 fd01 0211 0001 1 = 03
ffff8c7d7ce5d980 1472478698 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472478719 S Co:3:006:0 s 40 00 fd09 0211 0001 1 = 80
ffff8c7d7ce5d980 1472480318 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472480339 S Co:3:006:0 s 40 00 fd02 0211 0001 1 = 80
ffff8c7d7ce5d980 1472481934 C Co:3:006:0 0 1 >
ffff8c7d7ce5d980 1472684073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1472685714 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1472888065 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1472889710 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1472921838 C Ii:3:003:1 0:8 4 = 00020000
ffff8c89c3b34900 1472921857 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472929833 C Ii:3:003:1 0:8 4 = 0004ff00
ffff8c89c3b34900 1472929849 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472937833 C Ii:3:003:1 0:8 4 = 0007fe00
ffff8c89c3b34900 1472937849 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472945835 C Ii:3:003:1 0:8 4 = 0007ff00
ffff8c89c3b34900 1472945851 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472953836 C Ii:3:003:1 0:8 4 = 000afe00
ffff8c89c3b34900 1472953852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472961836 C Ii:3:003:1 0:8 4 = 000cff00
ffff8c89c3b34900 1472961852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472969832 C Ii:3:003:1 0:8 4 = 000b0000
ffff8c89c3b34900 1472969848 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472977832 C Ii:3:003:1 0:8 4 = 000b0000
ffff8c89c3b34900 1472977847 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472985837 C Ii:3:003:1 0:8 4 = 000c0000
ffff8c89c3b34900 1472985852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1472993835 C Ii:3:003:1 0:8 4 = 000e0100
ffff8c89c3b34900 1472993852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473001833 C Ii:3:003:1 0:8 4 = 000d0100
ffff8c89c3b34900 1473001848 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473009833 C Ii:3:003:1 0:8 4 = 000c0100
ffff8c89c3b34900 1473009849 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473017837 C Ii:3:003:1 0:8 4 = 000d0100
ffff8c89c3b34900 1473017853 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473025834 C Ii:3:003:1 0:8 4 = 000b0100
ffff8c89c3b34900 1473025850 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473033830 C Ii:3:003:1 0:8 4 = 000a0000
ffff8c89c3b34900 1473033846 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473041832 C Ii:3:003:1 0:8 4 = 000b0000
ffff8c89c3b34900 1473041848 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473049836 C Ii:3:003:1 0:8 4 = 00090100
ffff8c89c3b34900 1473049854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473057837 C Ii:3:003:1 0:8 4 = 00090000
ffff8c89c3b34900 1473057852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473065842 C Ii:3:003:1 0:8 4 = 00080000
ffff8c89c3b34900 1473065857 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473073827 C Ii:3:003:1 0:8 4 = 00070000
ffff8c89c3b34900 1473073843 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473081836 C Ii:3:003:1 0:8 4 = 00060000
ffff8c89c3b34900 1473081852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473089838 C Ii:3:003:1 0:8 4 = 00050000
ffff8c89c3b34900 1473089854 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1473092073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1473093708 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1473097837 C Ii:3:003:1 0:8 4 = 00040000
ffff8c89c3b34900 1473097852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473105837 C Ii:3:003:1 0:8 4 = 00040000
ffff8c89c3b34900 1473105851 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473113836 C Ii:3:003:1 0:8 4 = 00030000
ffff8c89c3b34900 1473113852 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473121838 C Ii:3:003:1 0:8 4 = 00020000
ffff8c89c3b34900 1473121854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473129837 C Ii:3:003:1 0:8 4 = 0003ff00
ffff8c89c3b34900 1473129854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473137839 C Ii:3:003:1 0:8 4 = 00030000
ffff8c89c3b34900 1473137854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473145835 C Ii:3:003:1 0:8 4 = 00030000
ffff8c89c3b34900 1473145849 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473153842 C Ii:3:003:1 0:8 4 = 00020000
ffff8c89c3b34900 1473153857 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473161838 C Ii:3:003:1 0:8 4 = 00010000
ffff8c89c3b34900 1473161853 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473169838 C Ii:3:003:1 0:8 4 = 00010000
ffff8c89c3b34900 1473169853 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1473296066 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1473297699 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1473393843 C Ii:3:003:1 0:8 4 = 00000100
ffff8c89c3b34900 1473393858 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473401838 C Ii:3:003:1 0:8 4 = 00ff0000
ffff8c89c3b34900 1473401854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473417836 C Ii:3:003:1 0:8 4 = 00000100
ffff8c89c3b34900 1473417852 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1473500070 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1473501702 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1473505841 C Ii:3:003:1 0:8 4 = 00ff0100
ffff8c89c3b34900 1473505858 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473513837 C Ii:3:003:1 0:8 4 = 00ff0100
ffff8c89c3b34900 1473513854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473521842 C Ii:3:003:1 0:8 4 = 00fe0100
ffff8c89c3b34900 1473521859 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473529844 C Ii:3:003:1 0:8 4 = 00fd0100
ffff8c89c3b34900 1473529860 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473537844 C Ii:3:003:1 0:8 4 = 00fd0200
ffff8c89c3b34900 1473537861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473545838 C Ii:3:003:1 0:8 4 = 00fd0100
ffff8c89c3b34900 1473545854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473553838 C Ii:3:003:1 0:8 4 = 00fc0200
ffff8c89c3b34900 1473553854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473561845 C Ii:3:003:1 0:8 4 = 00fd0100
ffff8c89c3b34900 1473561861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473569838 C Ii:3:003:1 0:8 4 = 00fb0100
ffff8c89c3b34900 1473569856 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473577837 C Ii:3:003:1 0:8 4 = 00fb0200
ffff8c89c3b34900 1473577854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473585838 C Ii:3:003:1 0:8 4 = 00fa0100
ffff8c89c3b34900 1473585854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473593838 C Ii:3:003:1 0:8 4 = 00fa0100
ffff8c89c3b34900 1473593855 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473601839 C Ii:3:003:1 0:8 4 = 00f70000
ffff8c89c3b34900 1473601855 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473609841 C Ii:3:003:1 0:8 4 = 00f80200
ffff8c89c3b34900 1473609856 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473617838 C Ii:3:003:1 0:8 4 = 00f70100
ffff8c89c3b34900 1473617854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473625840 C Ii:3:003:1 0:8 4 = 00f60200
ffff8c89c3b34900 1473625856 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473633838 C Ii:3:003:1 0:8 4 = 00f70200
ffff8c89c3b34900 1473633856 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473641842 C Ii:3:003:1 0:8 4 = 00f70300
ffff8c89c3b34900 1473641859 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473649838 C Ii:3:003:1 0:8 4 = 00f90200
ffff8c89c3b34900 1473649854 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473657845 C Ii:3:003:1 0:8 4 = 00fa0100
ffff8c89c3b34900 1473657861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473665840 C Ii:3:003:1 0:8 4 = 00fa0200
ffff8c89c3b34900 1473665856 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473673842 C Ii:3:003:1 0:8 4 = 00fc0100
ffff8c89c3b34900 1473673858 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473681842 C Ii:3:003:1 0:8 4 = 00fb0100
ffff8c89c3b34900 1473681858 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473689809 C Ii:3:003:1 0:8 4 = 00fc0100
ffff8c89c3b34900 1473689824 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473697840 C Ii:3:003:1 0:8 4 = 00fb0100
ffff8c89c3b34900 1473697857 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1473704065 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1473705708 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1473705818 C Ii:3:003:1 0:8 4 = 00f90000
ffff8c89c3b34900 1473705832 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473713840 C Ii:3:003:1 0:8 4 = 00fa0100
ffff8c89c3b34900 1473713857 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473721848 C Ii:3:003:1 0:8 4 = 00f90000
ffff8c89c3b34900 1473721863 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473729843 C Ii:3:003:1 0:8 4 = 00f90100
ffff8c89c3b34900 1473729860 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473737843 C Ii:3:003:1 0:8 4 = 00fa0000
ffff8c89c3b34900 1473737859 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473745843 C Ii:3:003:1 0:8 4 = 00fa0100
ffff8c89c3b34900 1473745859 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473753844 C Ii:3:003:1 0:8 4 = 00fc0000
ffff8c89c3b34900 1473753861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473761846 C Ii:3:003:1 0:8 4 = 00fc0100
ffff8c89c3b34900 1473761862 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473769846 C Ii:3:003:1 0:8 4 = 00fd0100
ffff8c89c3b34900 1473769862 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473777843 C Ii:3:003:1 0:8 4 = 00ff0100
ffff8c89c3b34900 1473777860 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1473785843 C Ii:3:003:1 0:8 4 = 00ff0000
ffff8c89c3b34900 1473785859 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1473908072 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1473909713 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1474065853 C Ii:3:003:1 0:8 4 = 00000100
ffff8c89c3b34900 1474065870 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474073847 C Ii:3:003:1 0:8 4 = 00010000
ffff8c89c3b34900 1474073863 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474089846 C Ii:3:003:1 0:8 4 = 00020000
ffff8c89c3b34900 1474089862 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474097844 C Ii:3:003:1 0:8 4 = 00030100
ffff8c89c3b34900 1474097861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474105844 C Ii:3:003:1 0:8 4 = 00030100
ffff8c89c3b34900 1474105860 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1474112067 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1474113701 C Ci:3:006:0 0 1 = 00
ffff8c89c3b34900 1474113851 C Ii:3:003:1 0:8 4 = 00060200
ffff8c89c3b34900 1474113868 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474121848 C Ii:3:003:1 0:8 4 = 00060200
ffff8c89c3b34900 1474121866 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474129850 C Ii:3:003:1 0:8 4 = 00080200
ffff8c89c3b34900 1474129866 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474137845 C Ii:3:003:1 0:8 4 = 00070200
ffff8c89c3b34900 1474137861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474145848 C Ii:3:003:1 0:8 4 = 000a0200
ffff8c89c3b34900 1474145864 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474153848 C Ii:3:003:1 0:8 4 = 00090100
ffff8c89c3b34900 1474153865 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474161847 C Ii:3:003:1 0:8 4 = 00080200
ffff8c89c3b34900 1474161863 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474169846 C Ii:3:003:1 0:8 4 = 00080100
ffff8c89c3b34900 1474169863 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474177846 C Ii:3:003:1 0:8 4 = 00070100
ffff8c89c3b34900 1474177862 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474185845 C Ii:3:003:1 0:8 4 = 00070100
ffff8c89c3b34900 1474185864 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474193845 C Ii:3:003:1 0:8 4 = 00070000
ffff8c89c3b34900 1474193861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474201845 C Ii:3:003:1 0:8 4 = 00060000
ffff8c89c3b34900 1474201862 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474209847 C Ii:3:003:1 0:8 4 = 00060100
ffff8c89c3b34900 1474209862 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474217846 C Ii:3:003:1 0:8 4 = 00040000
ffff8c89c3b34900 1474217861 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474225846 C Ii:3:003:1 0:8 4 = 00040000
ffff8c89c3b34900 1474225862 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474233848 C Ii:3:003:1 0:8 4 = 00020000
ffff8c89c3b34900 1474233863 S Ii:3:003:1 -115:8 4 <
ffff8c89c3b34900 1474241850 C Ii:3:003:1 0:8 4 = 00010000
ffff8c89c3b34900 1474241865 S Ii:3:003:1 -115:8 4 <
ffff8c7d7ce5d980 1474316071 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1474317703 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1474520072 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1474521709 C Ci:3:006:0 0 1 = 00
ffff8c7d7ce5d980 1474724073 S Ci:3:006:0 s c0 00 fd01 0201 0001 1 <
ffff8c7d7ce5d980 1474725716 C Ci:3:006:0 0 1 = 00
[-- Attachment #3: ir-keytable.out --]
[-- Type: text/plain, Size: 1580 bytes --]
Testing events. Please, press CTRL-C to abort.
26046.362562: lirc protocol(nec): scancode = 0x40
26046.362575: event type EV_MSC(0x04): scancode = 0x40
26046.362575: event type EV_KEY(0x01) key_down: KEY_FULL_SCREEN(0x0174)
26046.362575: event type EV_SYN(0x00).
26046.488063: event type EV_KEY(0x01) key_up: KEY_FULL_SCREEN(0x0174)
26046.488063: event type EV_SYN(0x00).
26046.573953: lirc protocol(nec): scancode = 0x40 repeat
26046.573962: event type EV_MSC(0x04): scancode = 0x40
26046.573962: event type EV_SYN(0x00).
26046.785977: lirc protocol(nec): scancode = 0x40 repeat
26046.785985: event type EV_MSC(0x04): scancode = 0x40
26046.785985: event type EV_SYN(0x00).
26046.997980: lirc protocol(nec): scancode = 0x40 repeat
26046.997988: event type EV_MSC(0x04): scancode = 0x40
26046.997988: event type EV_SYN(0x00).
26047.209964: lirc protocol(nec): scancode = 0x40 repeat
26047.209972: event type EV_MSC(0x04): scancode = 0x40
26047.209972: event type EV_SYN(0x00).
26047.421995: lirc protocol(nec): scancode = 0x40 repeat
26047.422003: event type EV_MSC(0x04): scancode = 0x40
26047.422003: event type EV_SYN(0x00).
26047.634003: lirc protocol(nec): scancode = 0x40 repeat
26047.634011: event type EV_MSC(0x04): scancode = 0x40
26047.634011: event type EV_SYN(0x00).
26047.846005: lirc protocol(nec): scancode = 0x40 repeat
26047.846013: event type EV_MSC(0x04): scancode = 0x40
26047.846013: event type EV_SYN(0x00).
26048.057982: lirc protocol(nec): scancode = 0x40 repeat
26048.057990: event type EV_MSC(0x04): scancode = 0x40
26048.057990: event type EV_SYN(0x00).
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-06 11:41 ` Marko Mäkelä
@ 2022-01-13 16:55 ` Sean Young
2022-01-14 6:31 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Sean Young @ 2022-01-13 16:55 UTC (permalink / raw)
To: Marko Mäkelä; +Cc: linux-media
On Thu, Jan 06, 2022 at 01:41:48PM +0200, Marko Mäkelä wrote:
> Wed, Jan 05, 2022 at 09:53:55AM +0000, Sean Young wrote:
> > On Tue, Jan 04, 2022 at 06:07:06PM +0200, Marko Mäkelä wrote:
> > > I tested once more the stock driver (value=200) with the NEC
> > > protocol. The GNOME volume control would only react to the initial
> > > press of the button, not on the repeats. Also in ir-keytable -t, I
> > > only see one key_down/key_up followed by LIRC-only messages:
> > >
> > > 2776.698529: lirc protocol(nec): scancode = 0x1e
> > > 2776.698539: event type EV_MSC(0x04): scancode = 0x1e
> > > 2776.698539: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
> > > 2776.698539: event type EV_SYN(0x00).
> > > 2776.824077: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
> > > 2776.824077: event type EV_SYN(0x00).
> > > 2776.909965: lirc protocol(nec): scancode = 0x1e repeat
> > > 2776.909973: event type EV_MSC(0x04): scancode = 0x1e
> > > 2776.909973: event type EV_SYN(0x00).
> > > 2777.121976: lirc protocol(nec): scancode = 0x1e repeat
> > > 2777.121983: event type EV_MSC(0x04): scancode = 0x1e
> > > 2777.121983: event type EV_SYN(0x00).
> >
> > Here the is such a delay between the the first message and the repeat,
> > that rc-core does not honour the repeat any more.
>
> I repeated the experiment with a stock Debian 5.15.0-2-amd64 kernel (based
> on 5.15.5). First, I checked the RCU with a digital camera. Because the
> blinking of the IR LED appeared a little erratic, I replaced the CR2025 cell
> (voltage=3.25V) with a better one (voltage=3.3V). It got brighter and better
> in the digital viewfinder, but there was no improvement for ir-keytable -t:
>
> Testing events. Please, press CTRL-C to abort.
> 25559.898935: lirc protocol(nec): scancode = 0x1e
> 25559.898948: event type EV_MSC(0x04): scancode = 0x1e
> 25559.898948: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
> 25559.898948: event type EV_SYN(0x00).
> 25560.024055: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
> 25560.024055: event type EV_SYN(0x00).
> 25560.110134: lirc protocol(nec): scancode = 0x1e repeat
> 25560.110141: event type EV_MSC(0x04): scancode = 0x1e
> 25560.110141: event type EV_SYN(0x00).
> 25560.322180: lirc protocol(nec): scancode = 0x1e repeat
> 25560.322188: event type EV_MSC(0x04): scancode = 0x1e
> 25560.322188: event type EV_SYN(0x00).
> 25560.534173: lirc protocol(nec): scancode = 0x1e repeat
> 25560.534180: event type EV_MSC(0x04): scancode = 0x1e
> 25560.534180: event type EV_SYN(0x00).
> 25560.746156: lirc protocol(nec): scancode = 0x1e repeat
> 25560.746163: event type EV_MSC(0x04): scancode = 0x1e
> 25560.746163: event type EV_SYN(0x00).
> 25560.958173: lirc protocol(nec): scancode = 0x1e repeat
> 25560.958181: event type EV_MSC(0x04): scancode = 0x1e
> 25560.958181: event type EV_SYN(0x00).
> 25997.954229: lirc protocol(nec): scancode = 0x1e repeat
> 25997.954241: event type EV_MSC(0x04): scancode = 0x1e
> 25997.954241: event type EV_SYN(0x00).
> 25998.166182: lirc protocol(nec): scancode = 0x1e repeat
> 25998.166189: event type EV_MSC(0x04): scancode = 0x1e
> 25998.166189: event type EV_SYN(0x00).
So I had to dig around for a while, but I have the same device here. After
some experimenting I've written a patch. Please could test it out for me,
a `Tested-by:` would be appreciated (if it works of course!).
Thanks
Sean
---
From f860a05c35a7b0e7b331e61e1b61674c2a9279f0 Mon Sep 17 00:00:00 2001
From: Sean Young <sean@mess.org>
Date: Thu, 13 Jan 2022 16:33:13 +0000
Subject: [PATCH] media: rtl28xxu: improve IR receiver
This device presents an IR buffer, which can be read and cleared.
Clearing the buffer is racey with receiving IR, so wait until the IR
message is finished before clearing it.
This should minimize the chance of the buffer clear happening while
IR is being received, although we cannot avoid this completely.
Signed-off-by: Sean Young <sean@mess.org>
---
drivers/media/usb/dvb-usb-v2/rtl28xxu.c | 26 ++++++++++++++++++++++---
1 file changed, 23 insertions(+), 3 deletions(-)
diff --git a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
index 795a012d4020..f6fc362573d0 100644
--- a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
+++ b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
@@ -1720,6 +1720,7 @@ static int rtl2832u_rc_query(struct dvb_usb_device *d)
{IR_RX_BUF_CTRL, 0x80, 0xff},
{IR_RX_CTRL, 0x80, 0xff},
};
+ u32 idle_length;
/* init remote controller */
if (!dev->rc_active) {
@@ -1770,6 +1771,22 @@ static int rtl2832u_rc_query(struct dvb_usb_device *d)
if (ret)
goto err;
+ dev_dbg(&d->intf->dev, "IR_RX_BUF=%*ph\n", len, buf);
+
+ /* if the receiver is not idle yet, do not process */
+ idle_length = 0;
+ if (len > 2) {
+ if (!(buf[len - 1] & 0x80))
+ idle_length += buf[len - 1] & 0x7f;
+ if (!(buf[len - 2] & 0x80))
+ idle_length += buf[len - 2] & 0x7f;
+ }
+
+ dev_dbg(&d->intf->dev, "idle_length=%x\n", idle_length);
+
+ if (idle_length < 0xbf)
+ return 0;
+
/* let hw receive new code */
for (i = 0; i < ARRAY_SIZE(refresh_tab); i++) {
ret = rtl28xxu_wr_reg_mask(d, refresh_tab[i].reg,
@@ -1807,9 +1824,12 @@ static int rtl2832u_get_rc_config(struct dvb_usb_device *d,
rc->allowed_protos = RC_PROTO_BIT_ALL_IR_DECODER;
rc->driver_type = RC_DRIVER_IR_RAW;
rc->query = rtl2832u_rc_query;
- rc->interval = 200;
- /* we program idle len to 0xc0, set timeout to one less */
- rc->timeout = 0xbf * 51;
+ rc->interval = 50;
+ /*
+ * The idle len is set to 0xc0, set timeout to one less plus
+ * the query interval with some extra margin for error
+ */
+ rc->timeout = 0xbf * 51 + MS_TO_US(60);
return 0;
}
--
2.34.1
^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-13 16:55 ` Sean Young
@ 2022-01-14 6:31 ` Marko Mäkelä
2022-01-29 17:15 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-01-14 6:31 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media
Thu, Jan 13, 2022 at 04:55:52PM +0000, Sean Young wrote:
>So I had to dig around for a while, but I have the same device here.
>After some experimenting I've written a patch. Please could test it out
>for me, a `Tested-by:` would be appreciated (if it works of course!).
It is significantly better for the bundled remote control unit (using
the NEC protocol). But it can still lose events. I tested by holding
down the VOL+ and VOL- keys. Also the GNOME Desktop was listening to
those events, so I got some additional visual feedback.
Here is a trace from ir-keytable -t, using the NEC protocol:
Testing events. Please, press CTRL-C to abort.
261.125938: lirc protocol(nec): scancode = 0x1e
261.125959: event type EV_MSC(0x04): scancode = 0x1e
261.125959: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
261.125959: event type EV_SYN(0x00).
261.189926: lirc protocol(nec): scancode = 0x1e repeat
261.189939: event type EV_MSC(0x04): scancode = 0x1e
261.189939: event type EV_SYN(0x00).
261.309891: lirc protocol(nec): scancode = 0x1e repeat
261.309905: event type EV_MSC(0x04): scancode = 0x1e
261.309905: event type EV_SYN(0x00).
261.429960: lirc protocol(nec): scancode = 0x1e repeat
261.429973: event type EV_MSC(0x04): scancode = 0x1e
261.429973: event type EV_SYN(0x00).
261.553908: lirc protocol(nec): scancode = 0x1e repeat
261.553923: event type EV_MSC(0x04): scancode = 0x1e
261.553923: event type EV_SYN(0x00).
261.617911: lirc protocol(nec): scancode = 0x1e repeat
261.617924: event type EV_MSC(0x04): scancode = 0x1e
261.617924: event type EV_SYN(0x00).
261.628041: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
261.628041: event type EV_SYN(0x00).
261.737970: lirc protocol(nec): scancode = 0x1e repeat
261.628041: event type EV_MSC(0x04): scancode = 0x1e
261.628041: event type EV_SYN(0x00).
261.760048: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
261.760048: event type EV_SYN(0x00).
261.857958: lirc protocol(nec): scancode = 0x1e repeat
261.760048: event type EV_MSC(0x04): scancode = 0x1e
261.760048: event type EV_SYN(0x00).
261.892056: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
261.892056: event type EV_SYN(0x00).
So far, so good. The initial delay between the key_down events is 500ms.
But, keep reading:
262.024055: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
262.024055: event type EV_SYN(0x00).
262.045960: lirc protocol(nec): scancode = 0x1e repeat
262.024055: event type EV_MSC(0x04): scancode = 0x1e
262.024055: event type EV_SYN(0x00).
262.156052: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
262.156052: event type EV_SYN(0x00).
262.156052: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
262.156052: event type EV_SYN(0x00).
264.074505: lirc protocol(nec): scancode = 0x1e repeat
264.074524: event type EV_MSC(0x04): scancode = 0x1e
264.074524: event type EV_SYN(0x00).
264.137961: lirc protocol(nec): scancode = 0xa
264.137979: event type EV_MSC(0x04): scancode = 0x0a
264.137979: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
264.137979: event type EV_SYN(0x00).
264.324062: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
264.324062: event type EV_SYN(0x00).
264.325944: lirc protocol(nec): scancode = 0xa repeat
264.325960: event type EV_MSC(0x04): scancode = 0x0a
264.325960: event type EV_SYN(0x00).
264.445972: lirc protocol(nec): scancode = 0xa repeat
264.445988: event type EV_MSC(0x04): scancode = 0x0a
264.445988: event type EV_SYN(0x00).
264.565937: lirc protocol(nec): scancode = 0xa repeat
264.565952: event type EV_MSC(0x04): scancode = 0x0a
[snip]
266.585974: lirc protocol(nec): scancode = 0xa repeat
266.585989: event type EV_MSC(0x04): scancode = 0x0a
266.585989: event type EV_SYN(0x00).
267.270556: lirc protocol(nec): scancode = 0xa repeat
267.270571: event type EV_MSC(0x04): scancode = 0x0a
267.270571: event type EV_SYN(0x00).
267.389958: lirc protocol(nec): scancode = 0xa
267.389976: event type EV_MSC(0x04): scancode = 0x0a
267.389976: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
267.389976: event type EV_SYN(0x00).
267.509941: lirc protocol(nec): scancode = 0xa repeat
267.509957: event type EV_MSC(0x04): scancode = 0x0a
267.509957: event type EV_SYN(0x00).
267.629971: lirc protocol(nec): scancode = 0xa repeat
267.629986: event type EV_MSC(0x04): scancode = 0x0a
267.629986: event type EV_SYN(0x00).
267.749948: lirc protocol(nec): scancode = 0xa repeat
267.749963: event type EV_MSC(0x04): scancode = 0x0a
267.749963: event type EV_SYN(0x00).
267.873963: lirc protocol(nec): scancode = 0xa repeat
267.873978: event type EV_MSC(0x04): scancode = 0x0a
267.873978: event type EV_SYN(0x00).
267.900054: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
267.900054: event type EV_SYN(0x00).
267.937934: lirc protocol(nec): scancode = 0xa repeat
267.900054: event type EV_MSC(0x04): scancode = 0x0a
267.900054: event type EV_SYN(0x00).
268.032044: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
268.032044: event type EV_SYN(0x00).
Why was there a key_up event at 264.324062 even though I continued to
hold down that button? Maybe shortly before another key_down was finally
generated, I had let the button go and pressed it again.
All in all, I long-pressed VOL+, VOL-, VOL+, VOL-, and only for the
second press (VOL-) I failed to get proper repeat events. So, it almost
works. For comparison, I used the stock kernel module, which never
generated repeat events for the NEC protocol.
Then, I loaded the hauppauge.toml and tested with RC5. It was fairly OK,
except for an anomaly: When I pressed Vol- or Vol+ after just having
long-pressed the other key, I got one more event for the previous key!
Here is a trace of that:
1471.642128: event type EV_MSC(0x04): scancode = 0x1e10
1471.642128: event type EV_SYN(0x00).
1471.676071: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
1471.676071: event type EV_SYN(0x00).
1471.808059: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
1471.808059: event type EV_SYN(0x00).
1471.808059: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
1471.808059: event type EV_SYN(0x00).
1472.266096: lirc protocol(rc5): scancode = 0x1e10 toggle=1
1472.266113: event type EV_MSC(0x04): scancode = 0x1e10
1472.266113: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
1472.266113: event type EV_SYN(0x00).
1472.386062: lirc protocol(rc5): scancode = 0x1e11
1472.386079: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
1472.386079: event type EV_MSC(0x04): scancode = 0x1e11
1472.386079: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
1472.386079: event type EV_SYN(0x00).
1472.450104: lirc protocol(rc5): scancode = 0x1e11
1472.450118: event type EV_MSC(0x04): scancode = 0x1e11
1472.450118: event type EV_SYN(0x00).
1472.570090: lirc protocol(rc5): scancode = 0x1e11
1472.570105: event type EV_MSC(0x04): scancode = 0x1e11
1472.570105: event type EV_SYN(0x00).
1472.760061: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
1472.760061: event type EV_SYN(0x00).
The events between 1472.266096 and 1472.386079 are fake. I only pressed
and released Vol+ once. Once I started to press Vol- I got fake key_down
and key_up for KEY_VOLUMEUP instead of getting the initial message for
KEY_VOLUMEDOWN.
I tried this also with short presses, pressing Vol- and Vol+
alternatively. Almost all of the time, the GNOME volume control widget
reacted by getting exactly the wrong event (from the previous key
press).
>From f860a05c35a7b0e7b331e61e1b61674c2a9279f0 Mon Sep 17 00:00:00 2001
>From: Sean Young <sean@mess.org>
>Date: Thu, 13 Jan 2022 16:33:13 +0000
>Subject: [PATCH] media: rtl28xxu: improve IR receiver
In my opinion, this patch is a significant improvement for decoding the
NEC protocol, as well as for the RC5 protocol, because for that one it
no longer sends key_up events before each repeated key_down event for a
held-down button.
But, for the RC5 decoder, there appears to be a serious regression that
instead of sending the event for the last received message, it will
repeat an event for the previously pressed button.
Best regards,
Marko
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-14 6:31 ` Marko Mäkelä
@ 2022-01-29 17:15 ` Marko Mäkelä
2022-02-08 16:46 ` Sean Young
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-01-29 17:15 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media
Hi Sean,
Did you have a chance to repeat my findings with a remote control unit
that uses the RC5 protocol?
I tried to understand the code changes. A few observations:
In rtl2831u_get_rc_config(), rc->interval is set to 400 and rc->timeout
is not set at all. Maybe it is OK, similar chips supported by the same
driver.
In rtl2832u_rc_query(), the idle_length is being computed from the last
two bytes of the IR_RX_BUF buffer. The threshold is 0xc0 and thus
it can only be exceeded if both last 7-bit bytes are included in the
sum. Side note: the & 0x7f is redundant, because the most significant
bit was already tested to be clear:
idle_length = 0;
if (len > 2) {
if (!(buf[len - 1] & 0x80))
idle_length += buf[len - 1] & 0x7f;
if (!(buf[len - 2] & 0x80))
idle_length += buf[len - 2] & 0x7f;
}
dev_dbg(&d->intf->dev, "idle_length=%x\n", idle_length);
if (idle_length < 0xbf)
return 0;
However, I spotted a potential problem here. I may of course be mistaken
because I do not know how the IR_RX_BUF is supposed to work. Could it
happen that buf[] contains some IR events, then 2 or more consecutive
bytes of no pulses (with the total time exceeding 0xbf*51µs), and then
again some IR events until the very end of the buffer, so that in the
above check, we would return 0? Could we in that case discard some IR
events? Could that explain the glitch that I observed with the NEC
protocol?
Best regards,
Marko
Fri, Jan 14, 2022 at 08:31:37AM +0200, Marko Mäkelä wrote:
>Thu, Jan 13, 2022 at 04:55:52PM +0000, Sean Young wrote:
>>So I had to dig around for a while, but I have the same device here.
>>After some experimenting I've written a patch. Please could test it
>>out for me, a `Tested-by:` would be appreciated (if it works of
>>course!).
>
>It is significantly better for the bundled remote control unit (using
>the NEC protocol). But it can still lose events. I tested by holding
>down the VOL+ and VOL- keys. Also the GNOME Desktop was listening to
>those events, so I got some additional visual feedback.
>
>Here is a trace from ir-keytable -t, using the NEC protocol:
>
>Testing events. Please, press CTRL-C to abort.
>261.125938: lirc protocol(nec): scancode = 0x1e
>261.125959: event type EV_MSC(0x04): scancode = 0x1e
>261.125959: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>261.125959: event type EV_SYN(0x00).
>261.189926: lirc protocol(nec): scancode = 0x1e repeat
>261.189939: event type EV_MSC(0x04): scancode = 0x1e
>261.189939: event type EV_SYN(0x00).
>261.309891: lirc protocol(nec): scancode = 0x1e repeat
>261.309905: event type EV_MSC(0x04): scancode = 0x1e
>261.309905: event type EV_SYN(0x00).
>261.429960: lirc protocol(nec): scancode = 0x1e repeat
>261.429973: event type EV_MSC(0x04): scancode = 0x1e
>261.429973: event type EV_SYN(0x00).
>261.553908: lirc protocol(nec): scancode = 0x1e repeat
>261.553923: event type EV_MSC(0x04): scancode = 0x1e
>261.553923: event type EV_SYN(0x00).
>261.617911: lirc protocol(nec): scancode = 0x1e repeat
>261.617924: event type EV_MSC(0x04): scancode = 0x1e
>261.617924: event type EV_SYN(0x00).
>261.628041: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>261.628041: event type EV_SYN(0x00).
>261.737970: lirc protocol(nec): scancode = 0x1e repeat
>261.628041: event type EV_MSC(0x04): scancode = 0x1e
>261.628041: event type EV_SYN(0x00).
>261.760048: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>261.760048: event type EV_SYN(0x00).
>261.857958: lirc protocol(nec): scancode = 0x1e repeat
>261.760048: event type EV_MSC(0x04): scancode = 0x1e
>261.760048: event type EV_SYN(0x00).
>261.892056: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>261.892056: event type EV_SYN(0x00).
>
>So far, so good. The initial delay between the key_down events is
>500ms. But, keep reading:
>
>262.024055: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>262.024055: event type EV_SYN(0x00).
>262.045960: lirc protocol(nec): scancode = 0x1e repeat
>262.024055: event type EV_MSC(0x04): scancode = 0x1e
>262.024055: event type EV_SYN(0x00).
>262.156052: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>262.156052: event type EV_SYN(0x00).
>262.156052: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
>262.156052: event type EV_SYN(0x00).
>264.074505: lirc protocol(nec): scancode = 0x1e repeat
>264.074524: event type EV_MSC(0x04): scancode = 0x1e
>264.074524: event type EV_SYN(0x00).
>264.137961: lirc protocol(nec): scancode = 0xa
>264.137979: event type EV_MSC(0x04): scancode = 0x0a
>264.137979: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
>264.137979: event type EV_SYN(0x00).
>264.324062: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
>264.324062: event type EV_SYN(0x00).
>264.325944: lirc protocol(nec): scancode = 0xa repeat
>264.325960: event type EV_MSC(0x04): scancode = 0x0a
>264.325960: event type EV_SYN(0x00).
>264.445972: lirc protocol(nec): scancode = 0xa repeat
>264.445988: event type EV_MSC(0x04): scancode = 0x0a
>264.445988: event type EV_SYN(0x00).
>264.565937: lirc protocol(nec): scancode = 0xa repeat
>264.565952: event type EV_MSC(0x04): scancode = 0x0a
>[snip]
>266.585974: lirc protocol(nec): scancode = 0xa repeat
>266.585989: event type EV_MSC(0x04): scancode = 0x0a
>266.585989: event type EV_SYN(0x00).
>267.270556: lirc protocol(nec): scancode = 0xa repeat
>267.270571: event type EV_MSC(0x04): scancode = 0x0a
>267.270571: event type EV_SYN(0x00).
>267.389958: lirc protocol(nec): scancode = 0xa
>267.389976: event type EV_MSC(0x04): scancode = 0x0a
>267.389976: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
>267.389976: event type EV_SYN(0x00).
>267.509941: lirc protocol(nec): scancode = 0xa repeat
>267.509957: event type EV_MSC(0x04): scancode = 0x0a
>267.509957: event type EV_SYN(0x00).
>267.629971: lirc protocol(nec): scancode = 0xa repeat
>267.629986: event type EV_MSC(0x04): scancode = 0x0a
>267.629986: event type EV_SYN(0x00).
>267.749948: lirc protocol(nec): scancode = 0xa repeat
>267.749963: event type EV_MSC(0x04): scancode = 0x0a
>267.749963: event type EV_SYN(0x00).
>267.873963: lirc protocol(nec): scancode = 0xa repeat
>267.873978: event type EV_MSC(0x04): scancode = 0x0a
>267.873978: event type EV_SYN(0x00).
>267.900054: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
>267.900054: event type EV_SYN(0x00).
>267.937934: lirc protocol(nec): scancode = 0xa repeat
>267.900054: event type EV_MSC(0x04): scancode = 0x0a
>267.900054: event type EV_SYN(0x00).
>268.032044: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
>268.032044: event type EV_SYN(0x00).
>
>Why was there a key_up event at 264.324062 even though I continued to
>hold down that button? Maybe shortly before another key_down was
>finally generated, I had let the button go and pressed it again.
>
>All in all, I long-pressed VOL+, VOL-, VOL+, VOL-, and only for the
>second press (VOL-) I failed to get proper repeat events. So, it
>almost works. For comparison, I used the stock kernel module, which
>never generated repeat events for the NEC protocol.
>
>Then, I loaded the hauppauge.toml and tested with RC5. It was fairly
>OK, except for an anomaly: When I pressed Vol- or Vol+ after just
>having long-pressed the other key, I got one more event for the
>previous key! Here is a trace of that:
>
>1471.642128: event type EV_MSC(0x04): scancode = 0x1e10
>1471.642128: event type EV_SYN(0x00).
>1471.676071: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>1471.676071: event type EV_SYN(0x00).
>1471.808059: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>1471.808059: event type EV_SYN(0x00).
>1471.808059: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
>1471.808059: event type EV_SYN(0x00).
>1472.266096: lirc protocol(rc5): scancode = 0x1e10 toggle=1
>1472.266113: event type EV_MSC(0x04): scancode = 0x1e10
>1472.266113: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
>1472.266113: event type EV_SYN(0x00).
>1472.386062: lirc protocol(rc5): scancode = 0x1e11
>1472.386079: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
>1472.386079: event type EV_MSC(0x04): scancode = 0x1e11
>1472.386079: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
>1472.386079: event type EV_SYN(0x00).
>1472.450104: lirc protocol(rc5): scancode = 0x1e11
>1472.450118: event type EV_MSC(0x04): scancode = 0x1e11
>1472.450118: event type EV_SYN(0x00).
>1472.570090: lirc protocol(rc5): scancode = 0x1e11
>1472.570105: event type EV_MSC(0x04): scancode = 0x1e11
>1472.570105: event type EV_SYN(0x00).
>1472.760061: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
>1472.760061: event type EV_SYN(0x00).
>
>The events between 1472.266096 and 1472.386079 are fake. I only
>pressed and released Vol+ once. Once I started to press Vol- I got
>fake key_down and key_up for KEY_VOLUMEUP instead of getting the
>initial message for KEY_VOLUMEDOWN.
>
>I tried this also with short presses, pressing Vol- and Vol+
>alternatively. Almost all of the time, the GNOME volume control widget
>reacted by getting exactly the wrong event (from the previous key
>press).
>
>>From f860a05c35a7b0e7b331e61e1b61674c2a9279f0 Mon Sep 17 00:00:00 2001
>>From: Sean Young <sean@mess.org>
>>Date: Thu, 13 Jan 2022 16:33:13 +0000
>>Subject: [PATCH] media: rtl28xxu: improve IR receiver
>
>In my opinion, this patch is a significant improvement for decoding
>the NEC protocol, as well as for the RC5 protocol, because for that
>one it no longer sends key_up events before each repeated key_down
>event for a held-down button.
>
>But, for the RC5 decoder, there appears to be a serious regression
>that instead of sending the event for the last received message, it
>will repeat an event for the previously pressed button.
>
>Best regards,
>
> Marko
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-01-29 17:15 ` Marko Mäkelä
@ 2022-02-08 16:46 ` Sean Young
2022-02-09 8:12 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Sean Young @ 2022-02-08 16:46 UTC (permalink / raw)
To: Marko Mäkelä; +Cc: Antti Palosaari, linux-media
Hi Marko,
On Sat, Jan 29, 2022 at 07:15:57PM +0200, Marko Mäkelä wrote:
> Hi Sean,
>
> Did you have a chance to repeat my findings with a remote control unit that
> uses the RC5 protocol?
Yes, I've reproduced the problem now. It's very weird.
After pressing button 1, waiting for a second or two, and then pressing button
3, the device reports some old IR from button 1 before reporting the IR from
button 3.
The IR is not a copy of old data, it so presumably its IR that was not
reported before. Now I don't know why this IR gets reported so late.
> I tried to understand the code changes. A few observations:
>
> In rtl2831u_get_rc_config(), rc->interval is set to 400 and rc->timeout is
> not set at all. Maybe it is OK, similar chips supported by the same driver.
The timeout won't have an affect on this problem.
> In rtl2832u_rc_query(), the idle_length is being computed from the last two
> bytes of the IR_RX_BUF buffer. The threshold is 0xc0 and thus
> it can only be exceeded if both last 7-bit bytes are included in the sum.
> Side note: the & 0x7f is redundant, because the most significant bit was
> already tested to be clear:
>
> idle_length = 0;
> if (len > 2) {
> if (!(buf[len - 1] & 0x80))
> idle_length += buf[len - 1] & 0x7f;
> if (!(buf[len - 2] & 0x80))
> idle_length += buf[len - 2] & 0x7f;
> }
>
> dev_dbg(&d->intf->dev, "idle_length=%x\n", idle_length);
>
> if (idle_length < 0xbf)
> return 0;
Yes, you are right. Note that I've observed this problem also we did not
enter the early return here (which I introduced).
> However, I spotted a potential problem here. I may of course be mistaken
> because I do not know how the IR_RX_BUF is supposed to work. Could it happen
> that buf[] contains some IR events, then 2 or more consecutive bytes of no
> pulses (with the total time exceeding 0xbf*51µs), and then again some IR
> events until the very end of the buffer, so that in the above check, we
> would return 0?
I have not seen this happen. You can enable debugging for this using:
echo 'file rtl28xxu.c +p' > /sys/kernel/debug/dynamic_debug/control
dmesg -w
I do not know exactly how the buffer works, only some experimentation will
help here. Unless there is a vendor driver/documentation for this device.
> Could we in that case discard some IR events? Could that
> explain the glitch that I observed with the NEC protocol?
I'm not really sure this is the problem, that's what not what I observed.
Sean
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-02-08 16:46 ` Sean Young
@ 2022-02-09 8:12 ` Marko Mäkelä
2022-02-12 11:16 ` Sean Young
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-02-09 8:12 UTC (permalink / raw)
To: Sean Young; +Cc: Antti Palosaari, linux-media
Hi Sean,
Tue, Feb 08, 2022 at 04:46:31PM +0000, Sean Young wrote:
>Hi Marko,
>
>On Sat, Jan 29, 2022 at 07:15:57PM +0200, Marko Mäkelä wrote:
>> Hi Sean,
>>
>> Did you have a chance to repeat my findings with a remote control unit that
>> uses the RC5 protocol?
>
>Yes, I've reproduced the problem now. It's very weird.
>
>After pressing button 1, waiting for a second or two, and then pressing button
>3, the device reports some old IR from button 1 before reporting the IR from
>button 3.
>
>The IR is not a copy of old data, it so presumably its IR that was not
>reported before. Now I don't know why this IR gets reported so late.
When I repeated the problem, the delay between subsequent button presses
could have been even less than a second.
How did you determine that it is not a copy of old data? I assume that
you can do that fairly easily for any kernel-side buffers, but what
about the buffer on the USB device itself?
[snip]
>I have not seen this happen. You can enable debugging for this using:
>
>echo 'file rtl28xxu.c +p' > /sys/kernel/debug/dynamic_debug/control
>
>dmesg -w
Thank you. It might take me some time to return to this.
>I do not know exactly how the buffer works, only some experimentation
>will help here. Unless there is a vendor driver/documentation for this
>device.
I am just guessing here, since I do not have any experience with USB
programming, and hardly any experience with the Linux kernel. Could it
be that the IR samples are being stored in a ring buffer, and the device
does not implicitly discard IR events as it is sending them to the USB
host? A simple test could be to read the buffer twice in a row. Will it
return the same contents, instead of returning nothing on the second
read?
If my ring buffer hypothesis holds, perhaps the kernel driver should
keep track on where the data ended on the previous read, re-read the
device's entire ring buffer, and resume parsing from the previous end of
the ring buffer? In that way, we should not see phantom old events.
Best regards,
Marko
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-02-09 8:12 ` Marko Mäkelä
@ 2022-02-12 11:16 ` Sean Young
2022-02-12 16:34 ` Sean Young
0 siblings, 1 reply; 17+ messages in thread
From: Sean Young @ 2022-02-12 11:16 UTC (permalink / raw)
To: Marko Mäkelä; +Cc: Antti Palosaari, linux-media
Hi Marko,
On Wed, Feb 09, 2022 at 10:12:34AM +0200, Marko Mäkelä wrote:
> Tue, Feb 08, 2022 at 04:46:31PM +0000, Sean Young wrote:
> > On Sat, Jan 29, 2022 at 07:15:57PM +0200, Marko Mäkelä wrote:
> > > Did you have a chance to repeat my findings with a remote control unit that
> > > uses the RC5 protocol?
> >
> > Yes, I've reproduced the problem now. It's very weird.
> >
> > After pressing button 1, waiting for a second or two, and then pressing button
> > 3, the device reports some old IR from button 1 before reporting the IR from
> > button 3.
> >
> > The IR is not a copy of old data, it so presumably its IR that was not
> > reported before. Now I don't know why this IR gets reported so late.
>
> When I repeated the problem, the delay between subsequent button presses
> could have been even less than a second.
>
> How did you determine that it is not a copy of old data? I assume that you
> can do that fairly easily for any kernel-side buffers, but what about the
> buffer on the USB device itself?
I've spent some more time debugging this. The problem is that we need to
increase the timeout to prevent key up events from arriving to early, but
the same timeout is used for the raw IR timeout.
I think rc-core needs a little refactoring to split out the timeout into
keyup_timeout and rawir_timeout. For this driver, the rawir_timeout needs
to be set to 0xbf * 51us, and the keyup_timeout to the query interval
(which 200ms).
My patch increased the timeout to 210ms but the IR receiver never sends
a space that long. So this IR will only get processed once *more* IR
arrives, so you get ghost key presses.
Sean
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-02-12 11:16 ` Sean Young
@ 2022-02-12 16:34 ` Sean Young
2022-02-13 17:12 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Sean Young @ 2022-02-12 16:34 UTC (permalink / raw)
To: Marko Mäkelä; +Cc: linux-media
Hi Marko,
On Sat, Feb 12, 2022 at 11:16:21AM +0000, Sean Young wrote:
> On Wed, Feb 09, 2022 at 10:12:34AM +0200, Marko Mäkelä wrote:
> > Tue, Feb 08, 2022 at 04:46:31PM +0000, Sean Young wrote:
> > > On Sat, Jan 29, 2022 at 07:15:57PM +0200, Marko Mäkelä wrote:
> > > > Did you have a chance to repeat my findings with a remote control unit that
> > > > uses the RC5 protocol?
> > >
> > > Yes, I've reproduced the problem now. It's very weird.
> > >
> > > After pressing button 1, waiting for a second or two, and then pressing button
> > > 3, the device reports some old IR from button 1 before reporting the IR from
> > > button 3.
> > >
> > > The IR is not a copy of old data, it so presumably its IR that was not
> > > reported before. Now I don't know why this IR gets reported so late.
> >
> > When I repeated the problem, the delay between subsequent button presses
> > could have been even less than a second.
> >
> > How did you determine that it is not a copy of old data? I assume that you
> > can do that fairly easily for any kernel-side buffers, but what about the
> > buffer on the USB device itself?
>
> I've spent some more time debugging this. The problem is that we need to
> increase the timeout to prevent key up events from arriving to early, but
> the same timeout is used for the raw IR timeout.
So I've sent two patches (you're on the cc) which should fix the issue. Please
can you test if this solves the issue?
These patches touch nearly every rc-core driver so they will need a good
testing.
Thanks
Sean
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-02-12 16:34 ` Sean Young
@ 2022-02-13 17:12 ` Marko Mäkelä
2022-03-26 18:44 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-02-13 17:12 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media
Hi Sean,
>>I've spent some more time debugging this. The problem is that we need
>>to increase the timeout to prevent key up events from arriving to
>>early, but the same timeout is used for the raw IR timeout.
>
>So I've sent two patches (you're on the cc) which should fix the issue.
>Please can you test if this solves the issue?
It is a significant improvement. Alas, I was able to repeat a glitch
with both the RC5 and NEC protocols. I was testing the key-repeat events
for the volume control. For both remotes, a sequence was lost every now
and then. Here is the output of "sudo ir-keytable -t" for both. I used
the default repeat period of 125ms, but I also repeated it with 100ms.
First, the RC5 remote:
135.157621: lirc protocol(rc5): scancode = 0x1e10 toggle=1
135.115390: event type EV_MSC(0x04): scancode = 0x1e10
135.115390: event type EV_SYN(0x00).
135.247388: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
135.247388: event type EV_SYN(0x00).
135.379387: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
135.379387: event type EV_SYN(0x00).
135.379387: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
135.379387: event type EV_SYN(0x00).
135.477638: lirc protocol(rc5): scancode = 0x1e11
135.477656: event type EV_MSC(0x04): scancode = 0x1e11
135.477656: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
135.477656: event type EV_SYN(0x00).
135.707404: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
135.707404: event type EV_SYN(0x00).
136.261605: lirc protocol(rc5): scancode = 0x1e11
136.261623: event type EV_MSC(0x04): scancode = 0x1e11
136.261623: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
136.261623: event type EV_SYN(0x00).
136.491396: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
136.491396: event type EV_SYN(0x00).
137.621640: lirc protocol(rc5): scancode = 0x1e11 toggle=1
137.621659: event type EV_MSC(0x04): scancode = 0x1e11
137.621659: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
137.621659: event type EV_SYN(0x00).
137.851403: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
137.851403: event type EV_SYN(0x00).
138.853651: lirc protocol(rc5): scancode = 0x1e11 toggle=1
138.853670: event type EV_MSC(0x04): scancode = 0x1e11
138.853670: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
138.853670: event type EV_SYN(0x00).
138.965618: lirc protocol(rc5): scancode = 0x1e11 toggle=1
138.965635: event type EV_MSC(0x04): scancode = 0x1e11
138.965635: event type EV_SYN(0x00).
139.077652: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.077670: event type EV_MSC(0x04): scancode = 0x1e11
139.077670: event type EV_SYN(0x00).
139.189646: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.189664: event type EV_MSC(0x04): scancode = 0x1e11
139.189664: event type EV_SYN(0x00).
139.301668: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.301684: event type EV_MSC(0x04): scancode = 0x1e11
139.301684: event type EV_SYN(0x00).
139.383390: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
139.383390: event type EV_SYN(0x00).
139.413590: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.383390: event type EV_MSC(0x04): scancode = 0x1e11
139.383390: event type EV_SYN(0x00).
139.515385: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
139.515385: event type EV_SYN(0x00).
139.525651: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.515385: event type EV_MSC(0x04): scancode = 0x1e11
139.515385: event type EV_SYN(0x00).
139.637630: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.637646: event type EV_MSC(0x04): scancode = 0x1e11
139.637646: event type EV_SYN(0x00).
139.647387: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
139.647387: event type EV_SYN(0x00).
139.749562: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.647387: event type EV_MSC(0x04): scancode = 0x1e11
139.647387: event type EV_SYN(0x00).
139.779387: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
139.779387: event type EV_SYN(0x00).
139.861680: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.779387: event type EV_MSC(0x04): scancode = 0x1e11
139.779387: event type EV_SYN(0x00).
139.911392: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
139.911392: event type EV_SYN(0x00).
139.973654: lirc protocol(rc5): scancode = 0x1e11 toggle=1
139.911392: event type EV_MSC(0x04): scancode = 0x1e11
139.911392: event type EV_SYN(0x00).
140.043399: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
140.043399: event type EV_SYN(0x00).
140.175392: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
140.175392: event type EV_SYN(0x00).
140.175392: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
140.175392: event type EV_SYN(0x00).
Then, the NEC remote:
Testing events. Please, press CTRL-C to abort.
312.477881: lirc protocol(nec): scancode = 0x1e
312.477894: event type EV_MSC(0x04): scancode = 0x1e
312.477894: event type EV_KEY(0x01) key_down: KEY_VOLUMEUP(0x0073)
312.477894: event type EV_SYN(0x00).
312.703402: event type EV_KEY(0x01) key_up: KEY_VOLUMEUP(0x0073)
312.703402: event type EV_SYN(0x00).
313.033303: lirc protocol(nec): scancode = 0x1e repeat
313.033312: event type EV_MSC(0x04): scancode = 0x1e
313.033312: event type EV_SYN(0x00).
314.497859: lirc protocol(nec): scancode = 0xa
314.497872: event type EV_MSC(0x04): scancode = 0x0a
314.497872: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
314.497872: event type EV_SYN(0x00).
314.609316: lirc protocol(nec): scancode = 0xa repeat
314.609325: event type EV_MSC(0x04): scancode = 0x0a
314.609325: event type EV_SYN(0x00).
314.721305: lirc protocol(nec): scancode = 0xa repeat
314.721313: event type EV_MSC(0x04): scancode = 0x0a
314.721313: event type EV_SYN(0x00).
314.833272: lirc protocol(nec): scancode = 0xa repeat
314.833280: event type EV_MSC(0x04): scancode = 0x0a
314.833280: event type EV_SYN(0x00).
314.945342: lirc protocol(nec): scancode = 0xa repeat
314.945350: event type EV_MSC(0x04): scancode = 0x0a
314.945350: event type EV_SYN(0x00).
314.999394: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
314.999394: event type EV_SYN(0x00).
315.131392: event type EV_KEY(0x01) key_down: KEY_VOLUMEDOWN(0x0072)
315.131392: event type EV_SYN(0x00).
315.131392: event type EV_KEY(0x01) key_up: KEY_VOLUMEDOWN(0x0072)
315.131392: event type EV_SYN(0x00).
315.277279: lirc protocol(nec): scancode = 0xa repeat
315.277289: event type EV_MSC(0x04): scancode = 0x0a
315.277289: event type EV_SYN(0x00).
315.497281: lirc protocol(nec): scancode = 0xa repeat
315.497290: event type EV_MSC(0x04): scancode = 0x0a
315.497290: event type EV_SYN(0x00).
315.717281: lirc protocol(nec): scancode = 0xa repeat
315.717290: event type EV_MSC(0x04): scancode = 0x0a
315.717290: event type EV_SYN(0x00).
315.829305: lirc protocol(nec): scancode = 0xa repeat
315.829314: event type EV_MSC(0x04): scancode = 0x0a
315.829314: event type EV_SYN(0x00).
315.941310: lirc protocol(nec): scancode = 0xa repeat
315.941319: event type EV_MSC(0x04): scancode = 0x0a
315.941319: event type EV_SYN(0x00).
316.053285: lirc protocol(nec): scancode = 0xa repeat
316.053294: event type EV_MSC(0x04): scancode = 0x0a
316.053294: event type EV_SYN(0x00).
316.165247: lirc protocol(nec): scancode = 0xa repeat
316.165256: event type EV_MSC(0x04): scancode = 0x0a
316.165256: event type EV_SYN(0x00).
316.277254: lirc protocol(nec): scancode = 0xa repeat
316.277263: event type EV_MSC(0x04): scancode = 0x0a
316.277263: event type EV_SYN(0x00).
316.389266: lirc protocol(nec): scancode = 0xa repeat
316.389274: event type EV_MSC(0x04): scancode = 0x0a
316.389274: event type EV_SYN(0x00).
316.501288: lirc protocol(nec): scancode = 0xa repeat
316.501296: event type EV_MSC(0x04): scancode = 0x0a
316.501296: event type EV_SYN(0x00).
316.613317: lirc protocol(nec): scancode = 0xa repeat
316.613326: event type EV_MSC(0x04): scancode = 0x0a
316.613326: event type EV_SYN(0x00).
316.725342: lirc protocol(nec): scancode = 0xa repeat
316.725350: event type EV_MSC(0x04): scancode = 0x0a
316.725350: event type EV_SYN(0x00).
316.837272: lirc protocol(nec): scancode = 0xa repeat
316.837281: event type EV_MSC(0x04): scancode = 0x0a
316.837281: event type EV_SYN(0x00).
316.949298: lirc protocol(nec): scancode = 0xa repeat
316.949307: event type EV_MSC(0x04): scancode = 0x0a
316.949307: event type EV_SYN(0x00).
317.061320: lirc protocol(nec): scancode = 0xa repeat
317.061328: event type EV_MSC(0x04): scancode = 0x0a
317.061328: event type EV_SYN(0x00).
317.173318: lirc protocol(nec): scancode = 0xa repeat
317.173327: event type EV_MSC(0x04): scancode = 0x0a
317.173327: event type EV_SYN(0x00).
317.285274: lirc protocol(nec): scancode = 0xa repeat
317.285283: event type EV_MSC(0x04): scancode = 0x0a
317.285283: event type EV_SYN(0x00).
317.397277: lirc protocol(nec): scancode = 0xa repeat
317.397285: event type EV_MSC(0x04): scancode = 0x0a
317.397285: event type EV_SYN(0x00).
317.509317: lirc protocol(nec): scancode = 0xa repeat
317.509325: event type EV_MSC(0x04): scancode = 0x0a
317.509325: event type EV_SYN(0x00).
317.621282: lirc protocol(nec): scancode = 0xa repeat
317.621291: event type EV_MSC(0x04): scancode = 0x0a
317.621291: event type EV_SYN(0x00).
317.733293: lirc protocol(nec): scancode = 0xa repeat
317.733302: event type EV_MSC(0x04): scancode = 0x0a
317.733302: event type EV_SYN(0x00).
317.845315: lirc protocol(nec): scancode = 0xa repeat
317.845324: event type EV_MSC(0x04): scancode = 0x0a
317.845324: event type EV_SYN(0x00).
Possibly related to this: A long time ago when I was involved with
formal methods in theoretical computer science, timers or timeouts would
make me nervous due to the inherent state space explosion. In model
checking, a timed event can be modeled with nondeterminism: in every
state where the event is enabled, it may or may not be executed. So, in
theory, timers or timeouts could open more room for race conditions or
starvation. In practice, if multiple timers are driven from the same
clock source, it should not be that bad.
>These patches touch nearly every rc-core driver so they will need a
>good testing.
Should this allow the key repeat period to be set to exactly match the
IR message rate, to get a consistent response rate? Or is there a small
probability that a key-down or key-up event will be delayed by exactly
one RC5 time slot?
Marko
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-02-13 17:12 ` Marko Mäkelä
@ 2022-03-26 18:44 ` Marko Mäkelä
2022-04-10 14:07 ` Marko Mäkelä
0 siblings, 1 reply; 17+ messages in thread
From: Marko Mäkelä @ 2022-03-26 18:44 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media
Hi Sean,
Sun, Feb 13, 2022 at 07:12:46PM +0200, Marko Mäkelä wrote:
>Hi Sean,
>
>>>I've spent some more time debugging this. The problem is that we
>>>need to increase the timeout to prevent key up events from
>>>arriving to early, but the same timeout is used for the raw IR
>>>timeout.
>>
>>So I've sent two patches (you're on the cc) which should fix the
>>issue. Please can you test if this solves the issue?
>
>It is a significant improvement. Alas, I was able to repeat a glitch
>with both the RC5 and NEC protocols. I was testing the key-repeat
>events for the volume control. For both remotes, a sequence was lost
>every now and then. Here is the output of "sudo ir-keytable -t" for
>both. I used the default repeat period of 125ms, but I also repeated
>it with 100ms.
I tested this once more, applying your 2 commits to the 5.17.0 kernel,
and I still observe the error that even though I hold a button
depressed, a key_up event will be delivered. The LIRC protocol events
appear to be generated fine.
Here is some "ir-keytable -t" output for the bundled remote control that
uses the NEC protocol.
2977.094816: lirc protocol(nec): scancode = 0x9
2977.094825: event type EV_MSC(0x04): scancode = 0x09
2977.094825: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2977.094825: event type EV_SYN(0x00).
2977.206201: lirc protocol(nec): scancode = 0x9 repeat
2977.206214: event type EV_MSC(0x04): scancode = 0x09
2977.206214: event type EV_SYN(0x00).
2977.318205: lirc protocol(nec): scancode = 0x9 repeat
2977.318217: event type EV_MSC(0x04): scancode = 0x09
2977.318217: event type EV_SYN(0x00).
2977.430187: lirc protocol(nec): scancode = 0x9 repeat
2977.430199: event type EV_MSC(0x04): scancode = 0x09
2977.430199: event type EV_SYN(0x00).
2977.542185: lirc protocol(nec): scancode = 0x9 repeat
2977.542197: event type EV_MSC(0x04): scancode = 0x09
2977.542197: event type EV_SYN(0x00).
2977.596054: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2977.596054: event type EV_SYN(0x00).
2977.654185: lirc protocol(nec): scancode = 0x9 repeat
2977.596054: event type EV_MSC(0x04): scancode = 0x09
2977.596054: event type EV_SYN(0x00).
2977.728050: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2977.728050: event type EV_SYN(0x00).
2977.766185: lirc protocol(nec): scancode = 0x9 repeat
2977.728050: event type EV_MSC(0x04): scancode = 0x09
2977.728050: event type EV_SYN(0x00).
2977.860047: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2977.860047: event type EV_SYN(0x00).
2977.878185: lirc protocol(nec): scancode = 0x9 repeat
2977.860047: event type EV_MSC(0x04): scancode = 0x09
2977.860047: event type EV_SYN(0x00).
2977.990153: lirc protocol(nec): scancode = 0x9 repeat
2977.990164: event type EV_MSC(0x04): scancode = 0x09
2977.990164: event type EV_SYN(0x00).
2977.992053: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2977.992053: event type EV_SYN(0x00).
2978.102203: lirc protocol(nec): scancode = 0x9 repeat
2977.992053: event type EV_MSC(0x04): scancode = 0x09
2977.992053: event type EV_SYN(0x00).
2978.124054: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.124054: event type EV_SYN(0x00).
2978.214192: lirc protocol(nec): scancode = 0x9 repeat
2978.124054: event type EV_MSC(0x04): scancode = 0x09
2978.124054: event type EV_SYN(0x00).
2978.260047: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.260047: event type EV_SYN(0x00).
2978.326193: lirc protocol(nec): scancode = 0x9 repeat
2978.260047: event type EV_MSC(0x04): scancode = 0x09
2978.260047: event type EV_SYN(0x00).
2978.396006: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.396006: event type EV_SYN(0x00).
2978.440131: lirc protocol(nec): scancode = 0x9 repeat
2978.396006: event type EV_MSC(0x04): scancode = 0x09
2978.396006: event type EV_SYN(0x00).
2978.528049: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.528049: event type EV_SYN(0x00).
2978.554229: lirc protocol(nec): scancode = 0x9 repeat
2978.528049: event type EV_MSC(0x04): scancode = 0x09
2978.528049: event type EV_SYN(0x00).
2978.660049: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.660049: event type EV_SYN(0x00).
2978.666239: lirc protocol(nec): scancode = 0x9 repeat
2978.660049: event type EV_MSC(0x04): scancode = 0x09
2978.660049: event type EV_SYN(0x00).
2978.778158: lirc protocol(nec): scancode = 0x9 repeat
2978.778169: event type EV_MSC(0x04): scancode = 0x09
2978.778169: event type EV_SYN(0x00).
2978.796049: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.796049: event type EV_SYN(0x00).
2978.928053: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.928053: event type EV_SYN(0x00).
2978.928053: event type EV_KEY(0x01) key_up: KEY_NUMERIC_1(0x0201)
2978.928053: event type EV_SYN(0x00).
2979.334204: lirc protocol(nec): scancode = 0x9 repeat
2979.334218: event type EV_MSC(0x04): scancode = 0x09
2979.334218: event type EV_SYN(0x00).
2979.554215: lirc protocol(nec): scancode = 0x9 repeat
2979.554229: event type EV_MSC(0x04): scancode = 0x09
2979.554229: event type EV_SYN(0x00).
2979.666173: lirc protocol(nec): scancode = 0x9 repeat
2979.666185: event type EV_MSC(0x04): scancode = 0x09
2979.666185: event type EV_SYN(0x00).
2979.778232: lirc protocol(nec): scancode = 0x9 repeat
2979.778243: event type EV_MSC(0x04): scancode = 0x09
2979.778243: event type EV_SYN(0x00).
2979.890230: lirc protocol(nec): scancode = 0x9 repeat
2979.890241: event type EV_MSC(0x04): scancode = 0x09
2979.890241: event type EV_SYN(0x00).
2980.002258: lirc protocol(nec): scancode = 0x9 repeat
2980.002269: event type EV_MSC(0x04): scancode = 0x09
2980.002269: event type EV_SYN(0x00).
2980.114226: lirc protocol(nec): scancode = 0x9 repeat
2980.114237: event type EV_MSC(0x04): scancode = 0x09
2980.114237: event type EV_SYN(0x00).
2980.226200: lirc protocol(nec): scancode = 0x9 repeat
2980.226212: event type EV_MSC(0x04): scancode = 0x09
2980.226212: event type EV_SYN(0x00).
2980.338197: lirc protocol(nec): scancode = 0x9 repeat
2980.338210: event type EV_MSC(0x04): scancode = 0x09
2980.338210: event type EV_SYN(0x00).
2980.450191: lirc protocol(nec): scancode = 0x9 repeat
2980.450203: event type EV_MSC(0x04): scancode = 0x09
2980.450203: event type EV_SYN(0x00).
2980.562195: lirc protocol(nec): scancode = 0x9 repeat
2980.562206: event type EV_MSC(0x04): scancode = 0x09
2980.562206: event type EV_SYN(0x00).
As you can see, LIRC events will be produced, but there were only
intermittent key_down events, and a premature key_up event while I was
holding the key down.
Above, I would like to emphasize the following glitch. Not only we got a
premature key_up while I held the button depressed, but that event was
generated at the very same timestamp with a key_down.
2978.778158: lirc protocol(nec): scancode = 0x9 repeat
2978.778169: event type EV_MSC(0x04): scancode = 0x09
2978.778169: event type EV_SYN(0x00).
2978.796049: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.796049: event type EV_SYN(0x00).
2978.928053: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
2978.928053: event type EV_SYN(0x00).
2978.928053: event type EV_KEY(0x01) key_up: KEY_NUMERIC_1(0x0201)
2978.928053: event type EV_SYN(0x00).
2979.334204: lirc protocol(nec): scancode = 0x9 repeat
2979.334218: event type EV_MSC(0x04): scancode = 0x09
2979.334218: event type EV_SYN(0x00).
This time, I also did
echo 'file rtl28xxu.c +p' > /sys/kernel/debug/dynamic_debug/control
dmesg
and here is some output corresponding to the above:
[ 2978.632071] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=ff 89 2c 8d 7f 40
[ 2978.633720] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 2978.635377] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 2978.637031] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 2978.740612] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 2978.742301] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 05
[ 2978.744024] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 05 00 <<< b0 2c 8d 7f 40
[ 2978.744037] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=b0 2c 8d 7f 40
[ 2978.745690] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 2978.747350] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 2978.749009] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 2978.852621] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 2978.854306] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 03
[ 2978.856004] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 03 00 <<< 8d 7f 40
[ 2978.856018] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=8d 7f 40
[ 2978.857669] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 2978.859320] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 2978.860976] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 2978.964619] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 2978.966304] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 04
[ 2978.968003] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 04 00 <<< ff b5 2b 8d
[ 2978.968016] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=ff b5 2b 8d
[ 2978.968021] dvb_usb_rtl28xxu 2-9.1:1.0: ignoring idle=2b
[ 2979.072616] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 2979.074308] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 06
[ 2979.076026] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 06 00 <<< ff b5 2b 8d 7f 40
[ 2979.076040] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=ff b5 2b 8d 7f 40
[ 2979.077691] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 2979.079350] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 2979.081008] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 2979.184612] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 2979.186294] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 04
[ 2979.187986] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 04 00 <<< ff b5 2c 8d
[ 2979.187997] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=ff b5 2c 8d
[ 2979.188001] dvb_usb_rtl28xxu 2-9.1:1.0: ignoring idle=2c
[ 2979.292615] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 2979.294304] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 06
[ 2979.296024] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 06 00 <<< ff b5 2c 8d 7f 40
[ 2979.296037] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=ff b5 2c 8d 7f 40
[ 2979.297696] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 2979.299352] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 2979.301013] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 2979.404611] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 2979.406292] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 06
[ 2979.408005] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 06 00 <<< ff b5 2c 8c 7f 40
[ 2979.408018] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=ff b5 2c 8c 7f 40
Here, the problem could be correlated with the "ignoring idle" messages.
The previous such message was at 2976.728254, which correlated with the
start of me pressing the button. I had released the previous button
about 40 seconds earlier.
With the RC5 remote control (using hauppauge.toml) it is similar, but
the key_down events never disappeared indefinitely. If I kept the button
depressed, eventually the bogus key_up would be followed by key_down.
Testing events. Please, press CTRL-C to abort.
4462.130185: lirc protocol(rc5): scancode = 0x1e01
4462.130197: event type EV_MSC(0x04): scancode = 0x1e01
4462.130197: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4462.130197: event type EV_SYN(0x00).
4462.242167: lirc protocol(rc5): scancode = 0x1e01
4462.242176: event type EV_MSC(0x04): scancode = 0x1e01
4462.242176: event type EV_SYN(0x00).
4462.354172: lirc protocol(rc5): scancode = 0x1e01
4462.354181: event type EV_MSC(0x04): scancode = 0x1e01
4462.354181: event type EV_SYN(0x00).
4462.466172: lirc protocol(rc5): scancode = 0x1e01
4462.466182: event type EV_MSC(0x04): scancode = 0x1e01
4462.466182: event type EV_SYN(0x00).
4462.578198: lirc protocol(rc5): scancode = 0x1e01
4462.578208: event type EV_MSC(0x04): scancode = 0x1e01
4462.578208: event type EV_SYN(0x00).
4462.652054: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4462.652054: event type EV_SYN(0x00).
4462.690173: lirc protocol(rc5): scancode = 0x1e01
4462.652054: event type EV_MSC(0x04): scancode = 0x1e01
4462.652054: event type EV_SYN(0x00).
4462.784052: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4462.784052: event type EV_SYN(0x00).
4462.802199: lirc protocol(rc5): scancode = 0x1e01
4462.784052: event type EV_MSC(0x04): scancode = 0x1e01
4462.784052: event type EV_SYN(0x00).
4462.914215: lirc protocol(rc5): scancode = 0x1e01
4462.914224: event type EV_MSC(0x04): scancode = 0x1e01
4462.914224: event type EV_SYN(0x00).
4462.916050: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4462.916050: event type EV_SYN(0x00).
4463.048051: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4463.048051: event type EV_SYN(0x00).
4463.130202: lirc protocol(rc5): scancode = 0x1e01
4463.048051: event type EV_MSC(0x04): scancode = 0x1e01
4463.048051: event type EV_SYN(0x00).
4463.180051: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4463.180051: event type EV_SYN(0x00).
4463.312052: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4463.312052: event type EV_SYN(0x00).
4463.346181: lirc protocol(rc5): scancode = 0x1e01
4463.312052: event type EV_MSC(0x04): scancode = 0x1e01
4463.312052: event type EV_SYN(0x00).
4463.444050: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4463.444050: event type EV_SYN(0x00).
4463.576056: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4463.576056: event type EV_SYN(0x00).
4463.576056: event type EV_KEY(0x01) key_up: KEY_NUMERIC_1(0x0201)
4463.576056: event type EV_SYN(0x00).
4464.466165: lirc protocol(rc5): scancode = 0x1e01
4464.466177: event type EV_MSC(0x04): scancode = 0x1e01
4464.466177: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4464.466177: event type EV_SYN(0x00).
4464.578177: lirc protocol(rc5): scancode = 0x1e01
4464.578187: event type EV_MSC(0x04): scancode = 0x1e01
4464.578187: event type EV_SYN(0x00).
4464.690210: lirc protocol(rc5): scancode = 0x1e01
4464.690219: event type EV_MSC(0x04): scancode = 0x1e01
4464.690219: event type EV_SYN(0x00).
4464.802158: lirc protocol(rc5): scancode = 0x1e01
4464.802167: event type EV_MSC(0x04): scancode = 0x1e01
4464.802167: event type EV_SYN(0x00).
4464.914163: lirc protocol(rc5): scancode = 0x1e01
4464.914172: event type EV_MSC(0x04): scancode = 0x1e01
4464.914172: event type EV_SYN(0x00).
4464.988053: event type EV_KEY(0x01) key_down: KEY_NUMERIC_1(0x0201)
4464.988053: event type EV_SYN(0x00).
Again, at 4463.576056 we get both key_down and key_up with the same
timestamp. Between the two first key_down there is a delay of about
500ms, and the repeat rate looks roughly correct too. So, the only
problem is the premature key_up event, and the 890ms delay until a
key_down was delivered again. The last key_down in the above snippet was
delivered in about 500ms from that. That is correct, as the driver
"thinks" that the key had been released in between.
Here is the dmesg output for that time frame:
[ 4463.405960] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=89 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4463.407580] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4463.409206] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4463.410830] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4463.514533] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4463.516188] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 0f
[ 4463.517940] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 0f 00 <<< 8e 11 92 12 92 11 92 12 92 11 92 24 91 7f 40
[ 4463.517953] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=8e 11 92 12 92 11 92 12 92 11 92 24 91 7f 40
[ 4463.519572] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4463.521199] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4463.522825] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4463.626542] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4463.628196] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 0f
[ 4463.629947] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 0f 00 <<< a6 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4463.629959] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=a6 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4463.631574] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4463.633201] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4463.634824] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4463.738496] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4463.740169] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 13
[ 4463.741961] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 13 00 <<< 88 11 92 11 a4 11 93 11 92 11 93 11 92 12 92 23 92 7f 40
[ 4463.741974] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=88 11 92 11 a4 11 93 11 92 11 93 11 92 12 92 23 92 7f 40
[ 4463.743596] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4463.745219] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4463.746848] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4463.850469] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4463.852113] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 15
[ 4463.853936] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 15 00 <<< 8d 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4463.853951] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=8d 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4463.855570] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4463.857194] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4463.858821] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4463.962543] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4463.964199] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 15
[ 4463.966010] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 15 00 <<< 94 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4463.966022] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=94 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4463.967636] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4463.969256] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4463.970880] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4464.074517] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4464.076193] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 17
[ 4464.078006] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 17 00 <<< a4 23 92 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4464.078019] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=a4 23 92 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4464.079639] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4464.081256] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4464.082879] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4464.186516] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4464.188168] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 19
[ 4464.190002] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 19 00 <<< 93 11 a4 23 92 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4464.190015] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=93 11 a4 23 92 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4464.191638] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4464.193257] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4464.194879] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4464.298515] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4464.300186] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 19
[ 4464.302020] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 19 00 <<< 92 11 a4 23 92 12 92 11 92 12 a3 12 92 12 91 12 92 12 91 12 92 23 92 7f 40
[ 4464.302034] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=92 11 a4 23 92 12 92 11 92 12 a3 12 92 12 91 12 92 12 91 12 92 23 92 7f 40
[ 4464.303652] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4464.305276] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4464.306898] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4464.410538] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4464.412209] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 19
[ 4464.414043] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 19 00 <<< 93 11 a4 23 92 11 93 11 92 12 a3 12 92 11 92 12 92 11 92 12 92 23 92 7f 40
[ 4464.414055] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=93 11 a4 23 92 11 93 11 92 12 a3 12 92 11 92 12 92 11 92 12 92 23 92 7f 40
[ 4464.415676] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4464.417303] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4464.418928] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4464.522518] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4464.524176] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 19
[ 4464.526010] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 19 00 <<< 93 11 a4 23 92 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4464.526025] dvb_usb_rtl28xxu 2-9.1:1.0: IR_RX_BUF=93 11 a4 23 92 11 93 11 92 11 a4 11 93 11 92 11 93 11 92 11 93 23 92 7f 40
[ 4464.527642] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 01 fd 11 02 01 00 >>> 03
[ 4464.529259] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 09 fd 11 02 01 00 >>> 80
[ 4464.530881] usb 2-9.1: rtl28xxu_ctrl_msg: 40 00 02 fd 11 02 01 00 >>> 80
[ 4464.634523] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 01 fd 01 02 01 00 <<< 83
[ 4464.636176] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 0b fd 01 02 01 00 <<< 19
[ 4464.638011] usb 2-9.1: rtl28xxu_ctrl_msg: c0 00 00 fc 01 02 19 00 <<< 93 11 a4 23 92 11 93 11 92 11 a4 12 92 11 92 12 92 11 92 12 92 23 92 7f 40
For the RC5 protocol, there are no "ignoring idle" messages. I could
offer another potential explanation for the premature key_up events.
You described the intended change earlier as follows:
>>I think rc-core needs a little refactoring to split out the timeout
>>into keyup_timeout and rawir_timeout. For this driver, the
>>rawir_timeout needs to be set to 0xbf * 51us, and the keyup_timeout to
>>the query interval (which 200ms).
In my previous message, I replied to that:
>Possibly related to this: A long time ago when I was involved with
>formal methods in theoretical computer science, timers or timeouts
>would make me nervous due to the inherent state space explosion. In
>model checking, a timed event can be modeled with nondeterminism: in
>every state where the event is enabled, it may or may not be executed.
>So, in theory, timers or timeouts could open more room for race
>conditions or starvation. In practice, if multiple timers are driven
>from the same clock source, it should not be that bad.
Maybe an easier-to-understand analogy would be the physics concept of
interference, nicely visualized by Moiré patterns.
I did not study the code, so I am merely thinking aloud here: If both
keyup_timeout and rawir_timeout occur at the same time, an incorrect
key_up event could be delivered every now and then. I guess that this
would require two independent threads being triggered by the timeouts,
and some race condition between them.
I am happy to test a revised patch.
Best regards,
Marko
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: Inconsistent RC5 ir-keytable events
2022-03-26 18:44 ` Marko Mäkelä
@ 2022-04-10 14:07 ` Marko Mäkelä
0 siblings, 0 replies; 17+ messages in thread
From: Marko Mäkelä @ 2022-04-10 14:07 UTC (permalink / raw)
To: Sean Young; +Cc: linux-media
Hi Sean,
Were you able to repeat the problem of bogus keyup events (and lost
key-repeat events) when holding down a remote control button for several
seconds?
I tried to understand your two commits and how the subsystem works. No
new timer callback is being declared in the patch. Basically, only the
field dvb_usb_rc::timeout is being split into rawir_timeout and
keyup_delay. For all other drivers except rtl28xxu.c they are being set
to identical values.
I could not figure out what would invoke rtl2832u_rc_query() that is
actually reading the IR data from the USB driver. As far as I can tell,
it is feeding the data to the LIRC driver (in a separate thread) via
ir_raw_event_store_with_filter() and ir_raw_event_handle(). The
ir_timer_keyup() and ir_timer_repeat() are presumably called from a
timer handler thread.
Because the LIRC events were seemingly always reported consistently, the
problem should either be some kind of a glitch between rc-ir-raw.c and
the decoder, or some glitch in the ir_raw_event data that is being
supplied to the decoder. I was thinking if the problem could reside here
in rtl2832u_rc_query():
diff --git a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
index a83b1107fc7f..3d292a351403 100644
--- a/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
+++ b/drivers/media/usb/dvb-usb-v2/rtl28xxu.c
@@ -1802,9 +1802,13 @@ static int rtl2832u_rc_query(struct dvb_usb_device *d)
}
/* pass data to Kernel IR decoder */
- for (i = 0; i < len; i++) {
+ for (i = 0; i < len; ) {
ev.pulse = buf[i] >> 7;
- ev.duration = 51 * (buf[i] & 0x7f);
+ ev.duration = buf[i] & 0x7f;
+ while (++i < len && ev.pulse == buf[i] >> 7) {
+ ev.duration += buf[i] & 0x7f;
+ }
+ ev.duration *= 51;
ir_raw_event_store_with_filter(d->rc_dev, &ev);
}
My idea was to avoid sending multiple events for a single transition
that for some reason was split into multiple bytes in the buffer. But,
this did not help at all. Holding down the Volume+ or Volume- button
would still fail to turn the volume all the way up or down in the GNOME
desktop, without any pauses.
This would seem to suggest some glitch between ir_raw_event_thread() and
the decoder, that is, ir_rc5_decode() or ir_nec_decode(), and the keyup
timeout.
I have two ideas how to avoid bogus keyup events:
(1) Extend the keyup timeout on every ir_raw_event_handle().
(2) In the keyup callback, reschedule the timer a little later if some
incompletely decoded raw events remain in the buffers.
I think that (1) is simpler.
Marko
^ permalink raw reply related [flat|nested] 17+ messages in thread
end of thread, other threads:[~2022-04-10 14:08 UTC | newest]
Thread overview: 17+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
[not found] <YdKdPosyzj2urFpS@jyty>
2022-01-03 9:21 ` Inconsistent RC5 ir-keytable events Sean Young
2022-01-03 10:35 ` Marko Mäkelä
2022-01-03 11:07 ` Sean Young
2022-01-03 12:21 ` Marko Mäkelä
2022-01-04 16:07 ` Marko Mäkelä
2022-01-05 9:53 ` Sean Young
2022-01-06 11:41 ` Marko Mäkelä
2022-01-13 16:55 ` Sean Young
2022-01-14 6:31 ` Marko Mäkelä
2022-01-29 17:15 ` Marko Mäkelä
2022-02-08 16:46 ` Sean Young
2022-02-09 8:12 ` Marko Mäkelä
2022-02-12 11:16 ` Sean Young
2022-02-12 16:34 ` Sean Young
2022-02-13 17:12 ` Marko Mäkelä
2022-03-26 18:44 ` Marko Mäkelä
2022-04-10 14:07 ` Marko Mäkelä
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.