Skip to content

[BUG] I2C Hang if TCA Polls Before Faces are Powered #264

New issue
New issue
Open
Bug
Open
[BUG] I2C Hang if TCA Polls Before Faces are Powered#264
Bug
Labels
bugSomething isn't workingcube killerBugs that might cause loss of mission for a CubeSat
@Mikefly123

Description

@Mikefly123
Mikefly123
opened on Jun 21, 2025

Summary

This is a really confounding one and will require us to do a bunch of refactor to try and protect against this Cube Killer behavior. We might also need to change significantly the hardware architecture to defend against this as well.

Essentially, it seems that if the solar face sensors that the TCA are trying read are turned off then the TCA for some reason causes all upstream I2C devices to not be able to communicate on the I2C bus. This is a big problem because it causes a software hang!

Steps to reproduce

  • Turn off the solar faces after initializing the TCA.
  • Try to poll a sensor on a solar face
  • Try to poll a different i2c1 sensor

Environment

Example of my attempts to understand this bug.

Press any key to enter the REPL. Use CTRL-D to reload.
repl.py output:
{"time": "2000-01-01 00:26:35", "level": "INFO", "msg": "Booting", "hardware_version": "9.2.4-11-gf12e5e9ed4 on 2025-04-21", "software_version": ""}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing watchdog", "pin": "board.WDT_WDI"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.WDT_WDI", "initial_value": false}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Petting watchdog"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing Config"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.MUX_RESET", "initial_value": true}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing spi bus"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing spi bus"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing i2c"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing i2c"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Booting up!", "boot_time": "946686395s"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.FIRE_DEPLOY1_A", "initial_value": false}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.FIRE_DEPLOY1_B", "initial_value": false}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.SPI0_CS0", "initial_value": true}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.RF1_RST", "initial_value": true}
{"time": "2000-01-01 00:26:35", "level": "ERROR", "msg": "Error Initializing Radio", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 138, in <module>\r\nTypeError: function takes 8 positional arguments but 7 were given\n"]}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing magnetometer"}
{"time": "2000-01-01 00:26:35", "level": "DEBUG", "msg": "Initializing IMU"}
{"time": "2000-01-01 00:26:35", "level": "INFO", "msg": "The satellite has a super secret code!", "super_secret_code": "b'ABCD'"}
{"time": "2000-01-01 00:26:35", "level": "INFO", "msg": "Initializing Functionalities"}
{"time": "2000-01-01 00:26:36", "level": "ERROR", "msg": "Error Initializing SD Card", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 164, in <module>\r\nRuntimeError: Mount point directory missing\n"]}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.SPI1_CS0", "initial_value": true}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.RF2_RST", "initial_value": true}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.RF2_IO0", "initial_value": true}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.RF2_TX_EN", "initial_value": true}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.RF2_RX_EN", "initial_value": true}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing radio", "radio_type": "SX1280Manager", "modulation": "<class 'LoRa'>"}
{"time": "2000-01-01 00:26:36", "level": "WARNING", "msg": "Radio send attempt failed: Not licensed."}
Radio2 sent Hello World
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing INA219 power monitor"}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing INA219 power monitor"}
{"time": "2000-01-01 00:26:36", "level": "DEBUG", "msg": "Initializing pin", "pin": "board.GPIO_EXPANDER_RESET", "initial_value": true}
{"time": "2000-01-01 00:26:36", "level": "ERROR", "msg": "Error Initializing Light Sensor", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 327, in sensor_init\r\n  File \"lib/adafruit_veml7700.py\", line 181, in __init__\r\nValueError: No I2C device at address: 0x10\n"]}
{"time": "2000-01-01 00:26:36", "level": "ERROR", "msg": "Error Initializing Motor Driver", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 334, in sensor_init\r\n  File \"lib/adafruit_drv2605.py\", line 93, in __init__\r\nValueError: No I2C device at address: 0x5a\n"]}
{"time": "2000-01-01 00:26:36", "level": "ERROR", "msg": "Error Initializing Light Sensor", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 327, in sensor_init\r\n  File \"lib/adafruit_veml7700.py\", line 181, in __init__\r\nValueError: No I2C device at address: 0x10\n"]}
{"time": "2000-01-01 00:26:36", "level": "ERROR", "msg": "Error Initializing Motor Driver", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 334, in sensor_init\r\n  File \"lib/adafruit_drv2605.py\", line 93, in __init__\r\nValueError: No I2C device at address: 0x5a\n"]}
{"time": "2000-01-01 00:26:36", "level": "ERROR", "msg": "Error Initializing Light Sensor", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 327, in sensor_init\r\n  File \"lib/adafruit_veml7700.py\", line 181, in __init__\r\nValueError: No I2C device at address: 0x10\n"]}
{"time": "2000-01-01 00:26:36", "level": "ERROR", "msg": "Error Initializing Light Sensor", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 327, in sensor_init\r\n  File \"lib/adafruit_veml7700.py\", line 181, in __init__\r\nValueError: No I2C device at address: 0x10\n"]}
{"time": "2000-01-01 00:26:37", "level": "ERROR", "msg": "Error Initializing Motor Driver", "err": ["Traceback (most recent call last):\r\n  File \"repl.py\", line 334, in sensor_init\r\n  File \"lib/adafruit_drv2605.py\", line 93, in __init__\r\nValueError: No I2C device at address: 0x5a\n"]}
Traceback (most recent call last):
  File "repl.py", line 379, in <module>
  File "lib/adafruit_mcp9808.py", line 149, in __init__
