diff mbox

[v2,7/7] media: rc: mceusb: allow the timeout to be configurable

Message ID 20180418112428.zk3lmdxoqv46weph@gofer.mess.org (mailing list archive)
State Not Applicable
Headers show

Commit Message

Sean Young April 18, 2018, 11:24 a.m. UTC
Hello Hias,

On Tue, Apr 17, 2018 at 09:14:57PM +0200, Matthias Reichl wrote:
> On Sun, Apr 08, 2018 at 10:19:42PM +0100, Sean Young wrote:
> > mceusb devices have a default timeout of 100ms, but this can be changed.
> 
> We finally added a backport of the v2 series (and also the mce_kbd
> series) to LibreELEC yesterday and ratcher quickly received 2 bugreports
> from users using mceusb receivers.
> 
> Local testing on RPi/gpio-ir and Intel NUC/ite-cir was fine, I've
> been using the v2 series for over a week without issues on
> LibreELEC (RPi with kernel 4.14).
> 
> Here are the links to the bugreports and logs:
> https://forum.kodi.tv/showthread.php?tid=298461&pid=2726684#pid2726684
> https://forum.kodi.tv/showthread.php?tid=298462&pid=2726690#pid2726690
> 
> Both users are using similar mceusb receivers:
> 
> Log 1:
> [    6.418218] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (147a:e017) as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/rc/rc0
> [    6.418358] input: Media Center Ed. eHome Infrared Remote Transceiver (147a:e017) as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/rc/rc0/input0
> [    6.419443] rc rc0: lirc_dev: driver ir-lirc-codec (mceusb) registered at minor = 0
> [    6.608114] mceusb 1-1.3:1.0: Registered Formosa21 SnowflakeEmulation with mce emulator interface version 1
> [    6.608125] mceusb 1-1.3:1.0: 0 tx ports (0x0 cabled) and 1 rx sensors (0x1 active)
> 
> Log 2:
> [    3.023361] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (147a:e03e) as /devices/pci0000:00/0000:00:14.0/usb1/1-10/1-10:1.0/rc/rc0
> [    3.023393] input: Media Center Ed. eHome Infrared Remote Transceiver (147a:e03e) as /devices/pci0000:00/0000:00:14.0/usb1/1-10/1-10:1.0/rc/rc0/input11
> [    3.023868] rc rc0: lirc_dev: driver ir-lirc-codec (mceusb) registered at minor = 0
> [    3.119384] input: eventlircd as /devices/virtual/input/input21
> [    3.138625] ip6_tables: (C) 2000-2006 Netfilter Core Team
> [    3.196830] mceusb 1-10:1.0: Registered Formosa21 eHome Infrared Transceiver with mce emulator interface version 2
> [    3.196836] mceusb 1-10:1.0: 0 tx ports (0x0 cabled) and 1 rx sensors (0x1 active)
> 
> In both cases ir-keytable doesn't report any scancodes and the
> ir-ctl -r output contains very odd long space values where I'd expect
> a short timeout instead:
> 
> gap between messages:
> space 800
> pulse 450
> space 16777215
> space 25400
> pulse 2650
> space 800
> 
> end of last message:
> space 800
> pulse 450
> space 16777215
> timeout 31750
> 
> This patch applied cleanly on 4.14 and the mceusb history from
> 4.14 to media/master looked rather unsuspicious. I'm not 100% sure
> if I might have missed a dependency when backporting the patch
> or if this is indeed an issue of this patch on these particular
> (or maybe some more) mceusb receivers.

Thanks again for a great bug report and analysis! So, it seems with the
shorter timeout, some mceusb devices add a specific "timeout" code to
the IR data stream (0x80) rather than a space. The current mceusb code
resets the decoders in this case, causing the IR decoders to reset and
lirc to report a space of 0xffffff.

Turns out that one of my mceusb devices also suffers from this, I don't
know how I missed this. Anyway hopefully this will solve the problem.


Thanks

Sean

From 92d27b206e51993e927dc0b3aba210a621eef3d0 Mon Sep 17 00:00:00 2001
From: Sean Young <sean@mess.org>
Date: Wed, 18 Apr 2018 10:36:25 +0100
Subject: [PATCH] media: rc: mceusb: IR of length 0 means IR timeout, not reset

