[PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling

[PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling

[Martin Kelly]

When interrupts are generated at a slower rate than the FIFO queue fills
up, we will have fewer timestamps than samples. Currently, we fill in 0
for any unmatched timestamps. However, this is very confusing for
userspace, which does not expect discontinuities in timestamps and
must somehow work around the issue.

Improve the situation by using the most recent timestamp when a
timestamp is missing. Although this guess is not perfectly accurate, it
is still close to the correct timestamp and won't result in the
confusion caused by using 0.

Signed-off-by: Martin Kelly <mkelly@xevo.com>
---
 drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

diff --git a/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c b/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
index ff81c6aa009d..a982037d5dad 100644
--- a/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
+++ b/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
@@ -126,6 +126,7 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
 	int result;
 	u8 data[INV_MPU6050_OUTPUT_DATA_SIZE];
 	u16 fifo_count;
+	s64 last_timestamp;
 	s64 timestamp;
 
 	mutex_lock(&st->lock);
@@ -159,6 +160,7 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
 	if (kfifo_len(&st->timestamps) >
 	    fifo_count / bytes_per_datum + INV_MPU6050_TIME_STAMP_TOR)
 		goto flush_fifo;
+	last_timestamp = 0;
 	while (fifo_count >= bytes_per_datum) {
 		result = regmap_bulk_read(st->map, st->reg->fifo_r_w,
 					  data, bytes_per_datum);
@@ -166,9 +168,11 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
 			goto flush_fifo;
 
 		result = kfifo_out(&st->timestamps, &timestamp, 1);
-		/* when there is no timestamp, put timestamp as 0 */
+		/* when there is no timestamp, just use the last one we saw */
 		if (result == 0)
-			timestamp = 0;
+			timestamp = last_timestamp;
+		else
+			last_timestamp = timestamp;
 
 		result = iio_push_to_buffers_with_timestamp(indio_dev, data,
 							    timestamp);
-- 
2.11.0

How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

[Jonathan Cameron]

On Fri, 23 Mar 2018 17:02:40 -0700
Martin Kelly <mkelly@xevo.com> wrote:

> When interrupts are generated at a slower rate than the FIFO queue fills
> up, we will have fewer timestamps than samples. Currently, we fill in 0
> for any unmatched timestamps. However, this is very confusing for
> userspace, which does not expect discontinuities in timestamps and
> must somehow work around the issue.
> 
> Improve the situation by using the most recent timestamp when a
> timestamp is missing. Although this guess is not perfectly accurate, it
> is still close to the correct timestamp and won't result in the
> confusion caused by using 0.
> 
> Signed-off-by: Martin Kelly <mkelly@xevo.com>
Hmm. I would like to see where other peoples opinions on this lie.
The decision to mark it as 0 was deliberately made.  There are a number
of applications where you have to 'know' the timestamps are incorrect
- pretending simply doesn't work.  Arguably it is fine for a system
to detect that it is seeing repeated values and hence 'fix them up.
This is a change in ABI however which is going to be unfortunate
if we have code out there which is doing the right thing - interpolating
timestamps only once we have another known point to build from.

So opinions anyone?

Jonathan
> ---
>  drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c | 8 ++++++--
>  1 file changed, 6 insertions(+), 2 deletions(-)
> 
> diff --git a/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c b/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
> index ff81c6aa009d..a982037d5dad 100644
> --- a/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
> +++ b/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
> @@ -126,6 +126,7 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
>  	int result;
>  	u8 data[INV_MPU6050_OUTPUT_DATA_SIZE];
>  	u16 fifo_count;
> +	s64 last_timestamp;
>  	s64 timestamp;
>  
>  	mutex_lock(&st->lock);
> @@ -159,6 +160,7 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
>  	if (kfifo_len(&st->timestamps) >
>  	    fifo_count / bytes_per_datum + INV_MPU6050_TIME_STAMP_TOR)
>  		goto flush_fifo;
> +	last_timestamp = 0;
>  	while (fifo_count >= bytes_per_datum) {
>  		result = regmap_bulk_read(st->map, st->reg->fifo_r_w,
>  					  data, bytes_per_datum);
> @@ -166,9 +168,11 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
>  			goto flush_fifo;
>  
>  		result = kfifo_out(&st->timestamps, &timestamp, 1);
> -		/* when there is no timestamp, put timestamp as 0 */
> +		/* when there is no timestamp, just use the last one we saw */
>  		if (result == 0)
> -			timestamp = 0;
> +			timestamp = last_timestamp;
> +		else
> +			last_timestamp = timestamp;
>  
>  		result = iio_push_to_buffers_with_timestamp(indio_dev, data,
>  							    timestamp);

Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

[Jean-Baptiste Maneyrol]

[-- Attachment #1: Type: text/plain, Size: 4219 bytes --]

Hello,


we should have 1 interrupt every time a sensor data has been acquired. So in theory this is not something that should happen. But real world is always a different story.


Do you have a case where you saw that happen?


The best way if this happens would be to create the timestamp based on the sampling rate since we know it (last timestamp + sampling interval). That would be very similar to the real value since the only difference is the clock drift between the chip and the system.


Best regards,

Jean-Baptiste Maneyrol

________________________________
From: linux-iio-owner@vger.kernel.org <linux-iio-owner@vger.kernel.org> on behalf of Jonathan Cameron <jic23@kernel.org>
Sent: Saturday, March 24, 2018 1:35:19 PM
To: Martin Kelly
Cc: linux-iio@vger.kernel.org; Jean-Baptiste Maneyrol
Subject: How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

On Fri, 23 Mar 2018 17:02:40 -0700
Martin Kelly <mkelly@xevo.com> wrote:

> When interrupts are generated at a slower rate than the FIFO queue fills
> up, we will have fewer timestamps than samples. Currently, we fill in 0
> for any unmatched timestamps. However, this is very confusing for
> userspace, which does not expect discontinuities in timestamps and
> must somehow work around the issue.
>
> Improve the situation by using the most recent timestamp when a
> timestamp is missing. Although this guess is not perfectly accurate, it
> is still close to the correct timestamp and won't result in the
> confusion caused by using 0.
>
> Signed-off-by: Martin Kelly <mkelly@xevo.com>
Hmm. I would like to see where other peoples opinions on this lie.
The decision to mark it as 0 was deliberately made.  There are a number
of applications where you have to 'know' the timestamps are incorrect
- pretending simply doesn't work.  Arguably it is fine for a system
to detect that it is seeing repeated values and hence 'fix them up.
This is a change in ABI however which is going to be unfortunate
if we have code out there which is doing the right thing - interpolating
timestamps only once we have another known point to build from.

So opinions anyone?

Jonathan
> ---
>  drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c | 8 ++++++--
>  1 file changed, 6 insertions(+), 2 deletions(-)
>
> diff --git a/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c b/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
> index ff81c6aa009d..a982037d5dad 100644
> --- a/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
> +++ b/drivers/iio/imu/inv_mpu6050/inv_mpu_ring.c
> @@ -126,6 +126,7 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
>        int result;
>        u8 data[INV_MPU6050_OUTPUT_DATA_SIZE];
>        u16 fifo_count;
> +     s64 last_timestamp;
>        s64 timestamp;
>
>        mutex_lock(&st->lock);
> @@ -159,6 +160,7 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
>        if (kfifo_len(&st->timestamps) >
>            fifo_count / bytes_per_datum + INV_MPU6050_TIME_STAMP_TOR)
>                goto flush_fifo;
> +     last_timestamp = 0;
>        while (fifo_count >= bytes_per_datum) {
>                result = regmap_bulk_read(st->map, st->reg->fifo_r_w,
>                                          data, bytes_per_datum);
> @@ -166,9 +168,11 @@ irqreturn_t inv_mpu6050_read_fifo(int irq, void *p)
>                        goto flush_fifo;
>
>                result = kfifo_out(&st->timestamps, &timestamp, 1);
> -             /* when there is no timestamp, put timestamp as 0 */
> +             /* when there is no timestamp, just use the last one we saw */
>                if (result == 0)
> -                     timestamp = 0;
> +                     timestamp = last_timestamp;
> +             else
> +                     last_timestamp = timestamp;
>
>                result = iio_push_to_buffers_with_timestamp(indio_dev, data,
>                                                            timestamp);

--
To unsubscribe from this list: send the line "unsubscribe linux-iio" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

[-- Attachment #2: Type: text/html, Size: 7883 bytes --]

Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

[Martin Kelly]

On 03/26/2018 07:20 AM, Jean-Baptiste Maneyrol wrote:
> Hello,
> 
> we should have 1 interrupt every time a sensor data has been acquired. So in theory this is not something that should happen. But real world is always a different story.
> 

Agreed.

> Do you have a case where you saw that happen?
> 

Yes, I'm seeing this on a board I'm working with. I'm also seeing I2C 
bus lockups at high frequencies, so my best guess (though speculation) 
is that the interrupts are being generated by the bus is dropping some 
of the messages. I'm seeing that, when the data ready interrupt fires, 
there are multiple messages in the FIFO, so all but the first get filled 
in with 0 timestamps. I plan to investigate why I'm getting bus lockups, 
but since this is exposed a bug, I wanted to first work on improving the 
resilience to such conditions.

> The best way if this happens would be to create the timestamp based on the sampling rate since we know it (last timestamp + sampling interval). That would be very similar to the real value since the only difference is  the clock drift between the chip and the system.
> 

That sounds reasonable. Let me make sure I understand what you're 
proposing. Let's say we have set the sample rate to 10 Hz. Every time we 
get an interrupt, we already take a timestamp, which should be the 
correct timestamp for the most recent sample. Imagine that after an 
interrupt, we see there are 4 samples in the FIFO instead of just 1. In 
that case, we mark the samples with timestamps:

sample 0 (oldest timestamp): interrupt timestamp - 0.3 seconds
sample 1: interrupt timestamp - 0.2 seconds
sample 2: interrupt timestamp - 0.1 seconds
sample 3 (newest timestamp): interrupt timestamp

Does that sound right to you? If so, I will revise my patch to do it.

Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

[Jean-Baptiste Maneyrol]

Hello,

this raises a good question of which interrupts we are missing (the oldest =
ones or the newest ones).

My bet would be that we are loosing interrupts from the newest data (the ir=
q thread can take too much time and we loose interrupt). In this case manua=
l timestamping would rather be:

sample 0 (oldest timestamp): interrupt timestamp
sample 1: interrupt timestamp + 0.1 seconds
sample 2: interrupt timestamp + 0.2 seconds
sample 3 (newest timestamp): interrupt timestamp + 0.3 seconds

Can you check with your setup that this is really what is happening?

Thanks for your feedback.

Best regards,
JB


From: Martin Kelly <mkelly@xevo.com>
Sent: Monday, March 26, 2018 19:43
To: Jean-Baptiste Maneyrol; Jonathan Cameron
Cc: linux-iio@vger.kernel.org
Subject: Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: i=
nv_mpu6050: improve missing timestamp handling)
=A0=20

On 03/26/2018 07:20 AM, Jean-Baptiste Maneyrol wrote:
> Hello,
>=20
> we should have 1 interrupt every time a sensor data has been acquired. So=
 in theory this is not something that should happen. But real world is alwa=
ys a different story.
>=20

Agreed.

> Do you have a case where you saw that happen?
>=20

Yes, I'm seeing this on a board I'm working with. I'm also seeing I2C=20
bus lockups at high frequencies, so my best guess (though speculation)=20
is that the interrupts are being generated by the bus is dropping some=20
of the messages. I'm seeing that, when the data ready interrupt fires,=20
there are multiple messages in the FIFO, so all but the first get filled=20
in with 0 timestamps. I plan to investigate why I'm getting bus lockups,=20
but since this is exposed a bug, I wanted to first work on improving the=20
resilience to such conditions.

> The best way if this happens would be to create the timestamp based on th=
e sampling rate since we know it (last timestamp + sampling interval). That=
 would be very similar to the real value since the only difference is=A0 th=
e clock drift between the chip and  the system.
>=20

That sounds reasonable. Let me make sure I understand what you're=20
proposing. Let's say we have set the sample rate to 10 Hz. Every time we=20
get an interrupt, we already take a timestamp, which should be the=20
correct timestamp for the most recent sample. Imagine that after an=20
interrupt, we see there are 4 samples in the FIFO instead of just 1. In=20
that case, we mark the samples with timestamps:

sample 0 (oldest timestamp): interrupt timestamp - 0.3 seconds
sample 1: interrupt timestamp - 0.2 seconds
sample 2: interrupt timestamp - 0.1 seconds
sample 3 (newest timestamp): interrupt timestamp

Does that sound right to you? If so, I will revise my patch to do it.
    =

Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

[Martin Kelly]

On 03/27/2018 01:47 AM, Jean-Baptiste Maneyrol wrote:
> Hello,
> 
> this raises a good question of which interrupts we are missing (the oldest ones or the newest ones).
> 
> My bet would be that we are loosing interrupts from the newest data (the irq thread can take too much time and we loose interrupt). In this case manual timestamping would rather be:
> 
> sample 0 (oldest timestamp): interrupt timestamp
> sample 1: interrupt timestamp + 0.1 seconds
> sample 2: interrupt timestamp + 0.2 seconds
> sample 3 (newest timestamp): interrupt timestamp + 0.3 seconds
> 
> Can you check with your setup that this is really what is happening?
> 

Yes, good point. I did a lot of testing and determined that the sequence 
of events is something like this:

IRQ --> timestamp
new datum
new datum
new datum
IRQ --> timestamp

Specifically:
- At 50 Hz, interrupts are being generated at about 30 Hz.
- The timestamps in the FIFO correspond to the *newest* data, not the 
oldest.

I tried interpolating using both assumptions: timestamps corresponding 
to oldest and then to newest data. Using timestamps corresponding to 
oldest data, we get timestamps that are not monotonically increasing and 
thus time moving backwards as the data flows. Using timestamps 
corresponding to oldest data, we get monotonically increasing time as it 
should be, and the data looks pretty consistent.

What I settled on is to use the newer timestamps we see to backdate the 
older data, the ones we remove first from the FIFO. It appears to be 
working nicely.

I sent a v2 of the patch that does this interpolation.

Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

[Jean-Baptiste Maneyrol]

Hello,

loosing data at 50Hz is really strange. I am currently running an old MPU-6=
500 at 200Hz on I2C @400KHz without any issue (using HiKey board).

Can you tell me what is the chip you are using, the board (CPU+freq) and th=
e I2C bus speed?

Anyway, your solution seems to be good, better then putting 0 for timestamp=
s.

Best regards,
JB
 =20
From: Martin Kelly <mkelly@xevo.com>
Sent: Wednesday, March 28, 2018 2:34:02 AM
To: Jean-Baptiste Maneyrol; Jonathan Cameron
Cc: linux-iio@vger.kernel.org
Subject: Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: i=
nv_mpu6050: improve missing timestamp handling)
=A0=20

On 03/27/2018 01:47 AM, Jean-Baptiste Maneyrol wrote:
> Hello,
>=20
> this raises a good question of which interrupts we are missing (the oldes=
t ones or the newest ones).
>=20
> My bet would be that we are loosing interrupts from the newest data (the =
irq thread can take too much time and we loose interrupt). In this case man=
ual timestamping would rather be:
>=20
> sample 0 (oldest timestamp): interrupt timestamp
> sample 1: interrupt timestamp + 0.1 seconds
> sample 2: interrupt timestamp + 0.2 seconds
> sample 3 (newest timestamp): interrupt timestamp + 0.3 seconds
>=20
> Can you check with your setup that this is really what is happening?
>=20

Yes, good point. I did a lot of testing and determined that the sequence=20
of events is something like this:

IRQ --> timestamp
new datum
new datum
new datum
IRQ --> timestamp

Specifically:
- At 50 Hz, interrupts are being generated at about 30 Hz.
- The timestamps in the FIFO correspond to the *newest* data, not the=20
oldest.

I tried interpolating using both assumptions: timestamps corresponding=20
to oldest and then to newest data. Using timestamps corresponding to=20
oldest data, we get timestamps that are not monotonically increasing and=20
thus time moving backwards as the data flows. Using timestamps=20
corresponding to oldest data, we get monotonically increasing time as it=20
should be, and the data looks pretty consistent.

What I settled on is to use the newer timestamps we see to backdate the=20
older data, the ones we remove first from the FIFO. It appears to be=20
working nicely.

I sent a v2 of the patch that does this interpolation.
    =

Re: How to handle missing timestamps? (was Re: [PATCH] iio: imu: inv_mpu6050: improve missing timestamp handling)

[Martin Kelly]

On 03/28/2018 08:13 AM, Jean-Baptiste Maneyrol wrote:
> Hello,
> 
> loosing data at 50Hz is really strange. I am currently running an old MPU-6500 at 200Hz on I2C @400KHz without any issue (using HiKey board).
> 

It is really strange, I agree. I am even losing data at 10 Hz, at about 
the same rate (6 interrupts for every 10 samples). The interrupt handler 
(both top and bottom half) are taking about 8 ms, so I don't think they 
are causing the issue (since the budget is 100 ms at 10 Hz). AFAICT, the 
interrupts either are not being generated at 10 Hz or are not being 
delivered at 10 Hz due to other latency in the system. I have not 
investigated enough yet to know exactly what's happening.

> Can you tell me what is the chip you are using, the board (CPU+freq) and the I2C bus speed?
> 

I'm using a nanopi neo air: 
http://www.friendlyarm.com/index.php?route=product/product&product_id=151. 
This is an ARM Cortex A7. This is an Allwinner H3 SoC running up to 1.2 
GHz, and the system load is near 0, so the system should be more than 
capable of handling 10 Hz data. The I2C bus is set at 400 KHz, and I 
have pasted the relevant device-tree fragment below.

Note that I'm also seeing the I2C bus lockup regularly at higher 
frequencies (500 Hz will reliably trigger it within a few seconds). I 
suspect these issues are related. Watching the output of 
iio_generic_buffer and similar tools shows the samples come in at a 
regular rate (say, 10 Hz) and then have periodic brief stalls before 
going back to the regular rate. This supports the theory of bus lockups 
causing the issue.

Device-tree fragment:

#include "sun8i-h3-nanopi-neo-air.dts"

[...]

&i2c0 {
         pinctrl-names = "default";
         pinctrl-0 = <&i2c0_pins>;
         status = "okay";
         bus_freq = <400000>;

         mpu9250@68 {
                 model = "Invensense MPU9250";
                 compatible = "invensense,mpu9250";
                 reg = <0x68>;
                 interrupt-parent = <&pio>;
                 interrupts = <6 11 IRQ_TYPE_EDGE_RISING>; /* PG11 / 
EINT11 */
         };
};

> Anyway, your solution seems to be good, better then putting 0 for timestamps.
> 
> Best regards,
> JB
>