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 76 forks source link

TransferFailedException #132

Open LeftyAce opened 9 years ago

LeftyAce commented 9 years ago

Hi all, and thanks for the great work on this project.

I'm having an issue downloading files from my watch. It worked fine for a few days, then it would fail mid-transfer, but if I retried a few times the transfer would complete, but now it fails every time. I'm running afdc5ff. I also get the libusb write failed, closing anyway hang at the very end (from issue 129). I got this even when transfers were working (I would just Control-C to quit).

Here is the command line output. Please let me know if there is more information I should provide.

$ antfs-cli
Driver available: [<class 'ant.base.driver.USB2Driver'>, <class 'ant.base.driver.USB3Driver'>]
 - Using: <class 'ant.base.driver.USB3Driver'>
Request basic information...
  Capabilities:  array('B', [8, 8, 0, 186, 54, 0, 223])
Starting system...
Key done...
Searching...
Authenticating with Forerunner 910XT (3841664808)
 - Passkey: OK
Downloading 4 file(s)
Downloading 2015-04-11_15-32-02_4_93.fit: [.....                         ] ETA: 0:02:19Traceback (most recent call last):
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/channel.py", line 114, in send_burst_transfer
    self.wait_for_event([Message.Code.EVENT_TRANSFER_TX_START])
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/channel.py", line 51, in wait_for_event
    return wait_for_event(ok_codes, self._node._events, self._node._event_cond)
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/filter.py", line 72, in wait_for_event
    return wait_for_message(match, process, queue, condition)
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/filter.py", line 57, in wait_for_message
    raise TransferFailedException()
ant.easy.exception.TransferFailedException

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.4/site-packages/antfs_cli-0.2-py3.4.egg/antfs_cli/program.py", line 343, in main
    g.start()
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/fs/manager.py", line 212, in start
    self._main()
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/fs/manager.py", line 150, in _main
    self.on_transport(beacon)
  File "/usr/lib/python3.4/site-packages/antfs_cli-0.2-py3.4.egg/antfs_cli/program.py", line 231, in on_transport
    self.download_file(fileobject)
  File "/usr/lib/python3.4/site-packages/antfs_cli-0.2-py3.4.egg/antfs_cli/program.py", line 268, in download_file
    data = self.download(fil.get_index(), AntFSCLI._get_progress_callback())
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/fs/manager.py", line 306, in download
    self._send_command(DownloadRequest(index, offset, True, crc))
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/fs/manager.py", line 190, in _send_command
    self._channel.send_burst_transfer(data)
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/channel.py", line 119, in send_burst_transfer
    self.send_burst_transfer(data)
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/channel.py", line 114, in send_burst_transfer
    self.wait_for_event([Message.Code.EVENT_TRANSFER_TX_START])
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/channel.py", line 51, in wait_for_event
    return wait_for_event(ok_codes, self._node._events, self._node._event_cond)
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/filter.py", line 72, in wait_for_event
    return wait_for_message(match, process, queue, condition)
  File "/usr/lib/python3.4/site-packages/openant-0.2-py3.4.egg/ant/easy/filter.py", line 61, 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

libusb: warning [libusb_close] internal signalling write failed, closing anyway
Eothred commented 9 years ago

I have a similar issue with my 910-XT. I usually solve it by deleting ~/.config/antfs-cli (or rename it, note you have all your downloaded fit files here), then run again. Have to do this quite often.

LeftyAce commented 9 years ago

Thanks for the tip, Eothred. It looks like I can just delete the authfile (not the whole .config directory). That fixes the problem, temporarily. I am still getting the USB failed to close error so I still have to kill antfs-cli with Control-C. Is it possible that the authfile isn't getting closed properly when I do that, and is getting corrupted? I currently only have a good authfile. I'll make a copy and see if it is different next time it failes.

Tigge commented 9 years ago

That is a bit weird. I'll see if I can look into it a bit more in detail. There is now a --pair switch that can be used to force a re-pair. Perhaps that is a better workaround if it do work.

Eothred commented 9 years ago

Hi Tigge,

Thanks for looking into it. What happens is usually that my GPS first show "transfer status", then after a while just quietly goes back to "default screen". antfs-cli is still staying in "transfer mode" for a while before it eventually seems to timeout or similar. The "--pair" functionality sounds like a useful workaround for now, I will try that next time!

LeftyAce commented 9 years ago

Hi Tigge,

I tried the new --pair switch, and it did force a re-pair (I get the pop up on the watch saying "pair with antfs-cli?"), but the transfer fails almost immediately. If I go and delete the authfile, the transfer works the first time.

I would love to help diagnose this, but don't really know how. Is there a way to check if the authfile is "valid" somehow? Or figure out if there's somewhere in the code involving reading the authfile that's causing this problem?

Here's the error I'm currently getting:

$ antfs-cli --pair

Driver available: [<class 'ant.base.driver.USB2Driver'>, <class 'ant.base.driver.USB3Driver'>]
 - Using: <class 'ant.base.driver.USB3Driver'>
Request basic information...
  Capabilities:  array('B', [8, 8, 0, 186, 54, 0, 223])
Starting system...
Key done...
Searching...
Authenticating with Forerunner 910XT (3841664808)
 - Pairing: OK
Traceback (most recent call last):
  File "/usr/lib/python3.4/site-packages/antfs_cli-0.3-py3.4.egg/antfs_cli/program.py", line 354, in main
    g.start()
  File "/usr/lib/python3.4/site-packages/openant-0.3-py3.4.egg/ant/fs/manager.py", line 217, in start
    self._main()
  File "/usr/lib/python3.4/site-packages/openant-0.3-py3.4.egg/ant/fs/manager.py", line 155, in _main
    self.on_transport(beacon)
  File "/usr/lib/python3.4/site-packages/antfs_cli-0.3-py3.4.egg/antfs_cli/program.py", line 196, in on_transport
    result = self.set_time()
  File "/usr/lib/python3.4/site-packages/openant-0.3-py3.4.egg/ant/fs/manager.py", line 347, in set_time
    self._send_commandpipe(t.get())
  File "/usr/lib/python3.4/site-packages/openant-0.3-py3.4.egg/ant/fs/manager.py", line 224, in _send_commandpipe
    self.upload(0xfffe, data)
  File "/usr/lib/python3.4/site-packages/openant-0.3-py3.4.egg/ant/fs/manager.py", line 266, in upload
    if upload_response._get_argument("response") != UploadResponse.Response.OK:
  File "/usr/lib/python3.4/site-packages/openant-0.3-py3.4.egg/ant/fs/command.py", line 67, in _get_argument
    return self._arguments[name]
KeyError: 'response'
 - Set time: Interrupted: 'response'
libusb: warning [libusb_close] internal signalling write failed, closing anyway
^C
LeftyAce commented 9 years ago

Updated information: Your suggestion of the --pair switch made me realize that I don't have to tell the watch to "enable pairing" in order for pairing to happen. I still get the pop-up option to pair even without "enable pairing" set in the menus on the watch.

But that seems to be what makes things work. If I don't enable pairing on the watch, deleting the authfile by itself is NOT sufficient. It seems that I have to enable pairing on the watch AND delete the authfile.

Sometimes that combination still results in a failure to connect (before the fit file starts transferring), but I can retry and it will connect and transfer the files. If I don't delete the authfile and enable pairing, the fit file transfer always fails.

Tigge commented 9 years ago

That error is in a new part of the code that I pushed yesterday, so it is probably not related to the other error you where getting. It is now trying to syncronize the time to the watch, but it is failing here for some reason. Do you have a log file I can look at?

LeftyAce commented 9 years ago

Thanks for the response! I just did a successful transfer (using the remove authfile and set the watch to pair trick) and it still said "set time: FAILED" but the file transfer succeeded. The output is here:

$ antfs-cli 

Driver available: [<class 'ant.base.driver.USB2Driver'>, <class 'ant.base.driver.USB3Driver'>]
 - Using: <class 'ant.base.driver.USB3Driver'>
Request basic information...
  Capabilities:  array('B', [8, 8, 0, 186, 54, 0, 223])
Starting system...
Key done...
Searching...
Authenticating with Forerunner 910XT (3841664808)
 - Pairing: OK
 - Set time: FAILED

Downloading 1 file(s)
Downloading 2015-06-11_07-46-20_4_142.fit: [..............................] ETA: 0:00:00
libusb: warning [libusb_close] internal signalling write failed, closing anyway

Is there a way to attach logfiles, or should I just paste it into a response here? The file is pretty large.

Tigge commented 9 years ago

I recommend using https://gist.github.com/ for log files. Either that or send me an email. It would be nice to have a log from a failing transfer as well as a good one if possible.

Eothred commented 9 years ago

I've tried the --pair twice now (sorry don't use my Garmin that often), worked very well. I'll try to remember to provide you the log files. Usually without the --pair option it fails 4 times out of 5, in particular for larger files.

Eothred commented 9 years ago

https://gist.github.com/Eothred/bf42a1948a6ffc2f985b both stdout and the log file (in case you see any useful info there as well)

LeftyAce commented 9 years ago

Sorry for the delay, here are my successful and unsuccessful log files. It seems that I have to enable pairing on the 910xt to get things to work. The --pair option does help, it means I don't have to delete the authfile directly.

Successful transfer: https://gist.github.com/LeftyAce/1500b93fd62f2130cee5 Failed transfer: https://gist.github.com/LeftyAce/0b962b836b5f2433e62c

Eothred commented 9 years ago

Just to add info here, the --pair clearly solves the issue (though it is not the way you want to solve it I guess). I downloaded 23 workouts from the watch in one go without any errors with the pair option. Without that option I would typically have to try an average of 5 times per workout. Larger files would fail more often (my impression).

LeftyAce commented 9 years ago

I feel bad that I'm just posting symptoms and have no idea how to diagnose this. For me, --pair makes things more likely to work, but I still get failures; I have to retry about every third time, and I may have to retry multiple times to get it to work. It does seem to be a bigger issue for large files.

Is there a timeout somewhere that could be causing a problem? Or is there a way to see if my system is doing something stupid like shutting off the ant+ stick? (I checked that in Powertop and did have to change some settings so the ant+ dongle wouldn't get powered off to save battery on my laptop...)

msitms commented 7 years ago

I have the same problem with my 310XT, but I already had similar issues with the Garmin software for Windows, so I'm pretty confident that this is not a bug related to anfs-cli or the underlying stack but some flaw of the Forerunner device or the ANT stick. Or maybe it's interfering with some other radio communication device (although I've tried to exclude that).

Because I first assumed that the problems might be related to Garmin's low-quality Windows software or drivers, I connected my ANT stick to my Raspberry Pi Model B+ running Raspbian. With Garmin's Windows software, I had to turn off and on the device to enforce a new try after each timeout (which made it practically impossible to sync after a while).

Thanks to this great software, I was able to write a bash script that automatically repeats the sync until antfs-cli returns an exit code of 0 and eventually, sometimes after hours (!) in case of large (or many) files, gets the job done:

#!/bin/bash
until antfs-cli
do
   echo "Trying again..."
done

Maybe this workaround works for others as well. Maybe increasing some timeouts, like suggested in #145, would help as well.