Results: Distance Sensor [Errno 5] Input/output With Software I2C Investigation

cyclicalobsessive · June 25, 2019, 11:34pm

More ghosts lately with the distance sensor errors stranding Carl - (He’s yelling at me!)

First I came home Sunday to:
2019-06-23 15:07|[logMaintenance.py.main]** Carl unable to dismount read_range_continuous_millimeters timeout **

(This one didn’t seem to be specifically distance sensor related:
2019-06-25 09:19|[logMaintenance.py.main]** Found Carl shutdown about 18in from dock **)

Then 9 hours after recharging and cold start:
2019-06-25 18:14|[logMaintenance.py.main]** distance sensor won’t init [Errno 5] Input/output error **

Attempted soft reboot, but:
2019-06-25 18:16|[logMaintenance.py.main]** distance sensor still won’t init **

Total shutdown and cold start seems to have fixed the issue for the time being.

I recently updated (/home/pi/Dexter) as of June 22 12:00 just before these ghosts appeared.

There is only one GoPiGo3 class running in Python3 (instantiated with use_mutex=True) at the time of each error. The program is juicer.py.

Any ideas what could have happened, or how to debug this?

10:23PM Carl just started shouting at me - “Cannot undock” (because the distance sensor crashed again.)

Stupid me, I didn’t do a backup before the update. Could this have something to do with a new way GoPiGo3 is handling I2C communications? Wouldn’t that be consistent with the mystery 180, mystery forward travel, and the distance sensor issue?

I’m shutting Carl down for the night for his own safety. I hope you all have some ideas for me to try tomorrow.

This is the point at which the errors first appeared this time:

********* CARL Basic STATUS *****
2019-06-25 21:08:33 up 2:48, 2 users, load average: 0.09, 0.06, 0.03
Battery Voltage: 11.81
5v Supply: 5.07
Estimated Life Remaining: 7 h 50 m
Processor Temp: 50.5’C
Clock Frequency: 600.0 MHz
throttled=0x0
Distance Sensor: nothing within 90 inches

Juicer Values:
Juicer Run Time 0 days 2h 46m
lastReading 11.864 volts
shortPeakVolts 11.967 volts
shortMeanVolts 11.865 volts
shortMinVolts 9.885 volts
longPeakVolts 13.543 volts
longMeanVolts 11.897 volts
longMinVolts 9.843 volts
Charging Status: Charging
Last Changed: 0 days 1h 13m 46s
Last Change Rule: 120
Docking Status: Docked
Docking Count: 217
Last Docking Change: 1h 14m 27s
chargeConditioning: 0
possibleEarlyTrickleVolts: 0.00

********* CARL Basic STATUS *****
2019-06-25 21:08:44 up 2:48, 2 users, load average: 0.28, 0.11, 0.04
Battery Voltage: 11.70
5v Supply: 5.06
Estimated Life Remaining: 7 h 50 m
Processor Temp: 50.5’C
Clock Frequency: 1.20 GHz
throttled=0x0
[Errno 5] Input/output error
[Errno 5] Input/output error
[Errno 5] Input/output error
Distance Sensor: -0.5 inches

and it continued until his battery was full (began trickle charging) and needed to get off the dock:
(Carl checks that nothing is in front of him that would block getting off the dock)

*** chargingState changed from: Charging to: Trickle Charging ****
*** by Rule: 230

**** Time to get off the pot
[Errno 5] Input/output error
[Errno 5] Input/output error
[Errno 5] Input/output error
** UNABLE TO UNDOCK **

**** Time to get off the pot
[Errno 5] Input/output error
[Errno 5] Input/output error
[Errno 5] Input/output error
**** UNABLE TO UNDOCK ****

********* CARL Basic STATUS *****
2019-06-25 22:23:10 up 4:03, 2 users, load average: 0.12, 0.09, 0.02
Battery Voltage: 10.37
5v Supply: 5.06
Estimated Life Remaining: 7 h 20 m
Processor Temp: 41.9’C
Clock Frequency: 600.0 MHz
throttled=0x0
[Errno 5] Input/output error
[Errno 5] Input/output error
[Errno 5] Input/output error
Distance Sensor: -0.5 inches

