sync modem --run failing on serial read error

[hachi]

The cmdline reports this as:

Syncing 53.c1.da (modem) device
  Adding ID: 1d.9d.c8  grp: 20  type: CTRL  data: 0x14 0x00 0x00:
ERROR: Serial read error from /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_AK05Z8HT-if00-port0

but on the server side there's a much expanded situation. I see the behavior here and it looks fairly normal. Happy to debug this if you have any pointers on where to start.

2020-02-18 02:38:37 INFO Modem: Device 53.c1.da (modem) cmd: sync
2020-02-18 02:38:37 UI Modem: Syncing 53.c1.da (modem) device
2020-02-18 02:38:37 DEBUG Mqtt: MQTT publish insteon/command/modem/session/4118655753 {"type": "MESSAGE", "data": "Syncing 53.c1.da (modem) device "} qos=0 ret=False
2020-02-18 02:38:37 DEBUG CommandSeq: Running command 1 of 6
2020-02-18 02:38:37 UI Modem:   Adding ID: 1d.9d.c8  grp: 20  type: CTRL  data: 0x14 0x00 0x00:
2020-02-18 02:38:37 DEBUG Mqtt: MQTT publish insteon/command/modem/session/4118655753 {"type": "MESSAGE", "data": "  Adding ID: 1d.9d.c8  grp: 20  type: CTRL  data: 0x14 0x00 0x00:"} qos=0 ret=False
2020-02-18 02:38:37 ERROR Serial: Serial read error from /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_AK05Z8HT-if00-port0
Traceback (most recent call last):
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/network/Serial.py", line 184, in read_from_link
    self.signal_read.emit(self, data)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/Signal.py", line 47, in emit
    slot(*args, **kwargs)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/Protocol.py", line 336, in _data_read
    self._process_msg(msg)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/Protocol.py", line 417, in _process_msg
    status = handler.msg_received(self, msg)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/handler/ModemDbGet.py", line 68, in msg_received
    self.on_done(True, "Database download complete", None)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/CommandSeq.py", line 133, in on_done
    entry.run(self.protocol, self.on_done)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/CommandSeq.py", line 201, in run
    self.func(*self.args, on_done=on_done, **self.kwargs)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/Modem.py", line 671, in sync
    seq.run()
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/CommandSeq.py", line 100, in run
    self.on_done(True, None, None)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/CommandSeq.py", line 133, in on_done
    entry.run(self.protocol, self.on_done)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/CommandSeq.py", line 201, in run
    self.func(*self.args, on_done=on_done, **self.kwargs)
  File "/root/insteon-mqtt/venv/lib/python3.7/site-packages/insteon_mqtt/Modem.py", line 699, in _sync_add
    on_done=on_done)
TypeError: add_on_device() got multiple values for argument 'on_done'
2020-02-18 02:38:37 DEBUG Mqtt: MQTT publish insteon/command/modem/session/4118655753 {"type": "ERROR", "data": "Serial read error from /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_AK05Z8HT-if00-port0"} qos=0 ret=False
2020-02-18 02:38:37 DEBUG Mqtt: MQTT writing
2020-02-18 02:38:42 WARNING Base: Handler timed out - no more retries (82 sent)
2020-02-18 02:38:42 DEBUG Mqtt: MQTT publish insteon/command/modem/session/4118655753 {"type": "MESSAGE", "data": "Handler timed out - no more retries (82 sent)"} qos=0 ret=False
2020-02-18 02:38:42 ERROR Mqtt: Sync complete
2020-02-18 02:38:42 DEBUG Mqtt: MQTT publish insteon/command/modem/session/4118655753 {"type": "ERROR", "data": "Sync complete"} qos=0 ret=False
2020-02-18 02:38:42 DEBUG Mqtt: MQTT publish insteon/command/modem/session/4118655753 {"type": "END", "data": null} qos=0 ret=False
2020-02-18 02:38:42 DEBUG Mqtt: MQTT writing

[hachi]

This problem is fixed by the same patch in #192

[krkeegan]

awesome