EV3 Color Sensor Mode Switch Latency

[devinbreise]

Not sure if this is a "bug" or just a fact of life...

When switching modes on a color sensor, it appears to take about 20ms for readings to become accurate.

This code was run on an EV3 (self.lightL is a ColorSensor object):

        left = self.lightL.color() #force color sensor into COLOR mode
        wait(500) #wait a little bit
        timer = StopWatch()
        timer.reset()
        while timer.time() < 1000:
            print(str(timer.time()) +":"+str(self.lightL.reflection()))

Here is the output:
0:79
14:79
18:79
22:14
26:14
37:14
40:14
47:14
etc.

Not sure if there is "correct" behavior here...maybe just some notes in the doc.

[dlech]

In fact, we were just looking at this recently. It does appear to be a fact of life (hardware issue). See ev3dev/ev3dev#1401.

[devinbreise]

If ev3dev can't address, perhaps you could consider some logic at the Pybricks level to notice the mode change, pull the stale data off the bus, and then return the current/accurate reading (with a bit more latency than a typical call to your ColorSensor reading API).

I stumbled on this while prototyping some typical FLL functionality for finding and "squaring" on lines on FLL mats. The current behavior can easily lead to what will appear to most to be an intermittent failure. It will be a challenging one to diagnose for most teams...

[dlech]

How would we know which values are stale and which values are good?

[devinbreise]

Presumably, this is a timing issue. Its interesting that the returned data is indeed "stale" (as opposed to random). I noticed that too in my testing. This suggests that somebody is caching somewhere. Not sure if this is at the device level, the device driver, ev3dev, or Pybricks. If the presumption is correct, there is likely some safe number of milliseconds that will ensure the cache is fresh. So logic would be:

ReadSensor()
-If Mode-Switch (relative to last read on this sensor)
--repeat
---read-sensor
--until elapsed time > threshold
--return read-sensor

This is essentially the code that would need to be implemented on top of Pybricks to be able to forget about this behavior.

Of course, noting the mode switch might be problematic. I've been wondering about the Pybricks object model and whether or not classes like ColorSensor maintain state beyond what ev3dev maintains...if they do, easy enough I suppose. If not (so that when someone instantiates two objects of ColorSensor pointing at the same underlying device, bad things do not happen), then not sure...

[laurensvalk]

here is likely some safe number of milliseconds that will ensure the cache is fresh

Unfortunately the timing varies a lot between modes.

This is essentially the code that would need to be implemented on top of Pybricks to be able to forget about this behavior.

For some use cases, maybe. But it would introduce unwanted delays in other code.

For example, in a balancing robot, getting an ambient light reading that's 20 milliseconds old is not so bad, compared to falling flat on its face 😄 .

I've been wondering about the Pybricks object model

For most sensors, the classes are similar to the iodevices.Ev3devSensor class. They read the values from the ev3dev file system.

maybe just some notes in the doc.

We'll do that, thanks!

Not sure if this is a "bug" or just a fact of life...

So all in all I'm afraid that's just how it works.

But you can mix color and reflection in another way. You could try using rgb() mode, which might give you all you need without mode switching.

[devinbreise]

Thanks, I take all your points. However, I think I have seen behavior where the returned value is much more stale than 20 msecs, more like "the last reading no matter how long ago it was". I'll see if I can reliably reproduce...

[laurensvalk]

Yes, it seems like a buffer of the last ~20-50 ms, from when that mode was last used, even if that's seconds or minutes ago.

[devinbreise]

Hmmm...So I think this may be a significant difference between how the MindStorms implementation and this one works. I was also able to reproduce it in a fairly standard FLL algorithm.

So here is a use case that concerns me. MindStorms example code is full of situations where a block is used to turn the motors on, the next block is a "wait" block that is triggered by a sensor reading, and the final block turns the motors off. FLL teams do this sort of thing all the time. The Pybricks version of this code might look like this:

        self.drive.drive(50,0)
        while sensor.reflection() > 20: #threshold for black
            pass
        self.drive.stop()

This code, in theory, has a challenging bug lurking in it that will manifest in what will appear to be a fairly random manner. Depending on what mode the ColorSensor was in before this code runs, and what reading it last received in that mode, and how fast the interpreter runs, the code will either work, or the robot won't move. To test this, I tried this code/procedure:

        sensor = ColorSensor(Port.S1)
        timer = StopWatch()
        
        #put the color sensor on a black line to start with

        timer.reset()
        for i in range(10): #take some readings
            print(str(timer.time()) +": REFLECT: "+str(sensor.reflection()))
        
        print(str("COLOR: "+str(sensor.color()))) #force color sensor into COLOR mode

        #Move (by hand) the robot back from the black line (color sensor over something brighter)
        self.tools.waitForAnyButtonBump()

        self.drive.settings()
        self.drive.drive(50,0)
        timer.reset()
        while sensor.reflection() > 20: #threshold for black
            print(str(timer.time()) +": REFLECT: "+str(sensor.reflection()))
        self.drive.stop()
        self.hold()

Sure enough, the second while loop's exit test gets triggered prematurely about 1 in 3 times when the code gets what is essentially a false positive from the sensor.

Of course, we can teach the kids about "noise" in sensors, running averages, etc. but this is something that, for whatever reason, has never been an issue with the MindStorms environment. So it seems likely to me that most teams will fall into this trap, and simply presume the platform is unstable when it starts happening to them.

[laurensvalk]

Thanks, those are good and valid points.

Instead of trying to solve modes more generally, I think what we could do is treat the ColorSensor class as a special case.

This seems to be the most relevant sensor to fix, and if we make it specific to this sensor and its modes, the fix is both well contained (it will not touch other sensors as side effects) and well defined (we can measure the required delays for each mode, for example).

