Tigge / antfs-cli

Extracts FIT files from ANT-FS based sport watches such as Garmin Forerunner 60, 405CX, 310XT, 610 and 910XT.
MIT License
312 stars 77 forks source link

Timeout occurs when attempting to download the file that comes after a 'large' file #190

Closed one-giant-leap closed 2 years ago

one-giant-leap commented 2 years ago

I am able to successfully download multiple small files without issue, however when a 'larger' file (e.g. 20910 bytes) is encountered, the 'larger' file will be downloaded successfully but the next file will produce a timeout.

For example, given the following Directory:

Index Type FIT Type FIT Number Size Date FIT Flags Flags 12 4 4 0 666 2000-01-01 04:29:42+00:00 0 rwe--- 13 4 4 0 666 2000-01-01 04:29:50+00:00 0 rwe--- 14 4 4 0 666 2000-01-01 04:29:56+00:00 0 rwe--- 15 4 4 0 666 2000-01-01 04:30:02+00:00 0 rwe--- 16 4 4 0 666 2000-01-01 04:30:08+00:00 0 rwe--- 17 4 4 0 666 2000-01-01 04:30:14+00:00 0 rwe--- 18 4 4 0 666 2000-01-01 04:30:20+00:00 0 rwe--- 25 4 4 0 20910 2000-01-01 04:46:12+00:00 0 rwe--- 22 4 4 0 666 2000-01-01 04:40:36+00:00 0 rwe--- 23 4 4 0 666 2000-01-01 04:40:40+00:00 0 rwe--- 24 4 4 0 666 2000-01-01 04:40:44+00:00 0 rwe---

Downloading index 22 will fail and the following error is printed:

File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/antfs_cli-0.4-py3.10.egg/antfs_cli/program.py", line 384, in main g.start() File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/fs/manager.py", line 223, in start self._main() File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/fs/manager.py", line 161, in _main self.on_transport(beacon) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/antfs_cli-0.4-py3.10.egg/antfs_cli/program.py", line 254, in on_transport self.download_file(fileobject) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/antfs_cli-0.4-py3.10.egg/antfs_cli/program.py", line 297, in download_file data = self.download(fil.get_index(), AntFSCLI._get_progress_callback()) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/fs/manager.py", line 325, in download self._send_command(DownloadRequest(index, offset, True, crc)) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/fs/manager.py", line 201, in _send_command self._channel.send_burst_transfer(data) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/easy/channel.py", line 133, in send_burst_transfer self.wait_for_event([Message.Code.EVENT_TRANSFER_TX_START]) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/easy/channel.py", line 50, in wait_for_event return wait_for_event(ok_codes, self._node._events, self._node._event_cond) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/easy/filter.py", line 73, in wait_for_event return wait_for_message(match, process, queue, condition) File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/site-packages/openant-0.4-py3.10.egg/ant/easy/filter.py", line 62, in wait_for_message raise AntException("Timed out while waiting for message") ant.easy.exception.AntException: Timed out while waiting for message Interrupted: Timed out while waiting for message

I have visibility into the device where the files originate (I have a debugger set up on the embedded device i.e. fitness watch). The device doesn't appear to receive the 'ANTFS_EVENT_DOWNLOAD_REQUEST' message from antfs-cli when the time comes to download the file in question (the one that follows a larger file). Hence, the device doesn't respond with the message that antfs-cli is waiting for and antfs-cli promptly times out (within 1-2 seconds of having downloaded the 'larger' file).

Any thoughts on what might be occurring? My next test is to see how long antfs-cli typically takes to time out after sending the 'ANTFS_EVENT_DOWNLOAD_REQUEST' message to the device. If it is after quite some time, then that suggests the time taken to download the 'larger' file is possibly starving a e.g. watchdog time or something similar.

one-giant-leap commented 2 years ago

I've managed to get it working. From what I can tell the issue was that multiple 'EVENT_RX_FAIL' messages would pile up when a large file transfer was taking place. When antfs-cli started to process the 'EVENT_RX_FAIL' messages upon having transferred the large file, it would time out prior to sending the next 'DOWNLOAD_REQUEST'.

The 'fix' was to check for any 'EVENT_RX_FAIL' messages and stop them going into the queue (code found in base/ant.py in openant).

  # Channel event
  elif (
      message._id == Message.ID.RESPONSE_CHANNEL
      and message._data[1] == 0x01
  ):
      _logger.debug("Got channel event, %r", message)
      if (
          message._data[2] != Message.Code.EVENT_RX_FAIL
      ):
          self._events.put(
              (
                  "event",
                  (message._data[0], message._data[1], message._data[2:]),
              )
          )
  elif message._id == Message.ID.BROADCAST_DATA:
      self._on_broadcast(message)
  elif message._id == Message.ID.ACKNOWLEDGED_DATA:
      self._on_acknowledge(message)
  elif message._id == Message.ID.BURST_TRANSFER_DATA:
      self._on_burst_data(message)
  else:
      _logger.warning("Got unknown message, %r", message)