RobertLucian · June 26, 2019, 12:19pm

Maybe. Since it’s something we introduced not long ago, it could be.

I’d do the following thing: add a try/except construct around the distance sensor so that when it actually fails, you can re-instantiate it again. I’m curious to see if it fails re-instantiating or not.

Also, after you come to a conclusion on that, can you also try the hardware I2C on the distance sensor? I’m interested in seeing if there’s any difference. It should be and it should be big - like with the hardware I2C it should fail more often.

Thank you!

cyclicalobsessive · June 26, 2019, 3:14pm

(I’m guessing it will fail since it would not init with a soft reboot after errno 5.)

Do I understand correctly?

Instantiating:

def initDS(egpg):    #will try twice to init a distance sensor
    try:
        ds = egpg.init_distance_sensor()  
    except:
        ds = None
        try:
            ds = egpg.init_distance_sensor()
        except:
            strToLog = "Failed to instantiate distance sensor (twice)"
            print(strToLog)
            if carl: runLog.logger.info(strToLog)
    return ds

ds = initDS(egpg)

and then in using the sensor:

def protected_read_mm(egpg, ds):
    distReading = -9999
    if ds != None:
        try:  distReading = ds.read_mm()
        except:
            strToLog = "Failed to read distance sensor, trying to reinitialize"
            try:  
                ds = initDS(egpg)      # **Does this reset ds globally?**
                if ds != None:
                    try:
                        distReading = ds.read_mm()  # try reading again
                    except:
                        strToLog = "Gave up reading distance sensor"
                        print(strToLog)
    return distReading

dist_mm = protected_read_mm(egpg,ds)

Is that going to work - reassigning the ds reference inside the protected_read_mm() method?

cyclicalobsessive · June 26, 2019, 3:23pm

I’m confused - before I updated, was:

  ds = egpg.init_distance_sensor()

using hardware I2C or a different software I2C?

I am going to try HW I2C again before changing my software.

my_distance_sensor = EasyDistanceSensor(use_mutex=True, port='RPI_1')

( my HWDistanceSensor.py and SWDistanceSensor.py )

The “Errno 5” rate for SW I2C is around 0.2% (HWvsSW_notes.txt)

until it fails completely.

HOLD THEM HORSES we got a loser here with a hot tip!
I ran a test with software I2C for three hours while the GoPiGo3 was on the charger and saw 72.7% of calls failed.

and now (no longer on the recharging dock, egpg.volt() returning 8.8v) trying to restart testing:

Distance Sensor init: [Errno 121] I2C transfer: Remote I/O error
Traceback (most recent call last):
  File "/usr/local/lib/python3.5/dist-packages/python_periphery-1.1.0-py3.5.egg/periphery/i2c.py", line 131, in transfer
OSError: [Errno 121] Remote I/O error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "HWDistanceSensor.py", line 20, in <module>
    my_sensor = EasyDistanceSensor(use_mutex=True, port='RPI_1')
  File "/usr/local/lib/python3.5/dist-packages/DI_Sensors-1.0.0-py3.5.egg/di_sensors/easy_distance_sensor.py", line 56, in __init__
  File "/usr/local/lib/python3.5/dist-packages/DI_Sensors-1.0.0-py3.5.egg/di_sensors/distance_sensor.py", line 28, in __init__
  File "/usr/local/lib/python3.5/dist-packages/DI_Sensors-1.0.0-py3.5.egg/di_sensors/VL53L0X.py", line 126, in __init__
  File "/usr/local/lib/python3.5/dist-packages/Dexter_AutoDetection_and_I2C_Mutex-0.0.0-py3.5.egg/di_i2c.py", line 220, in write_reg_8
  File "/usr/local/lib/python3.5/dist-packages/Dexter_AutoDetection_and_I2C_Mutex-0.0.0-py3.5.egg/di_i2c.py", line 177, in transfer
  File "/usr/local/lib/python3.5/dist-packages/python_periphery-1.1.0-py3.5.egg/periphery/i2c.py", line 133, in transfer