The last usb packet with IR data will end with 0x80 (MCE_IRDATA_TRAILER).
If we reset the decoder state at this point, IR decoding can fail.

Signed-off-by: Sean Young <sean@mess.org>
---
 drivers/media/rc/mceusb.c | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

Comments

Matthias Reichl April 18, 2018, 5:42 p.m. UTC | #1
Hi Sean,

On Wed, Apr 18, 2018 at 12:24:29PM +0100, Sean Young wrote:
> Hello Hias,
> 
> On Tue, Apr 17, 2018 at 09:14:57PM +0200, Matthias Reichl wrote:
> > On Sun, Apr 08, 2018 at 10:19:42PM +0100, Sean Young wrote:
> > > mceusb devices have a default timeout of 100ms, but this can be changed.
> > 
> > We finally added a backport of the v2 series (and also the mce_kbd
> > series) to LibreELEC yesterday and ratcher quickly received 2 bugreports
> > from users using mceusb receivers.
> > 
> > Local testing on RPi/gpio-ir and Intel NUC/ite-cir was fine, I've
> > been using the v2 series for over a week without issues on
> > LibreELEC (RPi with kernel 4.14).
> > 
> > Here are the links to the bugreports and logs:
> > https://forum.kodi.tv/showthread.php?tid=298461&pid=2726684#pid2726684
> > https://forum.kodi.tv/showthread.php?tid=298462&pid=2726690#pid2726690
> > 
> > Both users are using similar mceusb receivers:
> > 
> > Log 1:
> > [    6.418218] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (147a:e017) as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/rc/rc0
> > [    6.418358] input: Media Center Ed. eHome Infrared Remote Transceiver (147a:e017) as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/rc/rc0/input0
> > [    6.419443] rc rc0: lirc_dev: driver ir-lirc-codec (mceusb) registered at minor = 0
> > [    6.608114] mceusb 1-1.3:1.0: Registered Formosa21 SnowflakeEmulation with mce emulator interface version 1
> > [    6.608125] mceusb 1-1.3:1.0: 0 tx ports (0x0 cabled) and 1 rx sensors (0x1 active)
> > 
> > Log 2:
> > [    3.023361] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (147a:e03e) as /devices/pci0000:00/0000:00:14.0/usb1/1-10/1-10:1.0/rc/rc0
> > [    3.023393] input: Media Center Ed. eHome Infrared Remote Transceiver (147a:e03e) as /devices/pci0000:00/0000:00:14.0/usb1/1-10/1-10:1.0/rc/rc0/input11
> > [    3.023868] rc rc0: lirc_dev: driver ir-lirc-codec (mceusb) registered at minor = 0
> > [    3.119384] input: eventlircd as /devices/virtual/input/input21
> > [    3.138625] ip6_tables: (C) 2000-2006 Netfilter Core Team
> > [    3.196830] mceusb 1-10:1.0: Registered Formosa21 eHome Infrared Transceiver with mce emulator interface version 2
> > [    3.196836] mceusb 1-10:1.0: 0 tx ports (0x0 cabled) and 1 rx sensors (0x1 active)
> > 
> > In both cases ir-keytable doesn't report any scancodes and the
> > ir-ctl -r output contains very odd long space values where I'd expect
> > a short timeout instead:
> > 
> > gap between messages:
> > space 800
> > pulse 450
> > space 16777215
> > space 25400
> > pulse 2650
> > space 800
> > 
> > end of last message:
> > space 800
> > pulse 450
> > space 16777215
> > timeout 31750
> > 
> > This patch applied cleanly on 4.14 and the mceusb history from
> > 4.14 to media/master looked rather unsuspicious. I'm not 100% sure
> > if I might have missed a dependency when backporting the patch
> > or if this is indeed an issue of this patch on these particular
> > (or maybe some more) mceusb receivers.
> 
> Thanks again for a great bug report and analysis! So, it seems with the
> shorter timeout, some mceusb devices add a specific "timeout" code to
> the IR data stream (0x80) rather than a space. The current mceusb code
> resets the decoders in this case, causing the IR decoders to reset and
> lirc to report a space of 0xffffff.
> 
> Turns out that one of my mceusb devices also suffers from this, I don't
> know how I missed this. Anyway hopefully this will solve the problem.

Thanks a lot for the quick fix!

I can't test myself as I don't have the hardware, but we will
include the patch in tonight's LibreELEC build and I asked the
users to test it. I'll keep you posted about the outcome.

so long,

Hias

> 
> 
> Thanks
> 
> Sean
> 
> >>From 92d27b206e51993e927dc0b3aba210a621eef3d0 Mon Sep 17 00:00:00 2001
> From: Sean Young <sean@mess.org>
> Date: Wed, 18 Apr 2018 10:36:25 +0100
> Subject: [PATCH] media: rc: mceusb: IR of length 0 means IR timeout, not reset
> 
> The last usb packet with IR data will end with 0x80 (MCE_IRDATA_TRAILER).
> If we reset the decoder state at this point, IR decoding can fail.
> 
> Signed-off-by: Sean Young <sean@mess.org>
> ---
>  drivers/media/rc/mceusb.c | 7 ++++++-
>  1 file changed, 6 insertions(+), 1 deletion(-)
> 
> diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
> index c97cb2eb1c5f..5c0bf61fae26 100644
> --- a/drivers/media/rc/mceusb.c
> +++ b/drivers/media/rc/mceusb.c
> @@ -1201,7 +1201,12 @@ static void mceusb_process_ir_data(struct mceusb_dev *ir, int buf_len)
>  			if (ir->rem) {
>  				ir->parser_state = PARSE_IRDATA;
>  			} else {
> -				ir_raw_event_reset(ir->rc);
> +				init_ir_raw_event(&rawir);
> +				rawir.timeout = 1;
> +				rawir.duration = ir->rc->timeout;
> +				if (ir_raw_event_store_with_filter(ir->rc,
> +								   &rawir))
> +					event = true;
>  				ir->pulse_tunit = 0;
>  				ir->pulse_count = 0;
>  			}
> -- 
> 2.14.3
>
Matthias Reichl April 19, 2018, 10:17 p.m. UTC | #2
Hi Sean,

On Wed, Apr 18, 2018 at 07:42:29PM +0200, Matthias Reichl wrote:
> Hi Sean,
> 
> On Wed, Apr 18, 2018 at 12:24:29PM +0100, Sean Young wrote:
> > Hello Hias,
> > 
> > On Tue, Apr 17, 2018 at 09:14:57PM +0200, Matthias Reichl wrote:
> > > On Sun, Apr 08, 2018 at 10:19:42PM +0100, Sean Young wrote:
> > > > mceusb devices have a default timeout of 100ms, but this can be changed.
> > > 
> > > We finally added a backport of the v2 series (and also the mce_kbd
> > > series) to LibreELEC yesterday and ratcher quickly received 2 bugreports
> > > from users using mceusb receivers.
> > > 
> > > Local testing on RPi/gpio-ir and Intel NUC/ite-cir was fine, I've
> > > been using the v2 series for over a week without issues on
> > > LibreELEC (RPi with kernel 4.14).
> > > 
> > > Here are the links to the bugreports and logs:
> > > https://forum.kodi.tv/showthread.php?tid=298461&pid=2726684#pid2726684
> > > https://forum.kodi.tv/showthread.php?tid=298462&pid=2726690#pid2726690
> > > 
> > > Both users are using similar mceusb receivers:
> > > 
> > > Log 1:
> > > [    6.418218] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (147a:e017) as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/rc/rc0
> > > [    6.418358] input: Media Center Ed. eHome Infrared Remote Transceiver (147a:e017) as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/rc/rc0/input0
> > > [    6.419443] rc rc0: lirc_dev: driver ir-lirc-codec (mceusb) registered at minor = 0
> > > [    6.608114] mceusb 1-1.3:1.0: Registered Formosa21 SnowflakeEmulation with mce emulator interface version 1
> > > [    6.608125] mceusb 1-1.3:1.0: 0 tx ports (0x0 cabled) and 1 rx sensors (0x1 active)
> > > 
> > > Log 2:
> > > [    3.023361] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (147a:e03e) as /devices/pci0000:00/0000:00:14.0/usb1/1-10/1-10:1.0/rc/rc0
> > > [    3.023393] input: Media Center Ed. eHome Infrared Remote Transceiver (147a:e03e) as /devices/pci0000:00/0000:00:14.0/usb1/1-10/1-10:1.0/rc/rc0/input11
> > > [    3.023868] rc rc0: lirc_dev: driver ir-lirc-codec (mceusb) registered at minor = 0
> > > [    3.119384] input: eventlircd as /devices/virtual/input/input21
> > > [    3.138625] ip6_tables: (C) 2000-2006 Netfilter Core Team
> > > [    3.196830] mceusb 1-10:1.0: Registered Formosa21 eHome Infrared Transceiver with mce emulator interface version 2
> > > [    3.196836] mceusb 1-10:1.0: 0 tx ports (0x0 cabled) and 1 rx sensors (0x1 active)
> > > 
> > > In both cases ir-keytable doesn't report any scancodes and the
> > > ir-ctl -r output contains very odd long space values where I'd expect
> > > a short timeout instead:
> > > 
> > > gap between messages:
> > > space 800
> > > pulse 450
> > > space 16777215
> > > space 25400
> > > pulse 2650
> > > space 800
> > > 
> > > end of last message:
> > > space 800
> > > pulse 450
> > > space 16777215
> > > timeout 31750
> > > 
> > > This patch applied cleanly on 4.14 and the mceusb history from
> > > 4.14 to media/master looked rather unsuspicious. I'm not 100% sure
> > > if I might have missed a dependency when backporting the patch
> > > or if this is indeed an issue of this patch on these particular
> > > (or maybe some more) mceusb receivers.
> > 
> > Thanks again for a great bug report and analysis! So, it seems with the
> > shorter timeout, some mceusb devices add a specific "timeout" code to
> > the IR data stream (0x80) rather than a space. The current mceusb code
> > resets the decoders in this case, causing the IR decoders to reset and
> > lirc to report a space of 0xffffff.
> > 
> > Turns out that one of my mceusb devices also suffers from this, I don't
> > know how I missed this. Anyway hopefully this will solve the problem.
> 
> Thanks a lot for the quick fix!
> 
> I can't test myself as I don't have the hardware, but we will
> include the patch in tonight's LibreELEC build and I asked the
> users to test it. I'll keep you posted about the outcome.

One of the affected users reported back that the fix worked fine!

I'm keeping an eye on further reports but so far I'd say everything's
working really well.

Great job and thanks a lot for the improvements!

so long,

Hias

> 
> so long,
> 
> Hias
> 
> > 
> > 
> > Thanks
> > 
> > Sean
> > 
> > >>From 92d27b206e51993e927dc0b3aba210a621eef3d0 Mon Sep 17 00:00:00 2001
> > From: Sean Young <sean@mess.org>
> > Date: Wed, 18 Apr 2018 10:36:25 +0100
> > Subject: [PATCH] media: rc: mceusb: IR of length 0 means IR timeout, not reset
> > 
> > The last usb packet with IR data will end with 0x80 (MCE_IRDATA_TRAILER).
> > If we reset the decoder state at this point, IR decoding can fail.
> > 
> > Signed-off-by: Sean Young <sean@mess.org>
> > ---
> >  drivers/media/rc/mceusb.c | 7 ++++++-
> >  1 file changed, 6 insertions(+), 1 deletion(-)
> > 
> > diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
> > index c97cb2eb1c5f..5c0bf61fae26 100644
> > --- a/drivers/media/rc/mceusb.c
> > +++ b/drivers/media/rc/mceusb.c
> > @@ -1201,7 +1201,12 @@ static void mceusb_process_ir_data(struct mceusb_dev *ir, int buf_len)
> >  			if (ir->rem) {
> >  				ir->parser_state = PARSE_IRDATA;
> >  			} else {
> > -				ir_raw_event_reset(ir->rc);
> > +				init_ir_raw_event(&rawir);
> > +				rawir.timeout = 1;
> > +				rawir.duration = ir->rc->timeout;
> > +				if (ir_raw_event_store_with_filter(ir->rc,
> > +								   &rawir))
> > +					event = true;
> >  				ir->pulse_tunit = 0;
> >  				ir->pulse_count = 0;
> >  			}
> > -- 
> > 2.14.3
> >
Matthias Reichl April 21, 2018, 1:18 p.m. UTC | #3
Hi Sean,

On Fri, Apr 20, 2018 at 12:17:23AM +0200, Matthias Reichl wrote:
> One of the affected users reported back that the fix worked fine!
> 
> I'm keeping an eye on further reports but so far I'd say everything's
> working really well.

Another bug report came in, button press results in multiple
key down/up events
https://forum.kodi.tv/showthread.php?tid=298461&pid=2727837#pid2727837
(and following posts).

ir-ctl -r output looks fine to me, but ir-keytable -t output suggests
we'll need a margin between raw timeout and key up timeout:

https://pastebin.com/6RTSGXvp
2199.824106: event type EV_MSC(0x04): scancode = 0x800f0419
2199.824106: event type EV_KEY(0x01) key_down: KEY_STOP(0x0080)
2199.824106: event type EV_SYN(0x00).
2199.887081: event type EV_KEY(0x01) key_up: KEY_STOP(0x0080)
2199.887081: event type EV_MSC(0x04): scancode = 0x800f0422
2199.887081: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
2199.887081: event type EV_SYN(0x00).
2200.029804: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
2200.029804: event type EV_SYN(0x00).

so long,

Hias
Matthias Reichl April 21, 2018, 5:41 p.m. UTC | #4
On Sat, Apr 21, 2018 at 03:18:52PM +0200, Matthias Reichl wrote:
> Hi Sean,
> 
> On Fri, Apr 20, 2018 at 12:17:23AM +0200, Matthias Reichl wrote:
> > One of the affected users reported back that the fix worked fine!
> > 
> > I'm keeping an eye on further reports but so far I'd say everything's
> > working really well.
> 
> Another bug report came in, button press results in multiple
> key down/up events
> https://forum.kodi.tv/showthread.php?tid=298461&pid=2727837#pid2727837
> (and following posts).
> 
> ir-ctl -r output looks fine to me, but ir-keytable -t output suggests
> we'll need a margin between raw timeout and key up timeout:
> 
> https://pastebin.com/6RTSGXvp
> 2199.824106: event type EV_MSC(0x04): scancode = 0x800f0419
> 2199.824106: event type EV_KEY(0x01) key_down: KEY_STOP(0x0080)
> 2199.824106: event type EV_SYN(0x00).
> 2199.887081: event type EV_KEY(0x01) key_up: KEY_STOP(0x0080)
> 2199.887081: event type EV_MSC(0x04): scancode = 0x800f0422
> 2199.887081: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 2199.887081: event type EV_SYN(0x00).
> 2200.029804: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 2200.029804: event type EV_SYN(0x00).

Sorry, just noticed I snipped off the interesting part, here
is the rest:

2200.036070: event type EV_MSC(0x04): scancode = 0x800f0422
2200.036070: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
2200.036070: event type EV_SYN(0x00).
2200.143067: event type EV_MSC(0x04): scancode = 0x800f0422
2200.143067: event type EV_SYN(0x00).
2200.206061: event type EV_MSC(0x04): scancode = 0x800f0422
2200.206061: event type EV_SYN(0x00).
2200.346472: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
2200.346472: event type EV_SYN(0x00).

I looked at the log again, and now it doesn't make much sense
to me.

I'm not exactly sure what happened with the first KEY_OK
scancode, that seems to have been decoded ~60ms after the
KEY_STOP scancode (.887 vs .824).

The second KEY_OK scancode was decoded ~ 150ms after the first,
(and caused the problem), delay to third is 107ms, to fourth 63ms.

I'll ask the user to change batteries on the remote and check
if the reception is OK, could be that this was a false alarm.

Adding some margin (maybe 20-50ms) for keyup could still make
sense though, as currently we have basically just the timeout
as margin, which can be quite low and round to 1-2 jiffies.

so long,

Hias
diff mbox

Patch

diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
index c97cb2eb1c5f..5c0bf61fae26 100644
--- a/drivers/media/rc/mceusb.c
+++ b/drivers/media/rc/mceusb.c
@@ -1201,7 +1201,12 @@  static void mceusb_process_ir_data(struct mceusb_dev *ir, int buf_len)
 			if (ir->rem) {
 				ir->parser_state = PARSE_IRDATA;
 			} else {
-				ir_raw_event_reset(ir->rc);
+				init_ir_raw_event(&rawir);
+				rawir.timeout = 1;
+				rawir.duration = ir->rc->timeout;
+				if (ir_raw_event_store_with_filter(ir->rc,
+								   &rawir))
+					event = true;
 				ir->pulse_tunit = 0;
 				ir->pulse_count = 0;
 			}