[PATCH v2 0/7] Improve latency of IR decoding

[PATCH v2 0/7] Improve latency of IR decoding

[Sean Young]

The current IR decoding is much too slow. Many IR protocols rely on
a trailing space for decoding (e.g. rc-6 needs to know when the bits
end). The trailing space is generated by the IR timeout, and if this
is longer than required, buttons can feel slow to respond.

The other issue is the keyup timer. IR has no concept of a keyup message,
this is implied by the absence of IR. So, minimising the timeout for
this makes buttons less "sticky"; the are released much quicker.

With these patches in place, using IR with the builtin decoders is much
improved and feels very snappy.

Changes since v1:
 - lost more testing
 - fixed various issues with mce decoder
 - fixed mceusb so it can use better timeout too

Sean Young (7):
  media: rc: set timeout to smallest value required by enabled protocols
  media: rc: add ioctl to get the current timeout
  media: rc: per-protocol repeat period and minimum keyup timer
  media: rc: mce_kbd decoder: low timeout values cause double keydowns
  media: rc: mce_kbd protocol encodes two scancodes
  media: rc: mce_kbd decoder: fix stuck keys
  media: rc: mceusb: allow the timeout to be configurable

 Documentation/media/uapi/rc/lirc-func.rst          |  1 +
 .../media/uapi/rc/lirc-set-rec-timeout.rst         | 14 +++--
 drivers/media/cec/cec-core.c                       |  2 +-
 drivers/media/rc/ir-imon-decoder.c                 |  1 +
 drivers/media/rc/ir-jvc-decoder.c                  |  1 +
 drivers/media/rc/ir-mce_kbd-decoder.c              | 36 +++++++-----
 drivers/media/rc/ir-nec-decoder.c                  |  1 +
 drivers/media/rc/ir-rc5-decoder.c                  |  1 +
 drivers/media/rc/ir-rc6-decoder.c                  |  1 +
 drivers/media/rc/ir-sanyo-decoder.c                |  1 +
 drivers/media/rc/ir-sharp-decoder.c                |  1 +
 drivers/media/rc/ir-sony-decoder.c                 |  1 +
 drivers/media/rc/ir-xmp-decoder.c                  |  1 +
 drivers/media/rc/lirc_dev.c                        |  9 ++-
 drivers/media/rc/mceusb.c                          | 22 +++++++
 drivers/media/rc/rc-core-priv.h                    |  1 +
 drivers/media/rc/rc-ir-raw.c                       | 31 +++++++++-
 drivers/media/rc/rc-main.c                         | 68 +++++++++++-----------
 include/uapi/linux/lirc.h                          |  6 ++
 19 files changed, 144 insertions(+), 55 deletions(-)

-- 
2.14.3

[PATCH v2 1/7] media: rc: set timeout to smallest value required by enabled protocols

[Sean Young]

The longer the IR timeout, the longer the rc device waits until delivering
the trailing space. So, by reducing this timeout, we reduce the delay for
the last scancode to be delivered.

Note that the lirc daemon disables all protocols, in which case we revert
back to the default value.

Signed-off-by: Sean Young <sean@mess.org>
---
 drivers/media/rc/ir-imon-decoder.c    |  1 +
 drivers/media/rc/ir-jvc-decoder.c     |  1 +
 drivers/media/rc/ir-mce_kbd-decoder.c |  1 +
 drivers/media/rc/ir-nec-decoder.c     |  1 +
 drivers/media/rc/ir-rc5-decoder.c     |  1 +
 drivers/media/rc/ir-rc6-decoder.c     |  1 +
 drivers/media/rc/ir-sanyo-decoder.c   |  1 +
 drivers/media/rc/ir-sharp-decoder.c   |  1 +
 drivers/media/rc/ir-sony-decoder.c    |  1 +
 drivers/media/rc/ir-xmp-decoder.c     |  1 +
 drivers/media/rc/rc-core-priv.h       |  1 +
 drivers/media/rc/rc-ir-raw.c          | 31 ++++++++++++++++++++++++++++++-
 drivers/media/rc/rc-main.c            | 12 ++++++------
 13 files changed, 47 insertions(+), 7 deletions(-)

diff --git a/drivers/media/rc/ir-imon-decoder.c b/drivers/media/rc/ir-imon-decoder.c
index a1ff06a26542..9024b359e5ee 100644
--- a/drivers/media/rc/ir-imon-decoder.c
+++ b/drivers/media/rc/ir-imon-decoder.c
@@ -170,6 +170,7 @@ static struct ir_raw_handler imon_handler = {
 	.decode		= ir_imon_decode,
 	.encode		= ir_imon_encode,
 	.carrier	= 38000,
+	.max_space	= IMON_UNIT * IMON_BITS * 2,
 };
 
 static int __init ir_imon_decode_init(void)
diff --git a/drivers/media/rc/ir-jvc-decoder.c b/drivers/media/rc/ir-jvc-decoder.c
index 8cb68ae43282..190c690b14f8 100644
--- a/drivers/media/rc/ir-jvc-decoder.c
+++ b/drivers/media/rc/ir-jvc-decoder.c
@@ -213,6 +213,7 @@ static struct ir_raw_handler jvc_handler = {
 	.decode		= ir_jvc_decode,
 	.encode		= ir_jvc_encode,
 	.carrier	= 38000,
+	.max_space	= JVC_TRAILER_SPACE,
 };
 
 static int __init ir_jvc_decode_init(void)
diff --git a/drivers/media/rc/ir-mce_kbd-decoder.c b/drivers/media/rc/ir-mce_kbd-decoder.c
index c110984ca671..ae4b980c4a16 100644
--- a/drivers/media/rc/ir-mce_kbd-decoder.c
+++ b/drivers/media/rc/ir-mce_kbd-decoder.c
@@ -475,6 +475,7 @@ static struct ir_raw_handler mce_kbd_handler = {
 	.raw_register	= ir_mce_kbd_register,
 	.raw_unregister	= ir_mce_kbd_unregister,
 	.carrier	= 36000,
+	.max_space	= MCIR2_MAX_LEN,
 };
 
 static int __init ir_mce_kbd_decode_init(void)
diff --git a/drivers/media/rc/ir-nec-decoder.c b/drivers/media/rc/ir-nec-decoder.c
index 21647b809e6f..fac12f867a81 100644
--- a/drivers/media/rc/ir-nec-decoder.c
+++ b/drivers/media/rc/ir-nec-decoder.c
@@ -253,6 +253,7 @@ static struct ir_raw_handler nec_handler = {
 	.decode		= ir_nec_decode,
 	.encode		= ir_nec_encode,
 	.carrier	= 38000,
+	.max_space	= NEC_TRAILER_SPACE,
 };
 
 static int __init ir_nec_decode_init(void)
diff --git a/drivers/media/rc/ir-rc5-decoder.c b/drivers/media/rc/ir-rc5-decoder.c
index 74d3b859c3a2..711068c8de90 100644
--- a/drivers/media/rc/ir-rc5-decoder.c
+++ b/drivers/media/rc/ir-rc5-decoder.c
@@ -274,6 +274,7 @@ static struct ir_raw_handler rc5_handler = {
 	.decode		= ir_rc5_decode,
 	.encode		= ir_rc5_encode,
 	.carrier	= 36000,
+	.max_space	= RC5_TRAILER,
 };
 
 static int __init ir_rc5_decode_init(void)
diff --git a/drivers/media/rc/ir-rc6-decoder.c b/drivers/media/rc/ir-rc6-decoder.c
index 8314da32453f..9cc4820878c7 100644
--- a/drivers/media/rc/ir-rc6-decoder.c
+++ b/drivers/media/rc/ir-rc6-decoder.c
@@ -394,6 +394,7 @@ static struct ir_raw_handler rc6_handler = {
 	.decode		= ir_rc6_decode,
 	.encode		= ir_rc6_encode,
 	.carrier	= 36000,
+	.max_space	= RC6_SUFFIX_SPACE,
 };
 
 static int __init ir_rc6_decode_init(void)
diff --git a/drivers/media/rc/ir-sanyo-decoder.c b/drivers/media/rc/ir-sanyo-decoder.c
index 4efe6db5376a..e72787b446c9 100644
--- a/drivers/media/rc/ir-sanyo-decoder.c
+++ b/drivers/media/rc/ir-sanyo-decoder.c
@@ -210,6 +210,7 @@ static struct ir_raw_handler sanyo_handler = {
 	.decode		= ir_sanyo_decode,
 	.encode		= ir_sanyo_encode,
 	.carrier	= 38000,
+	.max_space	= SANYO_TRAILER_SPACE,
 };
 
 static int __init ir_sanyo_decode_init(void)
diff --git a/drivers/media/rc/ir-sharp-decoder.c b/drivers/media/rc/ir-sharp-decoder.c
index 6a38c50566a4..e7e3841a6eb0 100644
--- a/drivers/media/rc/ir-sharp-decoder.c
+++ b/drivers/media/rc/ir-sharp-decoder.c
@@ -226,6 +226,7 @@ static struct ir_raw_handler sharp_handler = {
 	.decode		= ir_sharp_decode,
 	.encode		= ir_sharp_encode,
 	.carrier	= 38000,
+	.max_space	= SHARP_ECHO_SPACE,
 };
 
 static int __init ir_sharp_decode_init(void)
diff --git a/drivers/media/rc/ir-sony-decoder.c b/drivers/media/rc/ir-sony-decoder.c
index 6764ec9de646..598bae8d8ffb 100644
--- a/drivers/media/rc/ir-sony-decoder.c
+++ b/drivers/media/rc/ir-sony-decoder.c
@@ -224,6 +224,7 @@ static struct ir_raw_handler sony_handler = {
 	.decode		= ir_sony_decode,
 	.encode		= ir_sony_encode,
 	.carrier	= 40000,
+	.max_space	= SONY_TRAILER_SPACE,
 };
 
 static int __init ir_sony_decode_init(void)
diff --git a/drivers/media/rc/ir-xmp-decoder.c b/drivers/media/rc/ir-xmp-decoder.c
index 58b47af1a763..e005a75a86fe 100644
--- a/drivers/media/rc/ir-xmp-decoder.c
+++ b/drivers/media/rc/ir-xmp-decoder.c
@@ -199,6 +199,7 @@ static int ir_xmp_decode(struct rc_dev *dev, struct ir_raw_event ev)
 static struct ir_raw_handler xmp_handler = {
 	.protocols	= RC_PROTO_BIT_XMP,
 	.decode		= ir_xmp_decode,
+	.max_space	= XMP_TRAILER_SPACE,
 };
 
 static int __init ir_xmp_decode_init(void)
diff --git a/drivers/media/rc/rc-core-priv.h b/drivers/media/rc/rc-core-priv.h
index e0e6a17460f6..8c38941295b8 100644
--- a/drivers/media/rc/rc-core-priv.h
+++ b/drivers/media/rc/rc-core-priv.h
@@ -37,6 +37,7 @@ struct ir_raw_handler {
 	int (*encode)(enum rc_proto protocol, u32 scancode,
 		      struct ir_raw_event *events, unsigned int max);
 	u32 carrier;
+	u32 max_space;
 
 	/* These two should only be used by the mce kbd decoder */
 	int (*raw_register)(struct rc_dev *dev);
diff --git a/drivers/media/rc/rc-ir-raw.c b/drivers/media/rc/rc-ir-raw.c
index 374f83105a23..1ce008dc7f47 100644
--- a/drivers/media/rc/rc-ir-raw.c
+++ b/drivers/media/rc/rc-ir-raw.c
@@ -233,7 +233,36 @@ ir_raw_get_allowed_protocols(void)
 
 static int change_protocol(struct rc_dev *dev, u64 *rc_proto)
 {
-	/* the caller will update dev->enabled_protocols */
+	struct ir_raw_handler *handler;
+	u32 timeout = 0;
+
+	if (!dev->max_timeout)
+		return 0;
+
+	mutex_lock(&ir_raw_handler_lock);
+	list_for_each_entry(handler, &ir_raw_handler_list, list) {
+		if (handler->protocols & *rc_proto) {
+			if (timeout < handler->max_space)
+				timeout = handler->max_space;
+		}
+	}
+	mutex_unlock(&ir_raw_handler_lock);
+
+	if (timeout == 0)
+		timeout = IR_DEFAULT_TIMEOUT;
+	else
+		timeout += MS_TO_NS(20);
+
+	if (timeout < dev->min_timeout)
+		timeout = dev->min_timeout;
+	else if (timeout > dev->max_timeout)
+		timeout = dev->max_timeout;
+
+	if (dev->s_timeout)
+		dev->s_timeout(dev, timeout);
+	else
+		dev->timeout = timeout;
+
 	return 0;
 }
 
diff --git a/drivers/media/rc/rc-main.c b/drivers/media/rc/rc-main.c
index b67be33bd62f..6a720e9c7aa8 100644
--- a/drivers/media/rc/rc-main.c
+++ b/drivers/media/rc/rc-main.c
@@ -1241,6 +1241,9 @@ static ssize_t store_protocols(struct device *device,
 	if (rc < 0)
 		goto out;
 
+	if (dev->driver_type == RC_DRIVER_IR_RAW)
+		ir_raw_load_modules(&new_protocols);
+
 	rc = dev->change_protocol(dev, &new_protocols);
 	if (rc < 0) {
 		dev_dbg(&dev->dev, "Error setting protocols to 0x%llx\n",
@@ -1248,9 +1251,6 @@ static ssize_t store_protocols(struct device *device,
 		goto out;
 	}
 
-	if (dev->driver_type == RC_DRIVER_IR_RAW)
-		ir_raw_load_modules(&new_protocols);
-
 	if (new_protocols != old_protocols) {
 		*current_protocols = new_protocols;
 		dev_dbg(&dev->dev, "Protocols changed to 0x%llx\n",
@@ -1735,6 +1735,9 @@ static int rc_prepare_rx_device(struct rc_dev *dev)
 	if (dev->driver_type == RC_DRIVER_SCANCODE && !dev->change_protocol)
 		dev->enabled_protocols = dev->allowed_protocols;
 
+	if (dev->driver_type == RC_DRIVER_IR_RAW)
+		ir_raw_load_modules(&rc_proto);
+
 	if (dev->change_protocol) {
 		rc = dev->change_protocol(dev, &rc_proto);
 		if (rc < 0)
@@ -1742,9 +1745,6 @@ static int rc_prepare_rx_device(struct rc_dev *dev)
 		dev->enabled_protocols = rc_proto;
 	}
 
-	if (dev->driver_type == RC_DRIVER_IR_RAW)
-		ir_raw_load_modules(&rc_proto);
-
 	set_bit(EV_KEY, dev->input_dev->evbit);
 	set_bit(EV_REP, dev->input_dev->evbit);
 	set_bit(EV_MSC, dev->input_dev->evbit);
-- 
2.14.3

[PATCH v2 2/7] media: rc: add ioctl to get the current timeout

[Sean Young]

Since the kernel now modifies the timeout, make it possible to retrieve
the current value.

Signed-off-by: Sean Young <sean@mess.org>
---
 Documentation/media/uapi/rc/lirc-func.rst            |  1 +
 Documentation/media/uapi/rc/lirc-set-rec-timeout.rst | 14 +++++++++-----
 drivers/media/rc/lirc_dev.c                          |  7 +++++++
 include/uapi/linux/lirc.h                            |  6 ++++++
 4 files changed, 23 insertions(+), 5 deletions(-)

diff --git a/Documentation/media/uapi/rc/lirc-func.rst b/Documentation/media/uapi/rc/lirc-func.rst
index ddb4620de294..9656423a3f28 100644
--- a/Documentation/media/uapi/rc/lirc-func.rst
+++ b/Documentation/media/uapi/rc/lirc-func.rst
@@ -17,6 +17,7 @@ LIRC Function Reference
     lirc-get-rec-resolution
     lirc-set-send-duty-cycle
     lirc-get-timeout
+    lirc-get-rec-timeout
     lirc-set-rec-timeout
     lirc-set-rec-carrier
     lirc-set-rec-carrier-range
diff --git a/Documentation/media/uapi/rc/lirc-set-rec-timeout.rst b/Documentation/media/uapi/rc/lirc-set-rec-timeout.rst
index b3e16bbdbc90..a833a6a4c25a 100644
--- a/Documentation/media/uapi/rc/lirc-set-rec-timeout.rst
+++ b/Documentation/media/uapi/rc/lirc-set-rec-timeout.rst
@@ -1,19 +1,23 @@
 .. -*- coding: utf-8; mode: rst -*-
 
 .. _lirc_set_rec_timeout:
+.. _lirc_get_rec_timeout:
 
-**************************
-ioctl LIRC_SET_REC_TIMEOUT
-**************************
+***************************************************
+ioctl LIRC_GET_REC_TIMEOUT and LIRC_SET_REC_TIMEOUT
+***************************************************
 
 Name
 ====
 
-LIRC_SET_REC_TIMEOUT - sets the integer value for IR inactivity timeout.
+LIRC_GET_REC_TIMEOUT/LIRC_SET_REC_TIMEOUT - Get/set the integer value for IR inactivity timeout.
 
 Synopsis
 ========
 
+.. c:function:: int ioctl( int fd, LIRC_GET_REC_TIMEOUT, __u32 *timeout )
+    :name: LIRC_GET_REC_TIMEOUT
+
 .. c:function:: int ioctl( int fd, LIRC_SET_REC_TIMEOUT, __u32 *timeout )
     :name: LIRC_SET_REC_TIMEOUT
 
@@ -30,7 +34,7 @@ Arguments
 Description
 ===========
 
-Sets the integer value for IR inactivity timeout.
+Get and set the integer value for IR inactivity timeout.
 
 If supported by the hardware, setting it to 0  disables all hardware timeouts
 and data should be reported as soon as possible. If the exact value
diff --git a/drivers/media/rc/lirc_dev.c b/drivers/media/rc/lirc_dev.c
index 247e6fc3dc0c..6b4755e9fa25 100644
--- a/drivers/media/rc/lirc_dev.c
+++ b/drivers/media/rc/lirc_dev.c
@@ -575,6 +575,13 @@ static long ir_lirc_ioctl(struct file *file, unsigned int cmd,
 		}
 		break;
 
+	case LIRC_GET_REC_TIMEOUT:
+		if (!dev->timeout)
+			ret = -ENOTTY;
+		else
+			val = DIV_ROUND_UP(dev->timeout, 1000);
+		break;
+
 	case LIRC_SET_REC_TIMEOUT_REPORTS:
 		if (!dev->timeout)
 			ret = -ENOTTY;
diff --git a/include/uapi/linux/lirc.h b/include/uapi/linux/lirc.h
index f189931042a7..6b319581882f 100644
--- a/include/uapi/linux/lirc.h
+++ b/include/uapi/linux/lirc.h
@@ -133,6 +133,12 @@
 
 #define LIRC_SET_WIDEBAND_RECEIVER     _IOW('i', 0x00000023, __u32)
 
+/*
+ * Return the recording timeout, which is either set by
+ * the ioctl LIRC_SET_REC_TIMEOUT or by the kernel after setting the protocols.
+ */
+#define LIRC_GET_REC_TIMEOUT	       _IOR('i', 0x00000024, __u32)
+
 /*
  * struct lirc_scancode - decoded scancode with protocol for use with
  *	LIRC_MODE_SCANCODE
-- 
2.14.3

[PATCH v2 3/7] media: rc: per-protocol repeat period and minimum keyup timer

[Sean Young]

Each IR protocol has its own repeat period. We can minimise the keyup
timer to be the protocol period + IR timeout. This makes keys less
"sticky" and makes IR more reactive and nicer to use.

This feature was previously attempted in commit d57ea877af38 ("media: rc:
per-protocol repeat period"), but that did not take the IR timeout into
account, and had to be reverted.

Signed-off-by: Sean Young <sean@mess.org>
---
 drivers/media/cec/cec-core.c |  2 +-
 drivers/media/rc/lirc_dev.c  |  2 +-
 drivers/media/rc/rc-main.c   | 56 +++++++++++++++++++++++---------------------
 3 files changed, 31 insertions(+), 29 deletions(-)

diff --git a/drivers/media/cec/cec-core.c b/drivers/media/cec/cec-core.c
index b0c87f9ea08f..b278ab90b387 100644
--- a/drivers/media/cec/cec-core.c
+++ b/drivers/media/cec/cec-core.c
@@ -322,7 +322,7 @@ struct cec_adapter *cec_allocate_adapter(const struct cec_adap_ops *ops,
 	adap->rc->allowed_protocols = RC_PROTO_BIT_CEC;
 	adap->rc->priv = adap;
 	adap->rc->map_name = RC_MAP_CEC;
-	adap->rc->timeout = MS_TO_NS(100);
+	adap->rc->timeout = MS_TO_NS(550);
 #endif
 	return adap;
 }
diff --git a/drivers/media/rc/lirc_dev.c b/drivers/media/rc/lirc_dev.c
index 6b4755e9fa25..cc58ed78462f 100644
--- a/drivers/media/rc/lirc_dev.c
+++ b/drivers/media/rc/lirc_dev.c
@@ -583,7 +583,7 @@ static long ir_lirc_ioctl(struct file *file, unsigned int cmd,
 		break;
 
 	case LIRC_SET_REC_TIMEOUT_REPORTS:
-		if (!dev->timeout)
+		if (dev->driver_type != RC_DRIVER_IR_RAW)
 			ret = -ENOTTY;
 		else
 			fh->send_timeout_reports = !!val;
diff --git a/drivers/media/rc/rc-main.c b/drivers/media/rc/rc-main.c
index 6a720e9c7aa8..9f4df60f62e1 100644
--- a/drivers/media/rc/rc-main.c
+++ b/drivers/media/rc/rc-main.c
@@ -26,50 +26,50 @@ static const struct {
 	unsigned int repeat_period;
 	unsigned int scancode_bits;
 } protocols[] = {
-	[RC_PROTO_UNKNOWN] = { .name = "unknown", .repeat_period = 250 },
-	[RC_PROTO_OTHER] = { .name = "other", .repeat_period = 250 },
+	[RC_PROTO_UNKNOWN] = { .name = "unknown", .repeat_period = 125 },
+	[RC_PROTO_OTHER] = { .name = "other", .repeat_period = 125 },
 	[RC_PROTO_RC5] = { .name = "rc-5",
-		.scancode_bits = 0x1f7f, .repeat_period = 250 },
+		.scancode_bits = 0x1f7f, .repeat_period = 114 },
 	[RC_PROTO_RC5X_20] = { .name = "rc-5x-20",
-		.scancode_bits = 0x1f7f3f, .repeat_period = 250 },
+		.scancode_bits = 0x1f7f3f, .repeat_period = 114 },
 	[RC_PROTO_RC5_SZ] = { .name = "rc-5-sz",
-		.scancode_bits = 0x2fff, .repeat_period = 250 },
+		.scancode_bits = 0x2fff, .repeat_period = 114 },
 	[RC_PROTO_JVC] = { .name = "jvc",
-		.scancode_bits = 0xffff, .repeat_period = 250 },
+		.scancode_bits = 0xffff, .repeat_period = 125 },
 	[RC_PROTO_SONY12] = { .name = "sony-12",
-		.scancode_bits = 0x1f007f, .repeat_period = 250 },
+		.scancode_bits = 0x1f007f, .repeat_period = 100 },
 	[RC_PROTO_SONY15] = { .name = "sony-15",
-		.scancode_bits = 0xff007f, .repeat_period = 250 },
+		.scancode_bits = 0xff007f, .repeat_period = 100 },
 	[RC_PROTO_SONY20] = { .name = "sony-20",
-		.scancode_bits = 0x1fff7f, .repeat_period = 250 },
+		.scancode_bits = 0x1fff7f, .repeat_period = 100 },
 	[RC_PROTO_NEC] = { .name = "nec",
-		.scancode_bits = 0xffff, .repeat_period = 250 },
+		.scancode_bits = 0xffff, .repeat_period = 110 },
 	[RC_PROTO_NECX] = { .name = "nec-x",
-		.scancode_bits = 0xffffff, .repeat_period = 250 },
+		.scancode_bits = 0xffffff, .repeat_period = 110 },
 	[RC_PROTO_NEC32] = { .name = "nec-32",
-		.scancode_bits = 0xffffffff, .repeat_period = 250 },
+		.scancode_bits = 0xffffffff, .repeat_period = 110 },
 	[RC_PROTO_SANYO] = { .name = "sanyo",
-		.scancode_bits = 0x1fffff, .repeat_period = 250 },
+		.scancode_bits = 0x1fffff, .repeat_period = 125 },
 	[RC_PROTO_MCIR2_KBD] = { .name = "mcir2-kbd",
-		.scancode_bits = 0xffff, .repeat_period = 250 },
+		.scancode_bits = 0xffff, .repeat_period = 100 },
 	[RC_PROTO_MCIR2_MSE] = { .name = "mcir2-mse",
-		.scancode_bits = 0x1fffff, .repeat_period = 250 },
+		.scancode_bits = 0x1fffff, .repeat_period = 100 },
 	[RC_PROTO_RC6_0] = { .name = "rc-6-0",
-		.scancode_bits = 0xffff, .repeat_period = 250 },
+		.scancode_bits = 0xffff, .repeat_period = 114 },
 	[RC_PROTO_RC6_6A_20] = { .name = "rc-6-6a-20",
-		.scancode_bits = 0xfffff, .repeat_period = 250 },
+		.scancode_bits = 0xfffff, .repeat_period = 114 },
 	[RC_PROTO_RC6_6A_24] = { .name = "rc-6-6a-24",
-		.scancode_bits = 0xffffff, .repeat_period = 250 },
+		.scancode_bits = 0xffffff, .repeat_period = 114 },
 	[RC_PROTO_RC6_6A_32] = { .name = "rc-6-6a-32",
-		.scancode_bits = 0xffffffff, .repeat_period = 250 },
+		.scancode_bits = 0xffffffff, .repeat_period = 114 },
 	[RC_PROTO_RC6_MCE] = { .name = "rc-6-mce",
-		.scancode_bits = 0xffff7fff, .repeat_period = 250 },
+		.scancode_bits = 0xffff7fff, .repeat_period = 114 },
 	[RC_PROTO_SHARP] = { .name = "sharp",
-		.scancode_bits = 0x1fff, .repeat_period = 250 },
-	[RC_PROTO_XMP] = { .name = "xmp", .repeat_period = 250 },
-	[RC_PROTO_CEC] = { .name = "cec", .repeat_period = 550 },
+		.scancode_bits = 0x1fff, .repeat_period = 125 },
+	[RC_PROTO_XMP] = { .name = "xmp", .repeat_period = 125 },
+	[RC_PROTO_CEC] = { .name = "cec", .repeat_period = 0 },
 	[RC_PROTO_IMON] = { .name = "imon",
-		.scancode_bits = 0x7fffffff, .repeat_period = 250 },
+		.scancode_bits = 0x7fffffff, .repeat_period = 114 },
 };
 
 /* Used to keep track of known keymaps */
@@ -690,7 +690,8 @@ static void ir_timer_repeat(struct timer_list *t)
 void rc_repeat(struct rc_dev *dev)
 {
 	unsigned long flags;
-	unsigned int timeout = protocols[dev->last_protocol].repeat_period;
+	unsigned int timeout = nsecs_to_jiffies(dev->timeout) +
+		msecs_to_jiffies(protocols[dev->last_protocol].repeat_period);
 	struct lirc_scancode sc = {
 		.scancode = dev->last_scancode, .rc_proto = dev->last_protocol,
 		.keycode = dev->keypressed ? dev->last_keycode : KEY_RESERVED,
@@ -706,7 +707,7 @@ void rc_repeat(struct rc_dev *dev)
 	input_sync(dev->input_dev);
 
 	if (dev->keypressed) {
-		dev->keyup_jiffies = jiffies + msecs_to_jiffies(timeout);
+		dev->keyup_jiffies = jiffies + timeout;
 		mod_timer(&dev->timer_keyup, dev->keyup_jiffies);
 	}
 
@@ -801,7 +802,7 @@ void rc_keydown(struct rc_dev *dev, enum rc_proto protocol, u32 scancode,
 	ir_do_keydown(dev, protocol, scancode, keycode, toggle);
 
 	if (dev->keypressed) {
-		dev->keyup_jiffies = jiffies +
+		dev->keyup_jiffies = jiffies + nsecs_to_jiffies(dev->timeout) +
 			msecs_to_jiffies(protocols[protocol].repeat_period);
 		mod_timer(&dev->timer_keyup, dev->keyup_jiffies);
 	}
@@ -1647,6 +1648,7 @@ struct rc_dev *rc_allocate_device(enum rc_driver_type type)
 		dev->input_dev->setkeycode = ir_setkeycode;
 		input_set_drvdata(dev->input_dev, dev);
 
+		dev->timeout = IR_DEFAULT_TIMEOUT;
 		timer_setup(&dev->timer_keyup, ir_timer_keyup, 0);
 		timer_setup(&dev->timer_repeat, ir_timer_repeat, 0);
 
-- 
2.14.3

[PATCH v2 4/7] media: rc: mce_kbd decoder: low timeout values cause double keydowns

[Sean Young]

The mce keyboard repeats pressed keys every 100ms. If the IR timeout
is set to less than that, we send key up events before the repeat
arrives, so we have key up/key down for each IR repeat.

The keyboard ends any sequence with a 0 scancode, in which case all keys
are cleared so there is no need to run the timeout timer: it only exists
for the case that the final 0 was not received.

Signed-off-by: Sean Young <sean@mess.org>
---
 drivers/media/rc/ir-mce_kbd-decoder.c | 12 +++++++-----
 1 file changed, 7 insertions(+), 5 deletions(-)

diff --git a/drivers/media/rc/ir-mce_kbd-decoder.c b/drivers/media/rc/ir-mce_kbd-decoder.c
index ae4b980c4a16..230b9397aa11 100644
--- a/drivers/media/rc/ir-mce_kbd-decoder.c
+++ b/drivers/media/rc/ir-mce_kbd-decoder.c
@@ -322,11 +322,13 @@ static int ir_mce_kbd_decode(struct rc_dev *dev, struct ir_raw_event ev)
 			scancode = data->body & 0xffff;
 			dev_dbg(&dev->dev, "keyboard data 0x%08x\n",
 				data->body);
-			if (dev->timeout)
-				delay = usecs_to_jiffies(dev->timeout / 1000);
-			else
-				delay = msecs_to_jiffies(100);
-			mod_timer(&data->rx_timeout, jiffies + delay);
+			if (scancode) {
+				delay = nsecs_to_jiffies(dev->timeout) +
+					msecs_to_jiffies(100);
+				mod_timer(&data->rx_timeout, jiffies + delay);
+			} else {
+				del_timer(&data->rx_timeout);
+			}
 			/* Pass data to keyboard buffer parser */
 			ir_mce_kbd_process_keyboard_data(dev, scancode);
 			lsc.rc_proto = RC_PROTO_MCIR2_KBD;
-- 
2.14.3

[PATCH v2 5/7] media: rc: mce_kbd protocol encodes two scancodes

[Sean Young]

If two keys are pressed, then both keys are encoded in the scancode. This
makes the mce keyboard more responsive.

Signed-off-by: Sean Young <sean@mess.org>
---
 drivers/media/rc/ir-mce_kbd-decoder.c | 21 ++++++++++++---------
 drivers/media/rc/rc-main.c            |  2 +-
 2 files changed, 13 insertions(+), 10 deletions(-)

diff --git a/drivers/media/rc/ir-mce_kbd-decoder.c b/drivers/media/rc/ir-mce_kbd-decoder.c
index 230b9397aa11..dcdba83290d2 100644
--- a/drivers/media/rc/ir-mce_kbd-decoder.c
+++ b/drivers/media/rc/ir-mce_kbd-decoder.c
@@ -147,13 +147,14 @@ static enum mce_kbd_mode mce_kbd_mode(struct mce_kbd_dec *data)
 static void ir_mce_kbd_process_keyboard_data(struct rc_dev *dev, u32 scancode)
 {
 	struct mce_kbd_dec *data = &dev->raw->mce_kbd;
-	u8 keydata   = (scancode >> 8) & 0xff;
+	u8 keydata1  = (scancode >> 8) & 0xff;
+	u8 keydata2  = (scancode >> 16) & 0xff;
 	u8 shiftmask = scancode & 0xff;
-	unsigned char keycode, maskcode;
+	unsigned char maskcode;
 	int i, keystate;
 
-	dev_dbg(&dev->dev, "keyboard: keydata = 0x%02x, shiftmask = 0x%02x\n",
-		keydata, shiftmask);
+	dev_dbg(&dev->dev, "keyboard: keydata2 = 0x%02x, keydata1 = 0x%02x, shiftmask = 0x%02x\n",
+		keydata2, keydata1, shiftmask);
 
 	for (i = 0; i < 7; i++) {
 		maskcode = kbd_keycodes[MCIR2_MASK_KEYS_START + i];
@@ -164,10 +165,12 @@ static void ir_mce_kbd_process_keyboard_data(struct rc_dev *dev, u32 scancode)
 		input_report_key(data->idev, maskcode, keystate);
 	}
 
-	if (keydata) {
-		keycode = kbd_keycodes[keydata];
-		input_report_key(data->idev, keycode, 1);
-	} else {
+	if (keydata1)
+		input_report_key(data->idev, kbd_keycodes[keydata1], 1);
+	if (keydata2)
+		input_report_key(data->idev, kbd_keycodes[keydata2], 1);
+
+	if (!keydata1 && !keydata2) {
 		for (i = 0; i < MCIR2_MASK_KEYS_START; i++)
 			input_report_key(data->idev, kbd_keycodes[i], 0);
 	}
@@ -319,7 +322,7 @@ static int ir_mce_kbd_decode(struct rc_dev *dev, struct ir_raw_event ev)
 
 		switch (data->wanted_bits) {
 		case MCIR2_KEYBOARD_NBITS:
-			scancode = data->body & 0xffff;
+			scancode = data->body & 0xffffff;
 			dev_dbg(&dev->dev, "keyboard data 0x%08x\n",
 				data->body);
 			if (scancode) {
diff --git a/drivers/media/rc/rc-main.c b/drivers/media/rc/rc-main.c
index 9f4df60f62e1..b7071bde670a 100644
--- a/drivers/media/rc/rc-main.c
+++ b/drivers/media/rc/rc-main.c
@@ -51,7 +51,7 @@ static const struct {
 	[RC_PROTO_SANYO] = { .name = "sanyo",
 		.scancode_bits = 0x1fffff, .repeat_period = 125 },
 	[RC_PROTO_MCIR2_KBD] = { .name = "mcir2-kbd",
-		.scancode_bits = 0xffff, .repeat_period = 100 },
+		.scancode_bits = 0xffffff, .repeat_period = 100 },
 	[RC_PROTO_MCIR2_MSE] = { .name = "mcir2-mse",
 		.scancode_bits = 0x1fffff, .repeat_period = 100 },
 	[RC_PROTO_RC6_0] = { .name = "rc-6-0",
-- 
2.14.3

[PATCH v2 6/7] media: rc: mce_kbd decoder: fix stuck keys

[Sean Young]

The MCE Remote sends a 0 scancode when keys are released. If this is not
received or decoded, then keys can get "stuck"; the keyup event is not
sent since the input_sync() is missing from the timeout handler.

Cc: stable@vger.kernel.org
Signed-off-by: Sean Young <sean@mess.org>
---
 drivers/media/rc/ir-mce_kbd-decoder.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/drivers/media/rc/ir-mce_kbd-decoder.c b/drivers/media/rc/ir-mce_kbd-decoder.c
index dcdba83290d2..a6adf54461e9 100644
--- a/drivers/media/rc/ir-mce_kbd-decoder.c
+++ b/drivers/media/rc/ir-mce_kbd-decoder.c
@@ -130,6 +130,8 @@ static void mce_kbd_rx_timeout(struct timer_list *t)
 
 	for (i = 0; i < MCIR2_MASK_KEYS_START; i++)
 		input_report_key(raw->mce_kbd.idev, kbd_keycodes[i], 0);
+
+	input_sync(raw->mce_kbd.idev);
 }
 
 static enum mce_kbd_mode mce_kbd_mode(struct mce_kbd_dec *data)
-- 
2.14.3

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

[Sean Young]

mceusb devices have a default timeout of 100ms, but this can be changed.

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

diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
index 69ba57372c05..c97cb2eb1c5f 100644
--- a/drivers/media/rc/mceusb.c
+++ b/drivers/media/rc/mceusb.c
@@ -982,6 +982,25 @@ static int mceusb_set_tx_carrier(struct rc_dev *dev, u32 carrier)
 	return 0;
 }
 
+static int mceusb_set_timeout(struct rc_dev *dev, unsigned int timeout)
+{
+	u8 cmdbuf[4] = { MCE_CMD_PORT_IR, MCE_CMD_SETIRTIMEOUT, 0, 0 };
+	struct mceusb_dev *ir = dev->priv;
+	unsigned int units;
+
+	units = DIV_ROUND_CLOSEST(timeout, US_TO_NS(MCE_TIME_UNIT));
+
+	cmdbuf[2] = units >> 8;
+	cmdbuf[3] = units;
+
+	mce_async_out(ir, cmdbuf, sizeof(cmdbuf));
+
+	/* get receiver timeout value */
+	mce_async_out(ir, GET_RX_TIMEOUT, sizeof(GET_RX_TIMEOUT));
+
+	return 0;
+}
+
 /*
  * Select or deselect the 2nd receiver port.
  * Second receiver is learning mode, wide-band, short-range receiver.
@@ -1415,7 +1434,10 @@ static struct rc_dev *mceusb_init_rc_dev(struct mceusb_dev *ir)
 	rc->dev.parent = dev;
 	rc->priv = ir;
 	rc->allowed_protocols = RC_PROTO_BIT_ALL_IR_DECODER;
+	rc->min_timeout = US_TO_NS(MCE_TIME_UNIT);
 	rc->timeout = MS_TO_NS(100);
+	rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
+	rc->s_timeout = mceusb_set_timeout;
 	if (!ir->flags.no_tx) {
 		rc->s_tx_mask = mceusb_set_tx_mask;
 		rc->s_tx_carrier = mceusb_set_tx_carrier;
-- 
2.14.3

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

[Matthias Reichl]

Hi Sean!

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.

so long,

Hias

> Signed-off-by: Sean Young <sean@mess.org>
> ---
>  drivers/media/rc/mceusb.c | 22 ++++++++++++++++++++++
>  1 file changed, 22 insertions(+)
> 
> diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
> index 69ba57372c05..c97cb2eb1c5f 100644
> --- a/drivers/media/rc/mceusb.c
> +++ b/drivers/media/rc/mceusb.c
> @@ -982,6 +982,25 @@ static int mceusb_set_tx_carrier(struct rc_dev *dev, u32 carrier)
>  	return 0;
>  }
>  
> +static int mceusb_set_timeout(struct rc_dev *dev, unsigned int timeout)
> +{
> +	u8 cmdbuf[4] = { MCE_CMD_PORT_IR, MCE_CMD_SETIRTIMEOUT, 0, 0 };
> +	struct mceusb_dev *ir = dev->priv;
> +	unsigned int units;
> +
> +	units = DIV_ROUND_CLOSEST(timeout, US_TO_NS(MCE_TIME_UNIT));
> +
> +	cmdbuf[2] = units >> 8;
> +	cmdbuf[3] = units;
> +
> +	mce_async_out(ir, cmdbuf, sizeof(cmdbuf));
> +
> +	/* get receiver timeout value */
> +	mce_async_out(ir, GET_RX_TIMEOUT, sizeof(GET_RX_TIMEOUT));
> +
> +	return 0;
> +}
> +
>  /*
>   * Select or deselect the 2nd receiver port.
>   * Second receiver is learning mode, wide-band, short-range receiver.
> @@ -1415,7 +1434,10 @@ static struct rc_dev *mceusb_init_rc_dev(struct mceusb_dev *ir)
>  	rc->dev.parent = dev;
>  	rc->priv = ir;
>  	rc->allowed_protocols = RC_PROTO_BIT_ALL_IR_DECODER;
> +	rc->min_timeout = US_TO_NS(MCE_TIME_UNIT);
>  	rc->timeout = MS_TO_NS(100);
> +	rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
> +	rc->s_timeout = mceusb_set_timeout;
>  	if (!ir->flags.no_tx) {
>  		rc->s_tx_mask = mceusb_set_tx_mask;
>  		rc->s_tx_carrier = mceusb_set_tx_carrier;
> -- 
> 2.14.3
> 

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

[Sean Young]

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(-)

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

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

[Matthias Reichl]

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
> 

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

[Matthias Reichl]

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
> > 

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

[Matthias Reichl]

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

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

[Matthias Reichl]

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

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

[Matthias Reichl]

Hi Sean!

[ I trimmed the Cc list, as this is mceusb specific ]

On Sat, Apr 21, 2018 at 07:41:21PM +0200, Matthias Reichl wrote:
> On Sat, Apr 21, 2018 at 03:18:52PM +0200, Matthias Reichl wrote:
> > 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).

The original reporter gave up before I could get enough info
to understand what's going on, but now another user with an identical
receiver and the same problems showed up and I could get debug logs.

FYI: I've uploaded the full dmesg here if you need more info
or I snipped off too much:
http://www.horus.com/~hias/tmp/mceusb-settimeout-issue.txt

Here's the info about the IR receiver:
[    2.208684] usb 1-1.3: New USB device found, idVendor=1784, idProduct=0011
[    2.208699] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    2.208708] usb 1-1.3: Product: eHome Infrared Transceiver
[    2.208716] usb 1-1.3: Manufacturer: Topseed Technology Corp.
[    2.208724] usb 1-1.3: SerialNumber: EID0137AG-8-0000104054

With timeout configuration in the mceusb driver disabled everything
works fine. But with timeout configuration enabled spurious "keyup"
events show up during a button press and sometimes also a spurious
"ghost" keypress several seconds after the original button press.

Here's the ir-keytable -t output to illustrate the behaviour:

80.385585: event type EV_MSC(0x04): scancode = 0x800f0422
80.385585: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
80.385585: event type EV_SYN(0x00).
80.492469: event type EV_MSC(0x04): scancode = 0x800f0422
80.492469: event type EV_SYN(0x00).
80.633371: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
80.633371: event type EV_SYN(0x00).
80.642478: event type EV_MSC(0x04): scancode = 0x800f0422
80.642478: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
80.642478: event type EV_SYN(0x00).
80.783375: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
80.783375: event type EV_SYN(0x00).
84.318011: event type EV_MSC(0x04): scancode = 0x800f0422
84.318011: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
84.318011: event type EV_SYN(0x00).
84.460049: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
84.460049: event type EV_SYN(0x00).

>From the kernel log the first 2 scancodes are perfectly fine,
we get the timeout space in chunks, followed by the "End of raw IR data"
message and the scancode is properly decoded. Then about 45ms later
the pulses of the following IR message come in.

Snippet from end of second scancode:

[   80.505896] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
[   80.505902] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   80.505907] mceusb 1-1.3:1.0: Storing space with duration 6350000
[   80.505911] mceusb 1-1.3:1.0: processed IR data
[   80.506894] mceusb 1-1.3:1.0: rx data: 81 05 (length=2)
[   80.506899] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   80.506904] mceusb 1-1.3:1.0: Storing space with duration 250000
[   80.506908] rc rc0: enter idle mode
[   80.506913] rc rc0: sample: (25650us space)
[   80.506918] mceusb 1-1.3:1.0: rx data: 80 (length=1)
[   80.506922] mceusb 1-1.3:1.0: End of raw IR data
[   80.506925] mceusb 1-1.3:1.0: processed IR data
[   80.506943] rc rc0: RC6 decode started at state 6 (25650us space)
[   80.506949] rc rc0: RC6 decode started at state 8 (25650us space)
[   80.506955] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
[   80.506961] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scancode 0x800f0422 keycode 0x160
[   80.552906] mceusb 1-1.3:1.0: rx data: 81 b5 (length=2)
[   80.552914] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   80.552919] mceusb 1-1.3:1.0: Storing pulse with duration 2650000
[   80.552924] rc rc0: leave idle mode

But then, the end of the third scancode gets interesting. The
last chunk of the timeout space is missing and instead we get
a combined message with the remaining space and a zero-length
pulse just before the fourth IR message starts. Of course, this is
too late and the keyup timer had already expired:

[   80.612896] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
[   80.612903] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   80.612908] mceusb 1-1.3:1.0: Storing space with duration 6350000
[   80.612912] mceusb 1-1.3:1.0: processed IR data
[   80.647880] rc rc0: keyup key 0x0160
[   80.656901] mceusb 1-1.3:1.0: rx data: 82 05 80 (length=3)
[   80.656908] mceusb 1-1.3:1.0: Raw IR data, 2 pulse/space samples
[   80.656913] mceusb 1-1.3:1.0: Storing space with duration 250000
[   80.656918] rc rc0: enter idle mode
[   80.656923] rc rc0: sample: (25650us space)
[   80.656928] mceusb 1-1.3:1.0: Storing pulse with duration 0
[   80.656931] rc rc0: leave idle mode
[   80.656935] mceusb 1-1.3:1.0: processed IR data
[   80.656967] rc rc0: RC6 decode started at state 6 (25650us space)
[   80.656973] rc rc0: RC6 decode started at state 8 (25650us space)
[   80.656979] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
[   80.656986] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scancode 0x800f0422 keycode 0x160
[   80.656998] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): key down event, key 0x0160, protocol 0x0013, scancode 0x800f0422
[   80.659900] mceusb 1-1.3:1.0: rx data: 81 b6 (length=2)
[   80.659908] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   80.659913] mceusb 1-1.3:1.0: Storing pulse with duration 2700000
[   80.659916] mceusb 1-1.3:1.0: processed IR data

A similar thing happened on the fourth IR message, a spurious pulse
picked up by the IR receiver about 4 seconds after the message seems
to have made it send out it's data and flush the decoder:

[   80.719899] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
[   80.719905] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   80.719910] mceusb 1-1.3:1.0: Storing space with duration 6350000
[   80.719914] mceusb 1-1.3:1.0: processed IR data
[   80.797908] rc rc0: keyup key 0x0160
[   84.332919] mceusb 1-1.3:1.0: rx data: 83 05 80 81 (length=4)
[   84.332934] mceusb 1-1.3:1.0: Raw IR data, 3 pulse/space samples
[   84.332944] mceusb 1-1.3:1.0: Storing space with duration 250000
[   84.332954] rc rc0: enter idle mode
[   84.332964] rc rc0: sample: (25650us space)
[   84.332973] mceusb 1-1.3:1.0: Storing pulse with duration 0
[   84.332981] rc rc0: leave idle mode
[   84.332989] mceusb 1-1.3:1.0: Storing pulse with duration 50000
[   84.332997] mceusb 1-1.3:1.0: processed IR data
[   84.333046] rc rc0: RC6 decode started at state 6 (25650us space)
[   84.333057] rc rc0: RC6 decode started at state 8 (25650us space)
[   84.333068] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
[   84.333080] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scanco
de 0x800f0422 keycode 0x160
[   84.333098] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): key do
wn event, key 0x0160, protocol 0x0013, scancode 0x800f0422
[   84.339912] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
[   84.339925] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   84.339934] mceusb 1-1.3:1.0: Storing space with duration 6350000
[   84.339944] rc rc0: sample: (00050us pulse)
[   84.339952] mceusb 1-1.3:1.0: processed IR data
[   84.339994] rc rc0: RC6 decode failed at state 0 (50us pulse)
[   84.345908] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
[   84.345918] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
[   84.345927] mceusb 1-1.3:1.0: Storing space with duration 6350000
[   84.345935] mceusb 1-1.3:1.0: processed IR data

We have both rc-6 and NEC protocol enabled and the timeout is
therefore auto-configured to 25650us. I'm wondering if this could
have something to do with the odd behaviour as we'll get a very
short 250us space message from the IR receiver (in addition to
the 4 6350us spaces). Maybe this triggers some bug in the IR
receiver?

As we saw those issues on RPi, where USB has always been a bit
problematic, I wouldn't rule that out as a possible cause as well.

I've asked the reporter to test with various other timeout values,
this should hopefully provide some more info.

so long,

Hias

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

[Sean Young]

Hi Hias,

On Mon, May 07, 2018 at 05:54:55PM +0200, Matthias Reichl wrote:
> Hi Sean!
> 
> [ I trimmed the Cc list, as this is mceusb specific ]
> 
> On Sat, Apr 21, 2018 at 07:41:21PM +0200, Matthias Reichl wrote:
> > On Sat, Apr 21, 2018 at 03:18:52PM +0200, Matthias Reichl wrote:
> > > 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).
> 
> The original reporter gave up before I could get enough info
> to understand what's going on, but now another user with an identical
> receiver and the same problems showed up and I could get debug logs.
> 
> FYI: I've uploaded the full dmesg here if you need more info
> or I snipped off too much:
> http://www.horus.com/~hias/tmp/mceusb-settimeout-issue.txt
> 
> Here's the info about the IR receiver:
> [    2.208684] usb 1-1.3: New USB device found, idVendor=1784, idProduct=0011
> [    2.208699] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> [    2.208708] usb 1-1.3: Product: eHome Infrared Transceiver
> [    2.208716] usb 1-1.3: Manufacturer: Topseed Technology Corp.
> [    2.208724] usb 1-1.3: SerialNumber: EID0137AG-8-0000104054
> 
> With timeout configuration in the mceusb driver disabled everything
> works fine. But with timeout configuration enabled spurious "keyup"
> events show up during a button press and sometimes also a spurious
> "ghost" keypress several seconds after the original button press.
> 
> Here's the ir-keytable -t output to illustrate the behaviour:
> 
> 80.385585: event type EV_MSC(0x04): scancode = 0x800f0422
> 80.385585: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 80.385585: event type EV_SYN(0x00).
> 80.492469: event type EV_MSC(0x04): scancode = 0x800f0422
> 80.492469: event type EV_SYN(0x00).
> 80.633371: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 80.633371: event type EV_SYN(0x00).
> 80.642478: event type EV_MSC(0x04): scancode = 0x800f0422
> 80.642478: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 80.642478: event type EV_SYN(0x00).
> 80.783375: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 80.783375: event type EV_SYN(0x00).
> 84.318011: event type EV_MSC(0x04): scancode = 0x800f0422
> 84.318011: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> 84.318011: event type EV_SYN(0x00).
> 84.460049: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> 84.460049: event type EV_SYN(0x00).
> 
> >From the kernel log the first 2 scancodes are perfectly fine,
> we get the timeout space in chunks, followed by the "End of raw IR data"
> message and the scancode is properly decoded. Then about 45ms later
> the pulses of the following IR message come in.
> 
> Snippet from end of second scancode:
> 
> [   80.505896] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)

I've been staring at these logs for days now. :) So here, 0x81 means one
byte of IR data, which is 0x7f. For each byte of IR data, if the high 
bit is set (so value >= 0x80) it is a pulse, else space. The remaining
7 bits denote the length of the pulse or space, times 50us. So here
we have 127 * 50 = 6350us space.

> [   80.505902] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   80.505907] mceusb 1-1.3:1.0: Storing space with duration 6350000
> [   80.505911] mceusb 1-1.3:1.0: processed IR data
> [   80.506894] mceusb 1-1.3:1.0: rx data: 81 05 (length=2)
> [   80.506899] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   80.506904] mceusb 1-1.3:1.0: Storing space with duration 250000

5 * 50 us = 250us space

> [   80.506908] rc rc0: enter idle mode
> [   80.506913] rc rc0: sample: (25650us space)
> [   80.506918] mceusb 1-1.3:1.0: rx data: 80 (length=1)

So the 80 here is the byte which marks the timeout.

> [   80.506922] mceusb 1-1.3:1.0: End of raw IR data
> [   80.506925] mceusb 1-1.3:1.0: processed IR data
> [   80.506943] rc rc0: RC6 decode started at state 6 (25650us space)
> [   80.506949] rc rc0: RC6 decode started at state 8 (25650us space)
> [   80.506955] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
> [   80.506961] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scancode 0x800f0422 keycode 0x160
> [   80.552906] mceusb 1-1.3:1.0: rx data: 81 b5 (length=2)
> [   80.552914] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   80.552919] mceusb 1-1.3:1.0: Storing pulse with duration 2650000
> [   80.552924] rc rc0: leave idle mode
> 
> But then, the end of the third scancode gets interesting. The
> last chunk of the timeout space is missing and instead we get
> a combined message with the remaining space and a zero-length
> pulse just before the fourth IR message starts. Of course, this is
> too late and the keyup timer had already expired:
> 
> [   80.612896] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> [   80.612903] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   80.612908] mceusb 1-1.3:1.0: Storing space with duration 6350000
> [   80.612912] mceusb 1-1.3:1.0: processed IR data
> [   80.647880] rc rc0: keyup key 0x0160
> [   80.656901] mceusb 1-1.3:1.0: rx data: 82 05 80 (length=3)

Here some is wrong. We have 2 bytes. The first one is 5 * 50 space, followed
by 0x80. First thing to observe is that we are are expecting a timeout
message here, but that would should be encoded as: 81 05 80 (so 1 byte
message of pulse/space follow by a new message.

Since 80 is interpreted as pulse/space (not timeout marker) we end up
with a pulse of length 0.

> [   80.656908] mceusb 1-1.3:1.0: Raw IR data, 2 pulse/space samples
> [   80.656913] mceusb 1-1.3:1.0: Storing space with duration 250000
> [   80.656918] rc rc0: enter idle mode
> [   80.656923] rc rc0: sample: (25650us space)
> [   80.656928] mceusb 1-1.3:1.0: Storing pulse with duration 0

See here pulse with duration 0. Which is invalid IR and really shouldn't
be generated by the driver.

Now, we could add some code that if 0x80 is encountered in pulse/space
irdata, then we see this as a timeout. However, ...

> [   80.656931] rc rc0: leave idle mode
> [   80.656935] mceusb 1-1.3:1.0: processed IR data
> [   80.656967] rc rc0: RC6 decode started at state 6 (25650us space)
> [   80.656973] rc rc0: RC6 decode started at state 8 (25650us space)
> [   80.656979] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
> [   80.656986] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scancode 0x800f0422 keycode 0x160
> [   80.656998] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): key down event, key 0x0160, protocol 0x0013, scancode 0x800f0422
> [   80.659900] mceusb 1-1.3:1.0: rx data: 81 b6 (length=2)
> [   80.659908] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   80.659913] mceusb 1-1.3:1.0: Storing pulse with duration 2700000
> [   80.659916] mceusb 1-1.3:1.0: processed IR data
> 
> A similar thing happened on the fourth IR message, a spurious pulse
> picked up by the IR receiver about 4 seconds after the message seems
> to have made it send out it's data and flush the decoder:
> 
> [   80.719899] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> [   80.719905] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   80.719910] mceusb 1-1.3:1.0: Storing space with duration 6350000
> [   80.719914] mceusb 1-1.3:1.0: processed IR data
> [   80.797908] rc rc0: keyup key 0x0160
> [   84.332919] mceusb 1-1.3:1.0: rx data: 83 05 80 81 (length=4)

This is looking very strange. We have 3 bytes; 250us space, timeout,
and then 50us pulse. The 250us space and timeout are about 4 seconds
late (the previous 4x6350us space were received much earlier, so the 
remainder of space before the timeout should have been sent much sooner.

> [   84.332934] mceusb 1-1.3:1.0: Raw IR data, 3 pulse/space samples
> [   84.332944] mceusb 1-1.3:1.0: Storing space with duration 250000
> [   84.332954] rc rc0: enter idle mode
> [   84.332964] rc rc0: sample: (25650us space)
> [   84.332973] mceusb 1-1.3:1.0: Storing pulse with duration 0
> [   84.332981] rc rc0: leave idle mode
> [   84.332989] mceusb 1-1.3:1.0: Storing pulse with duration 50000
> [   84.332997] mceusb 1-1.3:1.0: processed IR data
> [   84.333046] rc rc0: RC6 decode started at state 6 (25650us space)
> [   84.333057] rc rc0: RC6 decode started at state 8 (25650us space)
> [   84.333068] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
> [   84.333080] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scanco
> de 0x800f0422 keycode 0x160
> [   84.333098] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): key do
> wn event, key 0x0160, protocol 0x0013, scancode 0x800f0422
> [   84.339912] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> [   84.339925] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   84.339934] mceusb 1-1.3:1.0: Storing space with duration 6350000
> [   84.339944] rc rc0: sample: (00050us pulse)
> [   84.339952] mceusb 1-1.3:1.0: processed IR data
> [   84.339994] rc rc0: RC6 decode failed at state 0 (50us pulse)
> [   84.345908] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> [   84.345918] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> [   84.345927] mceusb 1-1.3:1.0: Storing space with duration 6350000
> [   84.345935] mceusb 1-1.3:1.0: processed IR data
> 
> We have both rc-6 and NEC protocol enabled and the timeout is
> therefore auto-configured to 25650us. I'm wondering if this could
> have something to do with the odd behaviour as we'll get a very
> short 250us space message from the IR receiver (in addition to
> the 4 6350us spaces). Maybe this triggers some bug in the IR
> receiver?

I think that is correct. For this mceusb device, we should add a quirk
which disables the setting of a timeout.

I do wonder if this could work in a slightly different way. Since the
device sends out space information before the timeout (every ~6ms), rather
than relying on setting a timeout on the device, we could rely on a 
software timeout handler. It would not be able to set timeouts > 100ms
but we're mostly not interested in that anyway.

> As we saw those issues on RPi, where USB has always been a bit
> problematic, I wouldn't rule that out as a possible cause as well.
> 
> I've asked the reporter to test with various other timeout values,
> this should hopefully provide some more info.
> 
> so long,
> 
> Hias

Here is a patch which hopefully solves it.

Thank you!

Sean

>From 075e1567851ebe3e9d36b30f436c9468fd8772a8 Mon Sep 17 00:00:00 2001
From: Sean Young <sean@mess.org>
Date: Wed, 9 May 2018 11:11:28 +0100
Subject: [PATCH] media: mceusb: MCE_CMD_SETIRTIMEOUT cause strange behaviour
 on device

If the IR timeout is set on vid 1784 pid 0011, the device starts
behaving strangely.

Reported-by: Matthias Reichl <hias@horus.com>
Signed-off-by: Sean Young <sean@mess.org>
---
 drivers/media/rc/mceusb.c | 22 +++++++++++++++++++---
 1 file changed, 19 insertions(+), 3 deletions(-)

diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
index 5c0bf61fae26..1619b748469b 100644
--- a/drivers/media/rc/mceusb.c
+++ b/drivers/media/rc/mceusb.c
@@ -181,6 +181,7 @@ enum mceusb_model_type {
 	MCE_GEN2 = 0,		/* Most boards */
 	MCE_GEN1,
 	MCE_GEN3,
+	MCE_GEN3_BROKEN_IRTIMEOUT,
 	MCE_GEN2_TX_INV,
 	MCE_GEN2_TX_INV_RX_GOOD,
 	POLARIS_EVK,
@@ -199,6 +200,7 @@ struct mceusb_model {
 	u32 mce_gen3:1;
 	u32 tx_mask_normal:1;
 	u32 no_tx:1;
+	u32 broken_irtimeout:1;
 	/*
 	 * 2nd IR receiver (short-range, wideband) for learning mode:
 	 *     0, absent 2nd receiver (rx2)
@@ -242,6 +244,12 @@ static const struct mceusb_model mceusb_model[] = {
 		.tx_mask_normal = 1,
 		.rx2 = 2,
 	},
+	[MCE_GEN3_BROKEN_IRTIMEOUT] = {
+		.mce_gen3 = 1,
+		.tx_mask_normal = 1,
+		.rx2 = 2,
+		.broken_irtimeout = 1
+	},
 	[POLARIS_EVK] = {
 		/*
 		 * In fact, the EVK is shipped without
@@ -352,7 +360,7 @@ static const struct usb_device_id mceusb_dev_table[] = {
 	  .driver_info = MCE_GEN2_TX_INV },
 	/* Topseed eHome Infrared Transceiver */
 	{ USB_DEVICE(VENDOR_TOPSEED, 0x0011),
-	  .driver_info = MCE_GEN3 },
+	  .driver_info = MCE_GEN3_BROKEN_IRTIMEOUT },
 	/* Ricavision internal Infrared Transceiver */
 	{ USB_DEVICE(VENDOR_RICAVISION, 0x0010) },
 	/* Itron ione Libra Q-11 */
@@ -1441,8 +1449,16 @@ static struct rc_dev *mceusb_init_rc_dev(struct mceusb_dev *ir)
 	rc->allowed_protocols = RC_PROTO_BIT_ALL_IR_DECODER;
 	rc->min_timeout = US_TO_NS(MCE_TIME_UNIT);
 	rc->timeout = MS_TO_NS(100);
-	rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
-	rc->s_timeout = mceusb_set_timeout;
+	if (!mceusb_model[ir->model].broken_irtimeout) {
+		rc->s_timeout = mceusb_set_timeout;
+		rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
+	} else {
+		/*
+		 * If we can't set the timeout using CMD_SETIRTIMEOUT, we can
+		 * rely on software timeouts for timeouts < 100ms.
+		 */
+		rc->max_timeout = rc->timeout;
+	}
 	if (!ir->flags.no_tx) {
 		rc->s_tx_mask = mceusb_set_tx_mask;
 		rc->s_tx_carrier = mceusb_set_tx_carrier;
-- 
2.14.3

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

[Matthias Reichl]

Hi Sean!

On Wed, May 09, 2018 at 10:44:42PM +0100, Sean Young wrote:
> Hi Hias,
> 
> On Mon, May 07, 2018 at 05:54:55PM +0200, Matthias Reichl wrote:
> > Hi Sean!
> > 
> > [ I trimmed the Cc list, as this is mceusb specific ]
> > 
> > On Sat, Apr 21, 2018 at 07:41:21PM +0200, Matthias Reichl wrote:
> > > On Sat, Apr 21, 2018 at 03:18:52PM +0200, Matthias Reichl wrote:
> > > > 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).
> > 
> > The original reporter gave up before I could get enough info
> > to understand what's going on, but now another user with an identical
> > receiver and the same problems showed up and I could get debug logs.
> > 
> > FYI: I've uploaded the full dmesg here if you need more info
> > or I snipped off too much:
> > http://www.horus.com/~hias/tmp/mceusb-settimeout-issue.txt
> > 
> > Here's the info about the IR receiver:
> > [    2.208684] usb 1-1.3: New USB device found, idVendor=1784, idProduct=0011
> > [    2.208699] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> > [    2.208708] usb 1-1.3: Product: eHome Infrared Transceiver
> > [    2.208716] usb 1-1.3: Manufacturer: Topseed Technology Corp.
> > [    2.208724] usb 1-1.3: SerialNumber: EID0137AG-8-0000104054
> > 
> > With timeout configuration in the mceusb driver disabled everything
> > works fine. But with timeout configuration enabled spurious "keyup"
> > events show up during a button press and sometimes also a spurious
> > "ghost" keypress several seconds after the original button press.
> > 
> > Here's the ir-keytable -t output to illustrate the behaviour:
> > 
> > 80.385585: event type EV_MSC(0x04): scancode = 0x800f0422
> > 80.385585: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> > 80.385585: event type EV_SYN(0x00).
> > 80.492469: event type EV_MSC(0x04): scancode = 0x800f0422
> > 80.492469: event type EV_SYN(0x00).
> > 80.633371: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> > 80.633371: event type EV_SYN(0x00).
> > 80.642478: event type EV_MSC(0x04): scancode = 0x800f0422
> > 80.642478: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> > 80.642478: event type EV_SYN(0x00).
> > 80.783375: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> > 80.783375: event type EV_SYN(0x00).
> > 84.318011: event type EV_MSC(0x04): scancode = 0x800f0422
> > 84.318011: event type EV_KEY(0x01) key_down: KEY_OK(0x0160)
> > 84.318011: event type EV_SYN(0x00).
> > 84.460049: event type EV_KEY(0x01) key_up: KEY_OK(0x0160)
> > 84.460049: event type EV_SYN(0x00).
> > 
> > >From the kernel log the first 2 scancodes are perfectly fine,
> > we get the timeout space in chunks, followed by the "End of raw IR data"
> > message and the scancode is properly decoded. Then about 45ms later
> > the pulses of the following IR message come in.
> > 
> > Snippet from end of second scancode:
> > 
> > [   80.505896] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> 
> I've been staring at these logs for days now. :)

You are not the only one :-)

> So here, 0x81 means one
> byte of IR data, which is 0x7f. For each byte of IR data, if the high 
> bit is set (so value >= 0x80) it is a pulse, else space. The remaining
> 7 bits denote the length of the pulse or space, times 50us. So here
> we have 127 * 50 = 6350us space.
> 
> > [   80.505902] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   80.505907] mceusb 1-1.3:1.0: Storing space with duration 6350000
> > [   80.505911] mceusb 1-1.3:1.0: processed IR data
> > [   80.506894] mceusb 1-1.3:1.0: rx data: 81 05 (length=2)
> > [   80.506899] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   80.506904] mceusb 1-1.3:1.0: Storing space with duration 250000
> 
> 5 * 50 us = 250us space
> 
> > [   80.506908] rc rc0: enter idle mode
> > [   80.506913] rc rc0: sample: (25650us space)
> > [   80.506918] mceusb 1-1.3:1.0: rx data: 80 (length=1)
> 
> So the 80 here is the byte which marks the timeout.

Yes. More specifically, it's the "IR Data End" message / command,
as mentioned on page 130 of the "Green Button" pdf.

> > [   80.506922] mceusb 1-1.3:1.0: End of raw IR data
> > [   80.506925] mceusb 1-1.3:1.0: processed IR data
> > [   80.506943] rc rc0: RC6 decode started at state 6 (25650us space)
> > [   80.506949] rc rc0: RC6 decode started at state 8 (25650us space)
> > [   80.506955] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
> > [   80.506961] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scancode 0x800f0422 keycode 0x160
> > [   80.552906] mceusb 1-1.3:1.0: rx data: 81 b5 (length=2)
> > [   80.552914] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   80.552919] mceusb 1-1.3:1.0: Storing pulse with duration 2650000
> > [   80.552924] rc rc0: leave idle mode
> > 
> > But then, the end of the third scancode gets interesting. The
> > last chunk of the timeout space is missing and instead we get
> > a combined message with the remaining space and a zero-length
> > pulse just before the fourth IR message starts. Of course, this is
> > too late and the keyup timer had already expired:
> > 
> > [   80.612896] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> > [   80.612903] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   80.612908] mceusb 1-1.3:1.0: Storing space with duration 6350000
> > [   80.612912] mceusb 1-1.3:1.0: processed IR data
> > [   80.647880] rc rc0: keyup key 0x0160
> > [   80.656901] mceusb 1-1.3:1.0: rx data: 82 05 80 (length=3)
> 
> Here some is wrong. We have 2 bytes. The first one is 5 * 50 space, followed
> by 0x80. First thing to observe is that we are are expecting a timeout
> message here, but that would should be encoded as: 81 05 80 (so 1 byte
> message of pulse/space follow by a new message.
> 
> Since 80 is interpreted as pulse/space (not timeout marker) we end up
> with a pulse of length 0.
> 
> > [   80.656908] mceusb 1-1.3:1.0: Raw IR data, 2 pulse/space samples
> > [   80.656913] mceusb 1-1.3:1.0: Storing space with duration 250000
> > [   80.656918] rc rc0: enter idle mode
> > [   80.656923] rc rc0: sample: (25650us space)
> > [   80.656928] mceusb 1-1.3:1.0: Storing pulse with duration 0
> 
> See here pulse with duration 0. Which is invalid IR and really shouldn't
> be generated by the driver.
> 
> Now, we could add some code that if 0x80 is encountered in pulse/space
> irdata, then we see this as a timeout. However, ...
> 
> > [   80.656931] rc rc0: leave idle mode
> > [   80.656935] mceusb 1-1.3:1.0: processed IR data
> > [   80.656967] rc rc0: RC6 decode started at state 6 (25650us space)
> > [   80.656973] rc rc0: RC6 decode started at state 8 (25650us space)
> > [   80.656979] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
> > [   80.656986] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scancode 0x800f0422 keycode 0x160
> > [   80.656998] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): key down event, key 0x0160, protocol 0x0013, scancode 0x800f0422
> > [   80.659900] mceusb 1-1.3:1.0: rx data: 81 b6 (length=2)
> > [   80.659908] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   80.659913] mceusb 1-1.3:1.0: Storing pulse with duration 2700000
> > [   80.659916] mceusb 1-1.3:1.0: processed IR data
> > 
> > A similar thing happened on the fourth IR message, a spurious pulse
> > picked up by the IR receiver about 4 seconds after the message seems
> > to have made it send out it's data and flush the decoder:
> > 
> > [   80.719899] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> > [   80.719905] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   80.719910] mceusb 1-1.3:1.0: Storing space with duration 6350000
> > [   80.719914] mceusb 1-1.3:1.0: processed IR data
> > [   80.797908] rc rc0: keyup key 0x0160
> > [   84.332919] mceusb 1-1.3:1.0: rx data: 83 05 80 81 (length=4)
> 
> This is looking very strange. We have 3 bytes; 250us space, timeout,
> and then 50us pulse. The 250us space and timeout are about 4 seconds
> late (the previous 4x6350us space were received much earlier, so the 
> remainder of space before the timeout should have been sent much sooner.

I don't think we should interpret 0x80 IR data as an IR data end /
timeout message. The binary value is the same, but we got it in
the context of an IR data message.

The "Green Button" pdf mentions durations have to be in the range
1-127. I haven't found a description how IR data with duration 0
should be handled, so I think we should treat IR data values 0x00
and 0x80 as illegal / undefined values.

We could add a check for duration 0 to mceusb_process_ir_data()
and then ignore such pluses/spaces, but I'm not sure if that could
cause any side effects so maybe better keep that code as is
and store pulses/space with duration 0.

> > [   84.332934] mceusb 1-1.3:1.0: Raw IR data, 3 pulse/space samples
> > [   84.332944] mceusb 1-1.3:1.0: Storing space with duration 250000
> > [   84.332954] rc rc0: enter idle mode
> > [   84.332964] rc rc0: sample: (25650us space)
> > [   84.332973] mceusb 1-1.3:1.0: Storing pulse with duration 0
> > [   84.332981] rc rc0: leave idle mode
> > [   84.332989] mceusb 1-1.3:1.0: Storing pulse with duration 50000
> > [   84.332997] mceusb 1-1.3:1.0: processed IR data
> > [   84.333046] rc rc0: RC6 decode started at state 6 (25650us space)
> > [   84.333057] rc rc0: RC6 decode started at state 8 (25650us space)
> > [   84.333068] rc rc0: RC6(6A) proto 0x0013, scancode 0x800f0422 (toggle: 1)
> > [   84.333080] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): scanco
> > de 0x800f0422 keycode 0x160
> > [   84.333098] rc rc0: Media Center Ed. eHome Infrared Remote Transceiver (1784:0011): key do
> > wn event, key 0x0160, protocol 0x0013, scancode 0x800f0422
> > [   84.339912] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> > [   84.339925] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   84.339934] mceusb 1-1.3:1.0: Storing space with duration 6350000
> > [   84.339944] rc rc0: sample: (00050us pulse)
> > [   84.339952] mceusb 1-1.3:1.0: processed IR data
> > [   84.339994] rc rc0: RC6 decode failed at state 0 (50us pulse)
> > [   84.345908] mceusb 1-1.3:1.0: rx data: 81 7f (length=2)
> > [   84.345918] mceusb 1-1.3:1.0: Raw IR data, 1 pulse/space samples
> > [   84.345927] mceusb 1-1.3:1.0: Storing space with duration 6350000
> > [   84.345935] mceusb 1-1.3:1.0: processed IR data
> > 
> > We have both rc-6 and NEC protocol enabled and the timeout is
> > therefore auto-configured to 25650us. I'm wondering if this could
> > have something to do with the odd behaviour as we'll get a very
> > short 250us space message from the IR receiver (in addition to
> > the 4 6350us spaces). Maybe this triggers some bug in the IR
> > receiver?
> 
> I think that is correct. For this mceusb device, we should add a quirk
> which disables the setting of a timeout.
> 
> I do wonder if this could work in a slightly different way. Since the
> device sends out space information before the timeout (every ~6ms), rather
> than relying on setting a timeout on the device, we could rely on a 
> software timeout handler. It would not be able to set timeouts > 100ms
> but we're mostly not interested in that anyway.

Ah, this is a very good idea!

I had thought about a quirk to use that device in the old, fixed 100ms,
timeout mode but if we can do <= 100ms in software it's a far
better and elegant solution.

The patch looks fine to me, I'll add it to our builds and see if
I can get some feedback on it.

so long & thanks a lot,

Hias

> > As we saw those issues on RPi, where USB has always been a bit
> > problematic, I wouldn't rule that out as a possible cause as well.
> > 
> > I've asked the reporter to test with various other timeout values,
> > this should hopefully provide some more info.
> > 
> > so long,
> > 
> > Hias
> 
> Here is a patch which hopefully solves it.
> 
> Thank you!
> 
> Sean
> 
> >>From 075e1567851ebe3e9d36b30f436c9468fd8772a8 Mon Sep 17 00:00:00 2001
> From: Sean Young <sean@mess.org>
> Date: Wed, 9 May 2018 11:11:28 +0100
> Subject: [PATCH] media: mceusb: MCE_CMD_SETIRTIMEOUT cause strange behaviour
>  on device
> 
> If the IR timeout is set on vid 1784 pid 0011, the device starts
> behaving strangely.
> 
> Reported-by: Matthias Reichl <hias@horus.com>
> Signed-off-by: Sean Young <sean@mess.org>
> ---
>  drivers/media/rc/mceusb.c | 22 +++++++++++++++++++---
>  1 file changed, 19 insertions(+), 3 deletions(-)
> 
> diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
> index 5c0bf61fae26..1619b748469b 100644
> --- a/drivers/media/rc/mceusb.c
> +++ b/drivers/media/rc/mceusb.c
> @@ -181,6 +181,7 @@ enum mceusb_model_type {
>  	MCE_GEN2 = 0,		/* Most boards */
>  	MCE_GEN1,
>  	MCE_GEN3,
> +	MCE_GEN3_BROKEN_IRTIMEOUT,
>  	MCE_GEN2_TX_INV,
>  	MCE_GEN2_TX_INV_RX_GOOD,
>  	POLARIS_EVK,
> @@ -199,6 +200,7 @@ struct mceusb_model {
>  	u32 mce_gen3:1;
>  	u32 tx_mask_normal:1;
>  	u32 no_tx:1;
> +	u32 broken_irtimeout:1;
>  	/*
>  	 * 2nd IR receiver (short-range, wideband) for learning mode:
>  	 *     0, absent 2nd receiver (rx2)
> @@ -242,6 +244,12 @@ static const struct mceusb_model mceusb_model[] = {
>  		.tx_mask_normal = 1,
>  		.rx2 = 2,
>  	},
> +	[MCE_GEN3_BROKEN_IRTIMEOUT] = {
> +		.mce_gen3 = 1,
> +		.tx_mask_normal = 1,
> +		.rx2 = 2,
> +		.broken_irtimeout = 1
> +	},
>  	[POLARIS_EVK] = {
>  		/*
>  		 * In fact, the EVK is shipped without
> @@ -352,7 +360,7 @@ static const struct usb_device_id mceusb_dev_table[] = {
>  	  .driver_info = MCE_GEN2_TX_INV },
>  	/* Topseed eHome Infrared Transceiver */
>  	{ USB_DEVICE(VENDOR_TOPSEED, 0x0011),
> -	  .driver_info = MCE_GEN3 },
> +	  .driver_info = MCE_GEN3_BROKEN_IRTIMEOUT },
>  	/* Ricavision internal Infrared Transceiver */
>  	{ USB_DEVICE(VENDOR_RICAVISION, 0x0010) },
>  	/* Itron ione Libra Q-11 */
> @@ -1441,8 +1449,16 @@ static struct rc_dev *mceusb_init_rc_dev(struct mceusb_dev *ir)
>  	rc->allowed_protocols = RC_PROTO_BIT_ALL_IR_DECODER;
>  	rc->min_timeout = US_TO_NS(MCE_TIME_UNIT);
>  	rc->timeout = MS_TO_NS(100);
> -	rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
> -	rc->s_timeout = mceusb_set_timeout;
> +	if (!mceusb_model[ir->model].broken_irtimeout) {
> +		rc->s_timeout = mceusb_set_timeout;
> +		rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
> +	} else {
> +		/*
> +		 * If we can't set the timeout using CMD_SETIRTIMEOUT, we can
> +		 * rely on software timeouts for timeouts < 100ms.
> +		 */
> +		rc->max_timeout = rc->timeout;
> +	}
>  	if (!ir->flags.no_tx) {
>  		rc->s_tx_mask = mceusb_set_tx_mask;
>  		rc->s_tx_carrier = mceusb_set_tx_carrier;
> -- 
> 2.14.3
> 

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

[Matthias Reichl]

Hi Sean,

On Thu, May 10, 2018 at 01:01:34PM +0200, Matthias Reichl wrote:
> On Wed, May 09, 2018 at 10:44:42PM +0100, Sean Young wrote:
> > On Mon, May 07, 2018 at 05:54:55PM +0200, Matthias Reichl wrote:
> > > The original reporter gave up before I could get enough info
> > > to understand what's going on, but now another user with an identical
> > > receiver and the same problems showed up and I could get debug logs.
> > > 
> > > FYI: I've uploaded the full dmesg here if you need more info
> > > or I snipped off too much:
> > > http://www.horus.com/~hias/tmp/mceusb-settimeout-issue.txt
> > > 
> > > Here's the info about the IR receiver:
> > > [    2.208684] usb 1-1.3: New USB device found, idVendor=1784, idProduct=0011
> > > [    2.208699] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> > > [    2.208708] usb 1-1.3: Product: eHome Infrared Transceiver
> > > [    2.208716] usb 1-1.3: Manufacturer: Topseed Technology Corp.
> > > [    2.208724] usb 1-1.3: SerialNumber: EID0137AG-8-0000104054
> >
> > I think that is correct. For this mceusb device, we should add a quirk
> > which disables the setting of a timeout.
> > 
> > I do wonder if this could work in a slightly different way. Since the
> > device sends out space information before the timeout (every ~6ms), rather
> > than relying on setting a timeout on the device, we could rely on a 
> > software timeout handler. It would not be able to set timeouts > 100ms
> > but we're mostly not interested in that anyway.
> 
> Ah, this is a very good idea!
> 
> I had thought about a quirk to use that device in the old, fixed 100ms,
> timeout mode but if we can do <= 100ms in software it's a far
> better and elegant solution.
> 
> The patch looks fine to me, I'll add it to our builds and see if
> I can get some feedback on it.

The user with the Topseed remote reported back, your patch fixed
the issue - thanks a lot!

so long,

Hias

> > Here is a patch which hopefully solves it.
> > 
> > Thank you!
> > 
> > Sean
> > 
> > >>From 075e1567851ebe3e9d36b30f436c9468fd8772a8 Mon Sep 17 00:00:00 2001
> > From: Sean Young <sean@mess.org>
> > Date: Wed, 9 May 2018 11:11:28 +0100
> > Subject: [PATCH] media: mceusb: MCE_CMD_SETIRTIMEOUT cause strange behaviour
> >  on device
> > 
> > If the IR timeout is set on vid 1784 pid 0011, the device starts
> > behaving strangely.
> > 
> > Reported-by: Matthias Reichl <hias@horus.com>
> > Signed-off-by: Sean Young <sean@mess.org>
> > ---
> >  drivers/media/rc/mceusb.c | 22 +++++++++++++++++++---
> >  1 file changed, 19 insertions(+), 3 deletions(-)
> > 
> > diff --git a/drivers/media/rc/mceusb.c b/drivers/media/rc/mceusb.c
> > index 5c0bf61fae26..1619b748469b 100644
> > --- a/drivers/media/rc/mceusb.c
> > +++ b/drivers/media/rc/mceusb.c
> > @@ -181,6 +181,7 @@ enum mceusb_model_type {
> >  	MCE_GEN2 = 0,		/* Most boards */
> >  	MCE_GEN1,
> >  	MCE_GEN3,
> > +	MCE_GEN3_BROKEN_IRTIMEOUT,
> >  	MCE_GEN2_TX_INV,
> >  	MCE_GEN2_TX_INV_RX_GOOD,
> >  	POLARIS_EVK,
> > @@ -199,6 +200,7 @@ struct mceusb_model {
> >  	u32 mce_gen3:1;
> >  	u32 tx_mask_normal:1;
> >  	u32 no_tx:1;
> > +	u32 broken_irtimeout:1;
> >  	/*
> >  	 * 2nd IR receiver (short-range, wideband) for learning mode:
> >  	 *     0, absent 2nd receiver (rx2)
> > @@ -242,6 +244,12 @@ static const struct mceusb_model mceusb_model[] = {
> >  		.tx_mask_normal = 1,
> >  		.rx2 = 2,
> >  	},
> > +	[MCE_GEN3_BROKEN_IRTIMEOUT] = {
> > +		.mce_gen3 = 1,
> > +		.tx_mask_normal = 1,
> > +		.rx2 = 2,
> > +		.broken_irtimeout = 1
> > +	},
> >  	[POLARIS_EVK] = {
> >  		/*
> >  		 * In fact, the EVK is shipped without
> > @@ -352,7 +360,7 @@ static const struct usb_device_id mceusb_dev_table[] = {
> >  	  .driver_info = MCE_GEN2_TX_INV },
> >  	/* Topseed eHome Infrared Transceiver */
> >  	{ USB_DEVICE(VENDOR_TOPSEED, 0x0011),
> > -	  .driver_info = MCE_GEN3 },
> > +	  .driver_info = MCE_GEN3_BROKEN_IRTIMEOUT },
> >  	/* Ricavision internal Infrared Transceiver */
> >  	{ USB_DEVICE(VENDOR_RICAVISION, 0x0010) },
> >  	/* Itron ione Libra Q-11 */
> > @@ -1441,8 +1449,16 @@ static struct rc_dev *mceusb_init_rc_dev(struct mceusb_dev *ir)
> >  	rc->allowed_protocols = RC_PROTO_BIT_ALL_IR_DECODER;
> >  	rc->min_timeout = US_TO_NS(MCE_TIME_UNIT);
> >  	rc->timeout = MS_TO_NS(100);
> > -	rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
> > -	rc->s_timeout = mceusb_set_timeout;
> > +	if (!mceusb_model[ir->model].broken_irtimeout) {
> > +		rc->s_timeout = mceusb_set_timeout;
> > +		rc->max_timeout = 10 * IR_DEFAULT_TIMEOUT;
> > +	} else {
> > +		/*
> > +		 * If we can't set the timeout using CMD_SETIRTIMEOUT, we can
> > +		 * rely on software timeouts for timeouts < 100ms.
> > +		 */
> > +		rc->max_timeout = rc->timeout;
> > +	}
> >  	if (!ir->flags.no_tx) {
> >  		rc->s_tx_mask = mceusb_set_tx_mask;
> >  		rc->s_tx_carrier = mceusb_set_tx_carrier;
> > -- 
> > 2.14.3
> > 

Re: [PATCH v2 0/7] Improve latency of IR decoding

[Matthias Reichl]

Hi Sean,

On Sun, Apr 08, 2018 at 10:19:35PM +0100, Sean Young wrote:
> The current IR decoding is much too slow. Many IR protocols rely on
> a trailing space for decoding (e.g. rc-6 needs to know when the bits
> end). The trailing space is generated by the IR timeout, and if this
> is longer than required, buttons can feel slow to respond.
> 
> The other issue is the keyup timer. IR has no concept of a keyup message,
> this is implied by the absence of IR. So, minimising the timeout for
> this makes buttons less "sticky"; the are released much quicker.
> 
> With these patches in place, using IR with the builtin decoders is much
> improved and feels very snappy.
> 
> Changes since v1:
>  - lost more testing
>  - fixed various issues with mce decoder
>  - fixed mceusb so it can use better timeout too

thanks, this version is working fine with meson-ir and gpio-rc-recv
(latter on RPi). I mainly tested it with rc-5 remotes so far, more
will follow and I'll update LibreELEC in a day or two to include
the v2 series.

Also thanks a lot for the mce_kbd fixes, I was just going to dig
into the decoder (we received a bug report about stuck keys with
mce_kbd last week), your patches can in just at the right time :)

I had a closer look at ir-mce_kbd-decoder.c and noticed 2 things
(which can be handled separately):

It looks like the input_sync call in the state machine error
path is not necessary:

out:
	dev_dbg(&dev->dev, "failed at state %i (%uus %s)\n",
		data->state, TO_US(ev.duration), TO_STR(ev.pulse));
	data->state = STATE_INACTIVE;
	input_sync(data->idev);
	return -EINVAL;

If I followed the code paths correctly states that generate
input events won't go to out, only paths were no events are
generated jump to out - but better verify that, I could have
missed something.

The other thing I noticed is that there's no spinlock synchronizing
the events from the timeout callback with the ones from the state
machine - like keylock in rc-main. So the code could potentially
be racy (if the timeout fires while the state machine is outputting
events).

so long,

Hias

> 
> Sean Young (7):
>   media: rc: set timeout to smallest value required by enabled protocols
>   media: rc: add ioctl to get the current timeout
>   media: rc: per-protocol repeat period and minimum keyup timer
>   media: rc: mce_kbd decoder: low timeout values cause double keydowns
>   media: rc: mce_kbd protocol encodes two scancodes
>   media: rc: mce_kbd decoder: fix stuck keys
>   media: rc: mceusb: allow the timeout to be configurable
> 
>  Documentation/media/uapi/rc/lirc-func.rst          |  1 +
>  .../media/uapi/rc/lirc-set-rec-timeout.rst         | 14 +++--
>  drivers/media/cec/cec-core.c                       |  2 +-
>  drivers/media/rc/ir-imon-decoder.c                 |  1 +
>  drivers/media/rc/ir-jvc-decoder.c                  |  1 +
>  drivers/media/rc/ir-mce_kbd-decoder.c              | 36 +++++++-----
>  drivers/media/rc/ir-nec-decoder.c                  |  1 +
>  drivers/media/rc/ir-rc5-decoder.c                  |  1 +
>  drivers/media/rc/ir-rc6-decoder.c                  |  1 +
>  drivers/media/rc/ir-sanyo-decoder.c                |  1 +
>  drivers/media/rc/ir-sharp-decoder.c                |  1 +
>  drivers/media/rc/ir-sony-decoder.c                 |  1 +
>  drivers/media/rc/ir-xmp-decoder.c                  |  1 +
>  drivers/media/rc/lirc_dev.c                        |  9 ++-
>  drivers/media/rc/mceusb.c                          | 22 +++++++
>  drivers/media/rc/rc-core-priv.h                    |  1 +
>  drivers/media/rc/rc-ir-raw.c                       | 31 +++++++++-
>  drivers/media/rc/rc-main.c                         | 68 +++++++++++-----------
>  include/uapi/linux/lirc.h                          |  6 ++
>  19 files changed, 144 insertions(+), 55 deletions(-)
> 
> -- 
> 2.14.3
> 

Re: [PATCH v2 0/7] Improve latency of IR decoding

[Sean Young]

On Tue, Apr 10, 2018 at 07:53:43PM +0200, Matthias Reichl wrote:
> Hi Sean,
> 
> On Sun, Apr 08, 2018 at 10:19:35PM +0100, Sean Young wrote:
> > The current IR decoding is much too slow. Many IR protocols rely on
> > a trailing space for decoding (e.g. rc-6 needs to know when the bits
> > end). The trailing space is generated by the IR timeout, and if this
> > is longer than required, buttons can feel slow to respond.
> > 
> > The other issue is the keyup timer. IR has no concept of a keyup message,
> > this is implied by the absence of IR. So, minimising the timeout for
> > this makes buttons less "sticky"; the are released much quicker.
> > 
> > With these patches in place, using IR with the builtin decoders is much
> > improved and feels very snappy.
> > 
> > Changes since v1:
> >  - lost more testing
> >  - fixed various issues with mce decoder
> >  - fixed mceusb so it can use better timeout too
> 
> thanks, this version is working fine with meson-ir and gpio-rc-recv
> (latter on RPi). I mainly tested it with rc-5 remotes so far, more
> will follow and I'll update LibreELEC in a day or two to include
> the v2 series.

Thanks again for testing!

> Also thanks a lot for the mce_kbd fixes, I was just going to dig
> into the decoder (we received a bug report about stuck keys with
> mce_kbd last week), your patches can in just at the right time :)
> 
> I had a closer look at ir-mce_kbd-decoder.c and noticed 2 things
> (which can be handled separately):
> 
> It looks like the input_sync call in the state machine error
> path is not necessary:
> 
> out:
> 	dev_dbg(&dev->dev, "failed at state %i (%uus %s)\n",
> 		data->state, TO_US(ev.duration), TO_STR(ev.pulse));
> 	data->state = STATE_INACTIVE;
> 	input_sync(data->idev);
> 	return -EINVAL;
> 
> If I followed the code paths correctly states that generate
> input events won't go to out, only paths were no events are
> generated jump to out - but better verify that, I could have
> missed something.

The input_sync() patch is in mce_kbd_rx_timeout() code path, which
doesn't go through this. Hopefully it should fix the keys stuck
issue.

> The other thing I noticed is that there's no spinlock synchronizing
> the events from the timeout callback with the ones from the state
> machine - like keylock in rc-main. So the code could potentially
> be racy (if the timeout fires while the state machine is outputting
> events).

This timeout is for sending keyups in case no keyup is received from
the keyboard via input_report_key(). The input system does locking
for us (see drivers/input/input.c:436).


Sean

Re: [PATCH v2 0/7] Improve latency of IR decoding

[Matthias Reichl]

On Tue, Apr 10, 2018 at 07:39:43PM +0100, Sean Young wrote:
> On Tue, Apr 10, 2018 at 07:53:43PM +0200, Matthias Reichl wrote:
> > Hi Sean,
> > 
> > On Sun, Apr 08, 2018 at 10:19:35PM +0100, Sean Young wrote:
> > > The current IR decoding is much too slow. Many IR protocols rely on
> > > a trailing space for decoding (e.g. rc-6 needs to know when the bits
> > > end). The trailing space is generated by the IR timeout, and if this
> > > is longer than required, buttons can feel slow to respond.
> > > 
> > > The other issue is the keyup timer. IR has no concept of a keyup message,
> > > this is implied by the absence of IR. So, minimising the timeout for
> > > this makes buttons less "sticky"; the are released much quicker.
> > > 
> > > With these patches in place, using IR with the builtin decoders is much
> > > improved and feels very snappy.
> > > 
> > > Changes since v1:
> > >  - lost more testing
> > >  - fixed various issues with mce decoder
> > >  - fixed mceusb so it can use better timeout too
> > 
> > thanks, this version is working fine with meson-ir and gpio-rc-recv
> > (latter on RPi). I mainly tested it with rc-5 remotes so far, more
> > will follow and I'll update LibreELEC in a day or two to include
> > the v2 series.
> 
> Thanks again for testing!
> 
> > Also thanks a lot for the mce_kbd fixes, I was just going to dig
> > into the decoder (we received a bug report about stuck keys with
> > mce_kbd last week), your patches can in just at the right time :)
> > 
> > I had a closer look at ir-mce_kbd-decoder.c and noticed 2 things
> > (which can be handled separately):
> > 
> > It looks like the input_sync call in the state machine error
> > path is not necessary:
> > 
> > out:
> > 	dev_dbg(&dev->dev, "failed at state %i (%uus %s)\n",
> > 		data->state, TO_US(ev.duration), TO_STR(ev.pulse));
> > 	data->state = STATE_INACTIVE;
> > 	input_sync(data->idev);
> > 	return -EINVAL;
> > 
> > If I followed the code paths correctly states that generate
> > input events won't go to out, only paths were no events are
> > generated jump to out - but better verify that, I could have
> > missed something.
> 
> The input_sync() patch is in mce_kbd_rx_timeout() code path, which
> doesn't go through this. Hopefully it should fix the keys stuck
> issue.

Yes, I saw that and the input_sync() in mce_kbd_rx_timeout() fixed
this (I could verify that locally).

What I meant is that the input_sync() in the snippet above, which
isn't touched by your patches, doesn't seem necessary, as the
code paths that lead to there don't submit input events. The
happy paths (successful key/mouse event and keyup) call input_sync()
at the end of STATE_FINISHED:

		lsc.scancode = scancode;
		ir_lirc_scancode_event(dev, &lsc);
		data->state = STATE_INACTIVE;
		input_event(data->idev, EV_MSC, MSC_SCAN, scancode);
		input_sync(data->idev);
		return 0;

> > The other thing I noticed is that there's no spinlock synchronizing
> > the events from the timeout callback with the ones from the state
> > machine - like keylock in rc-main. So the code could potentially
> > be racy (if the timeout fires while the state machine is outputting
> > events).
> 
> This timeout is for sending keyups in case no keyup is received from
> the keyboard via input_report_key(). The input system does locking
> for us (see drivers/input/input.c:436).

The synchronization code in rc-main looks like it's used to make
code blocks that eg call input_report_key and input_sync do that
in an atomic way (plus there's the special handling of keyup_jiffies
to prevent a race betwen the keyup timeout callback and new
decoded scancodes.

As both the timeout callback and the state machine send out
multiple key events and end them with input_sync it looks to me
like we'd need to make that atomic as well. Otherwise we could
have eg timeout running, starting to report a bunch of shift
and other keys as up, then interruption by a new key/scancode
calling input_report_key down plus input_sync and then timeout
resuming and reporting the rest of the keys down and again
do input_sync().

so long,

Hias

Re: [PATCH v2 0/7] Improve latency of IR decoding

[Sean Young]

On Tue, Apr 10, 2018 at 09:24:19PM +0200, Matthias Reichl wrote:
> On Tue, Apr 10, 2018 at 07:39:43PM +0100, Sean Young wrote:
> > On Tue, Apr 10, 2018 at 07:53:43PM +0200, Matthias Reichl wrote:
> > > Hi Sean,
> > > 
> > > On Sun, Apr 08, 2018 at 10:19:35PM +0100, Sean Young wrote:
> > > > The current IR decoding is much too slow. Many IR protocols rely on
> > > > a trailing space for decoding (e.g. rc-6 needs to know when the bits
> > > > end). The trailing space is generated by the IR timeout, and if this
> > > > is longer than required, buttons can feel slow to respond.
> > > > 
> > > > The other issue is the keyup timer. IR has no concept of a keyup message,
> > > > this is implied by the absence of IR. So, minimising the timeout for
> > > > this makes buttons less "sticky"; the are released much quicker.
> > > > 
> > > > With these patches in place, using IR with the builtin decoders is much
> > > > improved and feels very snappy.
> > > > 
> > > > Changes since v1:
> > > >  - lost more testing
> > > >  - fixed various issues with mce decoder
> > > >  - fixed mceusb so it can use better timeout too
> > > 
> > > thanks, this version is working fine with meson-ir and gpio-rc-recv
> > > (latter on RPi). I mainly tested it with rc-5 remotes so far, more
> > > will follow and I'll update LibreELEC in a day or two to include
> > > the v2 series.
> > 
> > Thanks again for testing!
> > 
> > > Also thanks a lot for the mce_kbd fixes, I was just going to dig
> > > into the decoder (we received a bug report about stuck keys with
> > > mce_kbd last week), your patches can in just at the right time :)
> > > 
> > > I had a closer look at ir-mce_kbd-decoder.c and noticed 2 things
> > > (which can be handled separately):
> > > 
> > > It looks like the input_sync call in the state machine error
> > > path is not necessary:
> > > 
> > > out:
> > > 	dev_dbg(&dev->dev, "failed at state %i (%uus %s)\n",
> > > 		data->state, TO_US(ev.duration), TO_STR(ev.pulse));
> > > 	data->state = STATE_INACTIVE;
> > > 	input_sync(data->idev);
> > > 	return -EINVAL;
> > > 
> > > If I followed the code paths correctly states that generate
> > > input events won't go to out, only paths were no events are
> > > generated jump to out - but better verify that, I could have
> > > missed something.
> > 
> > The input_sync() patch is in mce_kbd_rx_timeout() code path, which
> > doesn't go through this. Hopefully it should fix the keys stuck
> > issue.
> 
> Yes, I saw that and the input_sync() in mce_kbd_rx_timeout() fixed
> this (I could verify that locally).
> 
> What I meant is that the input_sync() in the snippet above, which
> isn't touched by your patches, doesn't seem necessary, as the
> code paths that lead to there don't submit input events. The
> happy paths (successful key/mouse event and keyup) call input_sync()
> at the end of STATE_FINISHED:
> 
> 		lsc.scancode = scancode;
> 		ir_lirc_scancode_event(dev, &lsc);
> 		data->state = STATE_INACTIVE;
> 		input_event(data->idev, EV_MSC, MSC_SCAN, scancode);
> 		input_sync(data->idev);
> 		return 0;

Yes, you're completely right.

> > > The other thing I noticed is that there's no spinlock synchronizing
> > > the events from the timeout callback with the ones from the state
> > > machine - like keylock in rc-main. So the code could potentially
> > > be racy (if the timeout fires while the state machine is outputting
> > > events).
> > 
> > This timeout is for sending keyups in case no keyup is received from
> > the keyboard via input_report_key(). The input system does locking
> > for us (see drivers/input/input.c:436).
> 
> The synchronization code in rc-main looks like it's used to make
> code blocks that eg call input_report_key and input_sync do that
> in an atomic way (plus there's the special handling of keyup_jiffies
> to prevent a race betwen the keyup timeout callback and new
> decoded scancodes.
> 
> As both the timeout callback and the state machine send out
> multiple key events and end them with input_sync it looks to me
> like we'd need to make that atomic as well. Otherwise we could
> have eg timeout running, starting to report a bunch of shift
> and other keys as up, then interruption by a new key/scancode
> calling input_report_key down plus input_sync and then timeout
> resuming and reporting the rest of the keys down and again
> do input_sync().

Again I stand corrected. I'm just testing some patches now for this.

Thanks for being patient and explaining that again :)

Sean