periphery.i2c.I2CError: [Errno 121] I2C transfer: Remote I/O error


and for SW I2C:

pi@Carl:~/Carl/systests/DistanceSensor $ python3 SWDistanceSensor.py 
Distance Sensor init: [Errno 5] Input/output error
Traceback (most recent call last):
  File "SWDistanceSensor.py", line 20, in <module>
    my_sensor = EasyDistanceSensor()
  File "/usr/local/lib/python3.5/dist-packages/DI_Sensors-1.0.0-py3.5.egg/di_sensors/easy_distance_sensor.py", line 56, in __init__
  File "/usr/local/lib/python3.5/dist-packages/DI_Sensors-1.0.0-py3.5.egg/di_sensors/distance_sensor.py", line 28, in __init__
  File "/usr/local/lib/python3.5/dist-packages/DI_Sensors-1.0.0-py3.5.egg/di_sensors/VL53L0X.py", line 126, in __init__
  File "/usr/local/lib/python3.5/dist-packages/Dexter_AutoDetection_and_I2C_Mutex-0.0.0-py3.5.egg/di_i2c.py", line 220, in write_reg_8
  File "/usr/local/lib/python3.5/dist-packages/Dexter_AutoDetection_and_I2C_Mutex-0.0.0-py3.5.egg/di_i2c.py", line 185, in transfer
  File "/usr/local/lib/python3.5/dist-packages/Dexter_AutoDetection_and_I2C_Mutex-0.0.0-py3.5.egg/di_i2c.py", line 469, in transfer
OSError: [Errno 5] Input/output error

cyclicalobsessive · June 26, 2019, 3:38pm

Also - it shouldn’t be any different that the program was running under nohup, correct?

nohup ~/Carl/Projects/Juicer/juicer.py > ~/Carl/juicer.out &

cyclicalobsessive · June 27, 2019, 3:21am

Tried to reset the I2C without cold start:

pi@Carl:~/Carl/systests/DistanceSensor $ lsmod
Module                  Size  Used by
i2c_dev                16384  0
i2c_bcm2708            16384  0
...
spi_bcm2835            16384  0
i2c_bcm2835            16384  0
...
pi@Carl:~/Carl/systests/DistanceSensor $ sudo rmmod i2c_dev
pi@Carl:~/Carl/systests/DistanceSensor $ sudo rmmod i2c_bcm2708
pi@Carl:~/Carl/systests/DistanceSensor $ sudo modprobe i2c_bcm2708
pi@Carl:~/Carl/systests/DistanceSensor $ sudo modprobe i2c_dev

pi@Carl:~/Carl/systests/DistanceSensor $ sudo rmmod i2c_dev
pi@Carl:~/Carl/systests/DistanceSensor $ sudo rmmod i2c_bcm2835
pi@Carl:~/Carl/systests/DistanceSensor $ sudo modprobe i2c_bcm2835
pi@Carl:~/Carl/systests/DistanceSensor $ sudo modprobe i2c_dev
pi@Carl:~/Carl/systests/DistanceSensor $ i2cdetect -y 1
     0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
00:          -- -- -- -- -- 08 -- -- -- -- -- -- -- 
10: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
20: -- -- -- -- -- -- -- -- -- -- 2a -- -- -- -- -- 
30: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
40: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
50: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
60: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
70: -- -- -- -- -- -- -- --

but no cigars for this robot.

Is there a “Reset the GoPiGo3 I2C” method?

cyclicalobsessive · June 27, 2019, 3:36pm

FINAL RESULTS - HW vs SW I2C

Analysis of the software I2C port lockup that disabled Carl on June 25th:

