Handle RNode BLE MTU request errors

This commit is contained in:
Mark Qvist 2024-10-01 23:52:04 +02:00
parent 9a8d46ab21
commit 72971d1aef

View File

@ -82,6 +82,7 @@ class KISS():
ERROR_TXFAILED = 0x02 ERROR_TXFAILED = 0x02
ERROR_EEPROM_LOCKED = 0x03 ERROR_EEPROM_LOCKED = 0x03
ERROR_INVALID_FIRMWARE = 0x10 ERROR_INVALID_FIRMWARE = 0x10
ERROR_INVALID_BLE_MTU = 0x20
PLATFORM_AVR = 0x90 PLATFORM_AVR = 0x90
PLATFORM_ESP32 = 0x80 PLATFORM_ESP32 = 0x80
@ -415,6 +416,7 @@ class RNodeInterface(Interface):
self.last_id = 0 self.last_id = 0
self.first_tx = None self.first_tx = None
self.reconnect_w = RNodeInterface.RECONNECT_WAIT self.reconnect_w = RNodeInterface.RECONNECT_WAIT
self.reconnect_lock = threading.Lock()
self.r_frequency = None self.r_frequency = None
self.r_bandwidth = None self.r_bandwidth = None
@ -517,9 +519,7 @@ class RNodeInterface(Interface):
RNS.log("The contained exception was: "+str(e), RNS.LOG_ERROR) RNS.log("The contained exception was: "+str(e), RNS.LOG_ERROR)
if len(self.hw_errors) == 0: if len(self.hw_errors) == 0:
RNS.log("Reticulum will attempt to bring up this interface periodically", RNS.LOG_ERROR) RNS.log("Reticulum will attempt to bring up this interface periodically", RNS.LOG_ERROR)
thread = threading.Thread(target=self.reconnect_port) thread = threading.Thread(target=self.reconnect_port, daemon=True).start()
thread.daemon = True
thread.start()
def read_mux(self, len=None): def read_mux(self, len=None):
@ -543,6 +543,15 @@ class RNodeInterface(Interface):
else: else:
raise IOError("No ports available for writing") raise IOError("No ports available for writing")
# def reset_ble(self):
# RNS.log(f"Clearing previous connection instance: "+str(self.ble))
# del self.ble
# self.ble = None
# self.serial = None
# self.ble = BLEConnection(owner=self, target_name=self.ble_name, target_bt_addr=self.ble_addr)
# self.serial = self.ble
# RNS.log(f"New connection instance: "+str(self.ble))
def open_port(self): def open_port(self):
if not self.use_ble: if not self.use_ble:
if self.port != None: if self.port != None:
@ -623,10 +632,9 @@ class RNodeInterface(Interface):
def configure_device(self): def configure_device(self):
self.resetRadioState()
sleep(2.0) sleep(2.0)
thread = threading.Thread(target=self.readLoop) thread = threading.Thread(target=self.readLoop, daemon=True).start()
thread.daemon = True
thread.start()
self.detect() self.detect()
if not self.use_ble: if not self.use_ble:
@ -859,16 +867,19 @@ class RNodeInterface(Interface):
raise IOError("An IO error occurred while configuring radio state for "+str(self)) raise IOError("An IO error occurred while configuring radio state for "+str(self))
def validate_firmware(self): def validate_firmware(self):
if (self.maj_version >= RNodeInterface.REQUIRED_FW_VER_MAJ): if (self.maj_version > RNodeInterface.REQUIRED_FW_VER_MAJ):
if (self.min_version >= RNodeInterface.REQUIRED_FW_VER_MIN): self.firmware_ok = True
self.firmware_ok = True else:
if (self.maj_version >= RNodeInterface.REQUIRED_FW_VER_MAJ):
if (self.min_version >= RNodeInterface.REQUIRED_FW_VER_MIN):
self.firmware_ok = True
if self.firmware_ok: if self.firmware_ok:
return return
RNS.log("The firmware version of the connected RNode is "+str(self.maj_version)+"."+str(self.min_version), RNS.LOG_ERROR) RNS.log("The firmware version of the connected RNode is "+str(self.maj_version)+"."+str(self.min_version), RNS.LOG_ERROR)
RNS.log("This version of Reticulum requires at least version "+str(RNodeInterface.REQUIRED_FW_VER_MAJ)+"."+str(RNodeInterface.REQUIRED_FW_VER_MIN), RNS.LOG_ERROR) RNS.log("This version of Reticulum requires at least version "+str(RNodeInterface.REQUIRED_FW_VER_MAJ)+"."+str(RNodeInterface.REQUIRED_FW_VER_MIN), RNS.LOG_ERROR)
RNS.log("Please update your RNode firmware with rnodeconf from https://github.com/markqvist/rnodeconfigutil/") RNS.log("Please update your RNode firmware with rnodeconf from https://github.com/markqvist/reticulum/")
error_description = "The firmware version of the connected RNode is "+str(self.maj_version)+"."+str(self.min_version)+". " error_description = "The firmware version of the connected RNode is "+str(self.maj_version)+"."+str(self.min_version)+". "
error_description += "This version of Reticulum requires at least version "+str(RNodeInterface.REQUIRED_FW_VER_MAJ)+"."+str(RNodeInterface.REQUIRED_FW_VER_MIN)+". " error_description += "This version of Reticulum requires at least version "+str(RNodeInterface.REQUIRED_FW_VER_MAJ)+"."+str(RNodeInterface.REQUIRED_FW_VER_MIN)+". "
error_description += "Please update your RNode firmware with rnodeconf from: https://github.com/markqvist/rnodeconfigutil/" error_description += "Please update your RNode firmware with rnodeconf from: https://github.com/markqvist/rnodeconfigutil/"
@ -876,7 +887,7 @@ class RNodeInterface(Interface):
def validateRadioState(self): def validateRadioState(self):
RNS.log("Wating for radio configuration validation for "+str(self)+"...", RNS.LOG_VERBOSE) RNS.log("Waiting for radio configuration validation for "+str(self)+"...", RNS.LOG_VERBOSE)
if not self.platform == KISS.PLATFORM_ESP32: if not self.platform == KISS.PLATFORM_ESP32:
sleep(1.00); sleep(1.00);
else: else:
@ -904,6 +915,13 @@ class RNodeInterface(Interface):
else: else:
return False return False
def resetRadioState(self):
self.r_frequency = None
self.r_bandwidth = None
self.r_txpower = None
self.r_sf = None
self.r_cr = None
self.r_state = None
def updateBitrate(self): def updateBitrate(self):
try: try:
@ -1287,36 +1305,41 @@ class RNodeInterface(Interface):
self.reconnect_port() self.reconnect_port()
def reconnect_port(self): def reconnect_port(self):
while not self.online and len(self.hw_errors) == 0: if self.reconnect_lock.locked():
try: RNS.log("Dropping superflous reconnect port job")
time.sleep(self.reconnect_w) return
if self.serial != None and self.port != None:
RNS.log("Attempting to reconnect serial port "+str(self.port)+" for "+str(self)+"...", RNS.LOG_EXTREME)
if self.bt_manager != None: with self.reconnect_lock:
RNS.log("Attempting to reconnect Bluetooth device for "+str(self)+"...", RNS.LOG_EXTREME) while not self.online and len(self.hw_errors) == 0:
try:
time.sleep(self.reconnect_w)
if self.serial != None and self.port != None:
RNS.log("Attempting to reconnect serial port "+str(self.port)+" for "+str(self)+"...", RNS.LOG_EXTREME)
self.open_port() if self.bt_manager != None:
RNS.log("Attempting to reconnect Bluetooth device for "+str(self)+"...", RNS.LOG_EXTREME)
if hasattr(self, "serial") and self.serial != None and self.serial.is_open: self.open_port()
self.configure_device()
if self.online:
if self.last_imagedata != None:
self.display_image(self.last_imagedata)
self.enable_external_framebuffer()
elif hasattr(self, "bt_manager") and self.bt_manager != None and self.bt_manager.connected: if hasattr(self, "serial") and self.serial != None and self.serial.is_open:
self.configure_device() self.configure_device()
if self.online: if self.online:
if self.last_imagedata != None: if self.last_imagedata != None:
self.display_image(self.last_imagedata) self.display_image(self.last_imagedata)
self.enable_external_framebuffer() self.enable_external_framebuffer()
except Exception as e: elif hasattr(self, "bt_manager") and self.bt_manager != None and self.bt_manager.connected:
RNS.log("Error while reconnecting RNode, the contained exception was: "+str(e), RNS.LOG_ERROR) self.configure_device()
if self.online:
if self.last_imagedata != None:
self.display_image(self.last_imagedata)
self.enable_external_framebuffer()
if self.online: except Exception as e:
RNS.log("Reconnected serial port for "+str(self)) RNS.log("Error while reconnecting RNode, the contained exception was: "+str(e), RNS.LOG_ERROR)
if self.online:
RNS.log("Reconnected serial port for "+str(self))
def detach(self): def detach(self):
self.detached = True self.detached = True
@ -1367,9 +1390,12 @@ class BLEConnection(BluetoothDispatcher):
UART_RX_CHAR_UUID = "6e400002-b5a3-f393-e0a9-e50e24dcca9e" UART_RX_CHAR_UUID = "6e400002-b5a3-f393-e0a9-e50e24dcca9e"
UART_TX_CHAR_UUID = "6e400003-b5a3-f393-e0a9-e50e24dcca9e" UART_TX_CHAR_UUID = "6e400003-b5a3-f393-e0a9-e50e24dcca9e"
MAX_GATT_ATTR_LEN = 512 MAX_GATT_ATTR_LEN = 512
BASE_MTU = 20
TARGET_MTU = 512
SCAN_TIMEOUT = 2.0 MTU_TIMEOUT = 4.0
CONNECT_TIMEOUT = 7.0 CONNECT_TIMEOUT = 7.0
RECONNECT_WAIT = 1.0
@property @property
def is_open(self): def is_open(self):
@ -1394,19 +1420,26 @@ class BLEConnection(BluetoothDispatcher):
try: try:
if self.connected: if self.connected:
RNS.log(f"Disconnecting BLE device from {self.owner}", RNS.LOG_DEBUG) RNS.log(f"Disconnecting BLE device from {self.owner}", RNS.LOG_DEBUG)
RNS.log("Waiting for BLE write buffer to empty...") # RNS.log("Waiting for BLE write buffer to empty...")
while self.owner.ble_waiting(): timeout = time.time() + 10
while self.owner.ble_waiting() and self.write_thread != None and time.time() < timeout:
time.sleep(0.1) time.sleep(0.1)
RNS.log("Writing concluded") # if time.time() > timeout:
# RNS.log("Writing timed out")
# else:
# RNS.log("Writing concluded")
self.rx_char = None self.rx_char = None
self.tx_char = None self.tx_char = None
self.mtu = BLEConnection.BASE_MTU
self.mtu_requested_time = None
RNS.log("Waiting for write thread to finish...") if self.write_thread != None:
while self.write_thread != None: # RNS.log("Waiting for write thread to finish...")
time.sleep(0.1) while self.write_thread != None:
time.sleep(0.1)
RNS.log("Writing finished, closing GATT connection") # RNS.log("Writing finished, closing GATT connection")
self.close_gatt() self.close_gatt()
with self.owner.ble_rx_lock: with self.owner.ble_rx_lock:
@ -1415,6 +1448,9 @@ class BLEConnection(BluetoothDispatcher):
with self.owner.ble_tx_lock: with self.owner.ble_tx_lock:
self.owner.ble_tx_queue = b"" self.owner.ble_tx_queue = b""
self.connected = False
self.ble_device = None
except Exception as e: except Exception as e:
RNS.log("An error occurred while closing BLE connection for {self.owner}: {e}", RNS.LOG_ERROR) RNS.log("An error occurred while closing BLE connection for {self.owner}: {e}", RNS.LOG_ERROR)
RNS.trace_exception(e) RNS.trace_exception(e)
@ -1424,15 +1460,20 @@ class BLEConnection(BluetoothDispatcher):
self.owner = owner self.owner = owner
self.target_name = target_name self.target_name = target_name
self.target_bt_addr = target_bt_addr self.target_bt_addr = target_bt_addr
self.scan_timeout = BLEConnection.SCAN_TIMEOUT
self.connect_timeout = BLEConnection.CONNECT_TIMEOUT self.connect_timeout = BLEConnection.CONNECT_TIMEOUT
self.ble_device = None self.ble_device = None
self.rx_char = None
self.tx_char = None
self.connected = False self.connected = False
self.was_connected = False
self.connected_time = None
self.mtu_requested_time = None
self.running = False self.running = False
self.should_run = False self.should_run = False
self.connect_job_running = False self.connect_job_running = False
self.write_thread = None self.write_thread = None
self.mtu = 20 self.mtu = BLEConnection.BASE_MTU
self.target_mtu = BLEConnection.TARGET_MTU
self.bt_manager = AndroidBluetoothManager(owner=self) self.bt_manager = AndroidBluetoothManager(owner=self)
@ -1462,13 +1503,23 @@ class BLEConnection(BluetoothDispatcher):
if self.ble_device != None: if self.ble_device != None:
if not self.connected: if not self.connected:
if self.was_connected:
RNS.log(f"Throttling BLE reconnect for {BLEConnection.RECONNECT_WAIT} seconds", RNS.LOG_DEBUG)
time.sleep(BLEConnection.RECONNECT_WAIT)
self.connect_device() self.connect_device()
else:
if self.connected:
RNS.log("Bluetooth was disabled, closing active BLE device connection", RNS.LOG_ERROR)
self.close()
time.sleep(2) time.sleep(2)
def connect_device(self): def connect_device(self):
if self.ble_device != None and self.bt_manager.bt_enabled(): if self.ble_device != None and self.bt_manager.bt_enabled():
RNS.log(f"Trying to connect BLE device {self.ble_device.getName()} / {self.ble_device.getAddress()} for {self.owner}...", RNS.LOG_DEBUG) RNS.log(f"Trying to connect BLE device {self.ble_device.getName()} / {self.ble_device.getAddress()} for {self.owner}...", RNS.LOG_DEBUG)
self.mtu = BLEConnection.BASE_MTU
self.connect_by_device_address(self.ble_device.getAddress()) self.connect_by_device_address(self.ble_device.getAddress())
end = time.time() + BLEConnection.CONNECT_TIMEOUT end = time.time() + BLEConnection.CONNECT_TIMEOUT
while time.time() < end and not self.connected: while time.time() < end and not self.connected:
@ -1480,6 +1531,12 @@ class BLEConnection(BluetoothDispatcher):
self.write_thread.start() self.write_thread.start()
else: else:
RNS.log(f"BLE device connection timed out for {self.owner}", RNS.LOG_DEBUG) RNS.log(f"BLE device connection timed out for {self.owner}", RNS.LOG_DEBUG)
if self.mtu_requested_time:
RNS.log("MTU update timeout, tearing down connection")
self.owner.hw_errors.append({"error": KISS.ERROR_INVALID_BLE_MTU, "description": "The Bluetooth Low Energy transfer MTU could not be configured for the connected device, and communication has failed. Restart Reticulum and any connected applications to retry connecting."})
self.close()
self.should_run = False
self.close_gatt() self.close_gatt()
self.connect_job_running = False self.connect_job_running = False
@ -1515,8 +1572,6 @@ class BLEConnection(BluetoothDispatcher):
found_device = device found_device = device
break break
RNS.log("Found device "+str(found_device))
return found_device return found_device
def on_connection_state_change(self, status, state): def on_connection_state_change(self, status, state):
@ -1526,21 +1581,37 @@ class BLEConnection(BluetoothDispatcher):
self.device_disconnected() self.device_disconnected()
def on_services(self, status, services): def on_services(self, status, services):
self.request_mtu(BLEConnection.MAX_GATT_ATTR_LEN) if status == GATT_SUCCESS:
self.rx_char = services.search(BLEConnection.UART_RX_CHAR_UUID) self.rx_char = services.search(BLEConnection.UART_RX_CHAR_UUID)
if self.rx_char is not None: if self.rx_char is not None:
self.tx_char = services.search(BLEConnection.UART_TX_CHAR_UUID) self.tx_char = services.search(BLEConnection.UART_TX_CHAR_UUID)
if self.tx_char is not None: if self.tx_char is not None:
if self.enable_notifications(self.tx_char): if self.enable_notifications(self.tx_char):
RNS.log("Enabled notifications for BLE TX characteristic") RNS.log("Enabled notifications for BLE TX characteristic", RNS.LOG_DEBUG)
self.connected = True
RNS.log(f"Requesting BLE connection MTU update to {self.target_mtu}", RNS.LOG_DEBUG)
self.mtu_requested_time = time.time()
self.request_mtu(self.target_mtu)
else:
RNS.log("Could not enable notifications for BLE TX characteristic", RNS.LOG_ERROR)
else:
RNS.log("BLE device service discovery failure", RNS.LOG_ERROR)
def on_mtu_changed(self, mtu, status): def on_mtu_changed(self, mtu, status):
if status == GATT_SUCCESS: if status == GATT_SUCCESS:
self.mtu = min(mtu-5, BLEConnection.MAX_GATT_ATTR_LEN) self.mtu = min(mtu-5, BLEConnection.MAX_GATT_ATTR_LEN)
RNS.log(f"BLE MTU updated to {self.mtu} for {self.owner}", RNS.LOG_DEBUG) RNS.log(f"BLE MTU updated to {self.mtu} for {self.owner}", RNS.LOG_DEBUG)
self.connected = True
self.was_connected = True
self.connected_time = time.time()
self.mtu_requested_time = None
else:
RNS.log(f"MTU update request did not succeed, mtu={mtu}, status={status}", RNS.LOG_ERROR)
def on_characteristic_changed(self, characteristic): def on_characteristic_changed(self, characteristic):
if characteristic.getUuid().toString() == BLEConnection.UART_TX_CHAR_UUID: if characteristic.getUuid().toString() == BLEConnection.UART_TX_CHAR_UUID: