search

hologram-io / hologram-python

Hologram device-side Python SDK - Send messages to the cloud in just 3 lines of code!
https://hologram.io/
MIT License
89 stars 47 forks source link

Catch serial exceptions on port detection commands #11

Closed agmangas closed 5 years ago

agmangas commented 5 years ago

Connecting a Nova modem on an Ubuntu Server 18.04 results in multiple ACM devices being created:

$ ls -lh /dev/ | grep ACM
crw-rw---- 1 root dialout 166,   0 Oct 11 12:25 ttyACM0
crw-rw---- 1 root dialout 166,   1 Oct 11 12:25 ttyACM1
crw-rw---- 1 root dialout 166,   2 Oct 11 12:25 ttyACM2
crw-rw---- 1 root dialout 166,   3 Oct 11 11:49 ttyACM3
crw-rw---- 1 root dialout 166,   4 Oct 11 11:49 ttyACM4
crw-rw---- 1 root dialout 166,   5 Oct 11 11:49 ttyACM5
crw-rw---- 1 root dialout 166,   6 Oct 11 11:49 ttyACM6

When the Hologram SDK checks every port in search of the modem some of those devices will raise a SerialException complaining about concurrent access:

DEBUG:Hologram.Network.Network:checking for vid_pid: ('12d1', '1506')
DEBUG:Hologram.Network.Network:checking for vid_pid: ('12d1', '1001')
DEBUG:Hologram.Network.Network:checking for vid_pid: ('05c6', '90b2')
DEBUG:Hologram.Network.Network:checking for vid_pid: ('1546', '1102')
INFO:Hologram.Network.Network:Detected modem Nova_U201
DEBUG:Hologram.Network.Modem.IModem:checking port ttyACM0
DEBUG:Hologram.Network.Modem.IModem:[AT]
Traceback (most recent call last):
  File "example-serial-interface.py", line 24, in <module>
    hologram = HologramCloud(None, network='cellular')
  File "/home/agmangas/hologram-python/Hologram/HologramCloud.py", line 72, in __init__
    network=network)
  File "/home/agmangas/hologram-python/Hologram/CustomCloud.py", line 35, in __init__
    network=network)
  File "/home/agmangas/hologram-python/Hologram/Cloud.py", line 36, in __init__
    self.initializeNetwork(network)
  File "/home/agmangas/hologram-python/Hologram/Cloud.py", line 50, in initializeNetwork
    self._networkManager = NetworkManager.NetworkManager(self.event, network)
  File "/home/agmangas/hologram-python/Hologram/Network/NetworkManager.py", line 40, in __init__
    self.network = network
  File "/home/agmangas/hologram-python/Hologram/Network/NetworkManager.py", line 71, in network
    self._network.autodetect_modem()
  File "/home/agmangas/hologram-python/Hologram/Network/Cellular.py", line 56, in autodetect_modem
    self.modem = dev_devices[0]
  File "/home/agmangas/hologram-python/Hologram/Network/Cellular.py", line 229, in modem
    self._modem = self._modemHandlers[modem](event=self.event)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Nova_U201.py", line 26, in __init__
    chatscript_file=chatscript_file, event=event)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Nova.py", line 22, in __init__
    chatscript_file=chatscript_file, event=event)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 79, in __init__
    self._initialize_device_name(device_name)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 110, in _initialize_device_name
    devices = self.detect_usable_serial_port()
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 215, in detect_usable_serial_port
    include_all_ports=False)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 201, in __detect_all_serial_ports
    res = self.command('', timeout=1)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 741, in command
    retries, seteq, read, prompt, data, hide)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 495, in __command_helper
    self.result = self.process_response(cmd, timeout, hide=hide)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 421, in process_response
    response = self._readline_from_serial_port(timeout, hide=hide)
  File "/home/agmangas/hologram-python/Hologram/Network/Modem/Modem.py", line 755, in _readline_from_serial_port
    r = self.serial_port.readline()
  File "/home/agmangas/hologram-python/.env/local/lib/python2.7/site-packages/serial/serialposix.py", line 501, in read
    'device reports readiness to read but returned no data '
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

This uncaught exception breaks the search loop when it could keep going to try to find another port. The PR catches those exceptions, logs them and lets the search loop continue.

In this example (where the PR has already been applied) ttyACM1 raises a SerialException but ttyACM2 ends up being the working port, and the command succeeds:

DEBUG:Hologram.Network.Network:checking for vid_pid: ('12d1', '1506')
DEBUG:Hologram.Network.Network:checking for vid_pid: ('12d1', '1001')
DEBUG:Hologram.Network.Network:checking for vid_pid: ('05c6', '90b2')
DEBUG:Hologram.Network.Network:checking for vid_pid: ('1546', '1102')
INFO:Hologram.Network.Network:Detected modem Nova_U201
DEBUG:Hologram.Network.Modem.IModem:checking port ttyACM0
DEBUG:Hologram.Network.Modem.IModem:[AT]
DEBUG:Hologram.Network.Modem.IModem:{}
DEBUG:Hologram.Network.Modem.IModem:checking port ttyACM1
DEBUG:Hologram.Network.Modem.IModem:[AT]
DEBUG:Hologram.Network.Modem.IModem:exception sending test command to ttyACM1: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
DEBUG:Hologram.Network.Modem.IModem:checking port ttyACM2
DEBUG:Hologram.Network.Modem.IModem:[AT]
DEBUG:Hologram.Network.Modem.IModem:{}
DEBUG:Hologram.Network.Modem.IModem:{OK}
INFO:Hologram.Network.Modem.IModem:found working port at ttyACM2
INFO:Hologram.Network.Modem.IModem:chatscript file: /home/agmangas/hologram-python/Hologram/Network/Modem/chatscripts/default-script
DEBUG:Hologram.Network.Modem.IModem:[ATE0]
DEBUG:Hologram.Network.Modem.IModem:{}
DEBUG:Hologram.Network.Modem.IModem:{OK}
agmangas commented 5 years ago

After investigating a bit more into this, it seems the problem was related to collisions between ModemManager and the Hologram SDK.

The Hologram SDK could not access the modem with ModemManager operating in the background. Ignoring the Nova modem from ModemManager fixed this issue:

$ cat /etc/NetworkManager/NetworkManager.conf 
[main]
plugins=ifupdown,keyfile

...

[keyfile]
unmanaged-devices=interface-name:ttyACM*

We also added a new udev rule to ignore the device for good measure, although it doesn't seem to be strictly necessary:

$ cat /etc/udev/rules.d/99-ttyacms.rules 
ATTRS{idVendor}=="1546" ATTRS{idProduct}=="1102", ENV{ID_MM_DEVICE_IGNORE}="1"

Knowing this, it seems this PR is more of a hack or workaround, so I'm closing it.