First I2C Errno 5 occurred off the charging dock (not charging), after 15 minutes operation, and was a single occurrence at 8.5v 8.6v peak in prior 5 minutes.
Second and third I2C Errno 5 events occurred while charging, after 2h and 2h22m operation, and were single occurrences at 11.5v 12v peak and 9.6v 15v peak respectively
Continuous I2C Errno 5 began while charging, after 2h46m operation, at 11.8v with 13.5v peak in the prior 5 minutes.

Given that Carl ran almost 24 hours a day for two months using hardware I2C for the distance sensor, and saw his first fatal I2C occurrence, on the charger and after updating which uses software I2C for the same code, battery, and charger, I began questioning if the software I2C could be sensitive to the charging voltage spikes seen in my very “off label” use of the GoPiGo3.

Repeated runs of SWDistanceSensor.py that uses software I2C exhibit a 0.2% Errno 5 Input/output error rate, and eventual complete non-recoverable GoPiGo3 I2C lockup that can only be corrected by total shutdown and cold start.

I ran the hardware I2C test for over seven hours, 102K calls, including two charging sessions, and did not see a single Errno 5. Additionally, I ran juicer successfully four hours, through a dock-charge-dismount-discharge-dock cycle which uses the distance sensor every 12 seconds. This is conclusive (enough).
. EDT.
08:06 Start HW I2C Distance Sensor Test
09:48 Manual Dock Recharge Start
11:02 Manual UnDock Discharging Start
14:24 6h18m No Errno 5 events in 102856 calls by HWDistanceSensor.py
(juicer.py also running using DistanceSensor via HW I2C every 12 seconds)

My use-case is outside the design parameters of the GoPiGo3, so my analysis should not be taken as a complaint or fault.

I thank DI for including the RPI_1 hardware I2C option when making changes intended to improve the product and reduce support incidents.

I believe for Carl’s circumstances returning to using hardware I2C has him back to managing his own battery charge level.

RobertLucian · June 28, 2019, 2:06pm

The first thing I have in mind is that there may be a bug with the software I2C.

Can you tell me if there are other I2C devices running in parallel with the distance sensor that don’t use the DI I2C module, and by that extension use the HW I2C?

The software I2C was implemented in such a way that every time a transmission starts and ends, the HW I2C gets disabled and respectively re-enabled. My gut tells me that if there’s a bug, it should come from that.

Please let me know about your configuration.

And thank you a lot for spending time on this!

Edit: in the meantime, you could also use the AD ports of the GoPiGo3. Any I2C device that has been implemented using our I2C module can also have the I2C device connected to the AD ports. That’s gonna work the same way as if it were connected to the I2C port.

cyclicalobsessive · June 28, 2019, 2:27pm

There is only one I2C sensor. The i2cdetect shows two devices. I would guess that one is the sensor and one is the GoPiGo3 board.

pi@Carl:~/Carl/systests/DistanceSensor $ i2cdetect -y 1
     0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
00:          -- -- -- -- -- 08 -- -- -- -- -- -- -- 
10: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
20: -- -- -- -- -- -- -- -- -- -- 2a -- -- -- -- -- 
30: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
40: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
50: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
60: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- 
70: -- -- -- -- -- -- -- --

Carl’s Config:

Distance Sensor connected to I2C connector 1 (right side when facing connectors)
Pan Servo connected to SERVO1
Tilt Servo connected to SERVO2
No Connections to AD1, AD2, I2C_2
(Only RPi3 and GoPiGo3 board stack)

RobertLucian · July 1, 2019, 6:10pm

So as I have found out, the GoPiGo3 is also reachable at 0x08 address, although we don’t offer any support for the I2C. In the initial designs, we had backward-compatibility in mind and then at some point after we had already made it that way, we decided to drop it and just leave it in until we had a chance to take it out. In one version of the firmware that’s coming up, the I2C is dropped completely.

After you’ve switched to the HW I2C, has it stopped working at any time?

cyclicalobsessive · July 1, 2019, 6:29pm

88 hours on HW I2C with zero Errno 5 Input/output, nor Err 121 Remote I/O errors in roughly 33K Distance Sensor read_mm(), each of which performed three I2C reads for approximately 100K transfers total.