There might be ways to make the delay less of an impact on tight loops. For example, we might be able to skip the hard delay if we have a time stamped value for that particular mode that is less than X milliseconds old.

Now I’m kind of curious for the loop time with the EV3 software doing both an ambient and a reflection or color measurement. I don’t remember ever trying that with the color sensor, and I’ve used that software a lot. I do remember there were significant delays with the infrared sensor.

The gyro sensor has problems of its own, so that’s probably for another post.

[laurensvalk]

Now I’m kind of curious for the loop time with the EV3 software

So here it goes, results in comment block:

No mode switching

Color Sensor Mode Switching (Color + Reflection)

IR Sensor mode switching

[laurensvalk]

I know someone who wrote a book about this stuff and then somehow forgot how big the problem really was:

[laurensvalk]

So with that in mind, and also because we did already hard code delays for 3 other sensors, I think I changed my mind about this suggestion:

Instead of trying to solve modes more generally, I think what we could do is treat the ColorSensor class as a special case.

I think I'm going to try adding a plain non-blocking delay to the function we use to switch modes after all. Doing extra buffer magic to avoid it probably more complicated and error prone than it's worth.

The delay could come from a look up table for sensor/mode combination, and default to 0 if we did not define a value. Or maybe default to ~30--50ms.

We can determine better values experimentally, and/or:

@dlech , do you want to have a look at the original firmware / VM to see if we can find LEGO's hard coded delays for each sensor or mode? (or something they used that resulted in the delay)

[laurensvalk]

Good news - this is really easy to add with a very minimal amount of code change.

Now we just need to settle on sensible defaults per sensor and/or mode, and an overall default.

[devinbreise]

I thought I recognized the name...that was very funny. And thank you for the books!

Based on your data above, I'd say you just reverse engineered the Mindstorms code... ;)

When you say "non-blocking delay", I got a little lost. Wouldn't the point be to "block" (e.g. not return from the sensor read method until assured that the returned value is not stale)?

[laurensvalk]

In this context, non-blocking means that all system processes like motor control continue. It is only the user script that blocks until data is considered "valid", in this case defined as "recent enough".

We've gone ahead and implemented this change experimentally, and we may release an updated beta in a few days or next week for extra verification.

It is set to 30 ms for the color sensor right now and 1100 ms for the infrared based on these preliminary experiments and insights from the EV3 source code. It would be good to verify if this is enough or too much and what the delays should be for other sensors or modes. For any sensors that aren't explicitly added, the default will be 0 ms.

It will still be possible to get the raw, instant (but possibly wrong) data via the Ev3devSensor class, so more advanced users can adapt it to their needs.

Thanks again for raising the issue!

[laurensvalk]

This has been implemented here and it can be tested as described in #17.

Would love to hear your feedback to see if it solves the issues you raised.

[devinbreise]

Testing with ca65b2f trying the use case that originally turned this up, all is well now and the additional latency on the mode switch reading doesn't have any noticeable performance impact. Thanks!

I went a little further and ran this code a few times, moving the sensors back and forth between white/black areas between each run.

        print(str("COLOR: "+str(sensor.color()))) #force color sensor into COLOR mode

        timer.reset()
        for i in range(10): #take some readings
            reading = sensor.reflection()
            print(str(timer.time()) +": REFLECT: "+str(reading))

        timer.reset()
        for i in range(10): #take some readings
            reading = sensor.color()
            print(str(timer.time()) +": COLOR: "+str(reading))

The mode switch delay is apparent exactly where it should be. Looks like it is working great!

COLOR: Color.WHITE
43: REFLECT: 94
45: REFLECT: 94
55: REFLECT: 94
59: REFLECT: 94
64: REFLECT: 94
73: REFLECT: 94
75: REFLECT: 94
82: REFLECT: 94
86: REFLECT: 94
96: REFLECT: 94
41: COLOR: Color.WHITE
50: COLOR: Color.WHITE
53: COLOR: Color.WHITE
60: COLOR: Color.WHITE
64: COLOR: Color.WHITE
74: COLOR: Color.WHITE
76: COLOR: Color.WHITE
81: COLOR: Color.WHITE
84: COLOR: Color.WHITE
91: COLOR: Color.WHITE

COLOR: Color.BLACK
45: REFLECT: 13
54: REFLECT: 13
62: REFLECT: 13
64: REFLECT: 13
66: REFLECT: 13
77: REFLECT: 13
84: REFLECT: 13
86: REFLECT: 13
94: REFLECT: 13
96: REFLECT: 13
41: COLOR: Color.BLACK
52: COLOR: Color.BLACK
60: COLOR: Color.BLACK
62: COLOR: Color.BLACK
72: COLOR: Color.BLACK
77: COLOR: Color.BLACK
85: COLOR: Color.BLACK
97: COLOR: Color.BLACK
101: COLOR: Color.BLACK
110: COLOR: Color.BLACK

[laurensvalk]

Thanks a lot for confirming!

[laurensvalk]

elbow_sensor = ColorSensor(Port.S3)
w = StopWatch()
for i in range(1000):
    elbow_sensor.color()
    elbow_sensor.reflection()
w.pause()
print(w.time())

This gives 100 seconds, which is about 1.5x what EV3-G does, so we are probably a bit (too far?) on the safe side right now. Previously, without pauses, this was about 10 seconds instead. EDIT: varies a little brick by brick, it is 71 seconds on another, so perhaps best kept as is.

And for comparison, this runs in 0.23 seconds for 1000 readings (0.23 msec per read), which is pretty good. EDIT: or 0.15 on another brick.

for i in range(1000):
    elbow_sensor.reflection()

[laurensvalk]

Case closed, then! 😄 Thanks!