ValueError: Unable to find MCP9808 at i2c address 0x1e

Adafruit CircuitPython 9.2.4-11-gf12e5e9ed4 on 2025-04-21; PROVESKit FC Board RP2350 V5a with rp2350a
>>> all_faces_off()
>>> all_faces
all_faces_off   all_faces_on    all_faces
>>> all_faces.face_test_all()
[[27.5625, None], [None, None], [None, None], [None, None], [None, None]]
>>> all_faces.face_test_all()
[[None, None], [None, None], [None, None], [None, None], [None, None]]
>>> all_faces.face_test_all()
[[None, None], [None, None], [None, None], [None, None], [None, None]]
>>> mux_reset.value
True
>>> mux_reset.value=False
>>> mux_reset.value=True
>>> all_faces.face_test_all()
[[None, None], [None, None], [None, None], [None, None], [None, None]]
>>> tca
<TCA9548A object at 0x20042c40>
>>> all_faces_on()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "repl.py", line 271, in all_faces_on
  File "lib/adafruit_mcp230xx/digital_inout.py", line 92, in value
  File "lib/adafruit_mcp230xx/mcp23017.py", line 81, in gpio
  File "lib/adafruit_mcp230xx/mcp230xx.py", line 36, in _read_u16le
KeyboardInterrupt: 
>>> mux_reset.value=False
>>> all_faces_on()
>>> mux_reset.value=True
>>> all_faces_on()
>>> all_faces.face_test_all()
[[27.6875, None], [22.4375, 0.0], [27.6875, None], [27.6875, None], [27.6875, None]]
>>> all_faces.face_test_all()
[[27.75, None], [22.4375, 0.0], [27.75, None], [27.75, None], [27.75, None]]
>>> all_faces.face_test_all()
[[27.75, None], [22.4375, 0.0], [27.75, None], [27.75, None], [27.75, None]]
>>> all_faces_off()
>>> all_faces_on()
>>> all_faces_off()
>>> all_faces_on()
>>> all_faces_off()
>>> imu.get_acceleration()
(-1.11266, 0.061017, 9.78545)
>>> all_faces.face_test_all()
[[27.75, None], [None, None], [None, None], [None, None], [None, None]]
>>> imu.get_acceleration()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "lib/pysquared/hardware/imu/manager/lsm6dsox.py", line 62, in get_acceleration
KeyboardInterrupt: 
>>> all_faces_on()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "repl.py", line 271, in all_faces_on
  File "lib/adafruit_mcp230xx/digital_inout.py", line 92, in value
  File "lib/adafruit_mcp230xx/mcp23017.py", line 81, in gpio
  File "lib/adafruit_mcp230xx/mcp230xx.py", line 36, in _read_u16le
OSError: [Errno 116] ETIMEDOUT
>>> mux_reset.value=False
>>> all_faces_on()
>>> all_faces_off()
>>> mux_reset.value=True
>>> all_faces.face_test_all()
[[27.8125, None], [None, None], [None, None], [None, None], [None, None]]
>>> all_faces.face_test_all()
[[None, None], [None, None], [None, None], [None, None], [None, None]]
>>> imu.get_acceleration()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "lib/pysquared/hardware/imu/manager/lsm6dsox.py", line 62, in get_acceleration
KeyboardInterrupt: 
>>> all_faces_on()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "repl.py", line 271, in all_faces_on
  File "lib/adafruit_mcp230xx/digital_inout.py", line 92, in value
  File "lib/adafruit_mcp230xx/mcp23017.py", line 81, in gpio
  File "lib/adafruit_mcp230xx/mcp230xx.py", line 36, in _read_u16le
OSError: [Errno 116] ETIMEDOUT
>>> mux_reset.value=False
>>> all_faces_on()
>>> all_faces.face_test_all()
[[None, None], [None, None], [None, None], [None, None], [None, None]]
>>> 
>>> mux_reset.value=True
>>> all_faces.face_test_all()
[[None, None], [None, None], [None, None], [None, None], [None, None]]
>>> all_faces.face_test_all()
[[None, None], [None, None], [None, None], [None, None], [None, None]]
>>> imu.get_acceleration()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "lib/pysquared/hardware/imu/manager/lsm6dsox.py", line 62, in get_acceleration
  File "lib/adafruit_lsm6ds/__init__.py", line 279, in acceleration
  File "lib/adafruit_register/i2c_struct.py", line 49, in __get__
KeyboardInterrupt:

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingcube killerBugs that might cause loss of mission for a CubeSat

    Type

    Bug

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions