search

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

antfs-cli times out when waiting for message #145

Open HelgeKrueger opened 8 years ago

HelgeKrueger commented 8 years ago

I installed antfs-cli on a new computer and now it usually times out with the following error

Downloading 2016-02-05_20-26-20_4_707.fit: [............                  ] ETA: 0:00:27Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/antfs_cli/program.py", line 356, in main
    g.start()
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 217, in start
    self._main()
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 155, in _main
    self.on_transport(beacon)
  File "build/bdist.linux-x86_64/egg/antfs_cli/program.py", line 244, in on_transport
    self.download_file(fileobject)
  File "build/bdist.linux-x86_64/egg/antfs_cli/program.py", line 281, in download_file
    data = self.download(fil.get_index(), AntFSCLI._get_progress_callback())
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 311, in download
    self._send_command(DownloadRequest(index, offset, True, crc))
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 195, in _send_command
    self._channel.send_burst_transfer(data)
  File "/usr/local/lib/python2.7/dist-packages/ant/easy/channel.py", line 119, in send_burst_transfer
    self.send_burst_transfer(data)
  File "/usr/local/lib/python2.7/dist-packages/ant/easy/channel.py", line 114, in send_burst_transfer
    self.wait_for_event([Message.Code.EVENT_TRANSFER_TX_START])
  File "/usr/local/lib/python2.7/dist-packages/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/local/lib/python2.7/dist-packages/ant/easy/filter.py", line 72, in wait_for_event
    return wait_for_message(match, process, queue, condition)
  File "/usr/local/lib/python2.7/dist-packages/ant/easy/filter.py", line 61, in wait_for_message
    raise AntException("Timed out while waiting for message")
AntException: Timed out while waiting for message
Interrupted: Timed out while waiting for message

I attached the output of antfs-cli --debug as log.txt

I am running the Ubuntu. Kernel 4.2.0-25-generic. Any help on how to get antfs-cli working properly is appreciated.

HelgeKrueger commented 8 years ago

I am trying to understand what happens. The difference in the debug output is the following if everything is doing well

Wait for response...
Get command, t15, s0
Read data: [a4 09 50 20 05 7d 06 43 9c 17 31 0f 55] (now have [a4 09 50 20 05 7d 06 43 9c 17 31 0f 55] in buffer)

versus the following if something breaks

Wait for response...
Get command, t15, s0
Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer)
Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)>

Not sure what happens yet. The line Get command, t15, s0 comes from ant.fs.manager._get_command. So this should probably be an issue for the openant repo.

netwel commented 8 years ago

I experienced some time outs as well , but it works fine if I first turn the wifi on my laptop off. Ant is very delicate protocol, lots of possible sources for interference on the signal. think like bluetooth, nearby mobile device etc, Hope this helps

HelgeKrueger commented 8 years ago

I am unsure why this helps, but by changing the timeout in ant.fs.manage.py in the _get_command function from 15 seconds to 5 seconds, I am able to transfer files. It often takes quite a bit of time, but works flawlessly so far.

This should at least help in narrowing down where the problem is coming from, but I am not sure how one could construct a better fix from it.

Tigge commented 8 years ago

@HelgeKrueger Interesting. I'll take a look and see if I can figure out why changing this helps.

jirivrany commented 8 years ago

Same issue for me. I will try the change suggested by @HelgeKrueger.

Update - after 2 days of testing, it seems, that lower timeout helps. I'm not sure why. I will try to play with that a bit more.

SimonArnu commented 8 years ago

As I always had issues with timeouts, I tried the change mentioned by @HelgeKrueger. It really helped, no more timeouts. Thanks for the suggestion.

HelgeKrueger commented 8 years ago

I think the interesting change in behavior is shown in the following snippet.

Read data: [a4 09 50 60 14 d4 1c 90 48 06 48 ba 6d] (now have [a4 09 50 60 14 d4 1c 90 48 06 48 ba 6d] in buffer)
Read data: [a4 09 50 a0 00 00 00 00 00 00 e7 d5 6f] (now have [a4 09 50 a0 00 00 00 00 00 00 e7 d5 6f] in buffer)
parsing data array('B', [68, 137, 0, 0, 0, 2, 0, 0, 0, 156, 0, 0, 207, 211, 2, 0, 186, 99, 49, 213, 183, 40, 34, 150, 130, 66, 8, 137, 181, 22, 0, 19, 21, 207, 19, 134, 0, 4, 50, 186, 99, 49, 2, 2, 4, 1, 3, 3, 255, 255, 255, 6, 50, 186, 99, 49, 177, 185, 40, 34, 171, 128, 66, 8, 137, 181, 22, 0, 16, 21, 214, 21, 134, 0, 6, 51, 186, 99, 49, 56, 186, 40, 34, 161, 127, 66, 8, 86, 182, 22, 0, 13, 21, 48, 12, 134, 0, 4, 52, 186, 99, 49, 4, 4, 4, 1, 3, 3, 255, 255, 255, 6, 52, 186, 99, 49, 211, 186, 40, 34, 220, 126, 66, 8, 27, 183, 22, 0, 11, 21, 170, 7, 133, 0, 6, 53, 186, 99, 49, 19, 187, 40, 34, 165, 125, 66, 8, 252, 183, 22, 0, 8, 21, 210, 8, 133, 0, 6, 54, 186, 99, 49, 50, 187, 40, 34, 169, 123, 66, 8, 228, 185, 22, 0, 6, 21, 11, 19, 132, 11, 6, 55, 186, 99, 49, 122, 186, 40, 34, 159, 120, 66, 8, 19, 188, 22, 0, 4, 21, 212, 21, 131, 46, 6, 56, 186, 99, 49, 119, 185, 40, 34, 163, 118, 66, 8, 123, 190, 22, 0, 2, 21, 24, 24, 131, 54, 6, 57, 186, 99, 49, 77, 183, 40, 34, 22, 116, 66, 8, 18, 193, 22, 0, 0, 21, 226, 25, 131, 60, 6, 58, 186, 99, 49, 126, 181, 40, 34, 18, 113, 66, 8, 196, 195, 22, 0, 255, 20, 248, 26, 130, 63, 6, 59, 186, 99, 49, 131, 179, 40, 34, 182, 109, 66, 8, 104, 198, 22, 0, 255, 20, 95, 26, 130, 44, 6, 61, 186, 99, 49, 234, 175, 40, 34, 138, 103, 66, 8, 2, 204, 22, 0, 255, 20, 14, 28, 132, 69, 6, 62, 186, 99, 49, 182, 173, 40, 34, 85, 99, 66, 8, 208, 206, 22, 0, 0, 21, 14, 28, 134, 70, 6, 63, 186, 99, 49, 187, 171, 40, 34, 205, 95, 66, 8, 160, 209, 22, 0, 0, 21, 38, 28, 134, 70, 6, 64, 186, 99, 49, 180, 169, 40, 34, 29, 92, 66, 8, 120, 212, 22, 0, 0, 21, 111, 28, 137, 71, 6, 65, 186, 99, 49, 199, 167, 40, 34, 132, 88, 66, 8, 75, 215, 22, 0, 255, 20, 62, 28, 137, 71, 6, 66, 186, 99, 49, 5, 166, 40, 34, 43, 85, 66, 8, 33, 218, 22, 0, 0, 21, 87, 28, 137, 71, 6, 67, 186, 99, 49, 68, 164, 40, 34, 238, 81, 66, 8, 246, 220, 22, 0, 0, 21, 87, 28, 141, 71, 6, 68, 186, 99, 49, 47, 162, 40, 34, 23, 78, 66, 8, 214, 223, 22, 0, 0, 21, 187, 28, 141, 71, 6, 69, 186, 99, 49, 71, 160, 40, 34, 93, 74, 66, 8, 181, 226, 22, 0, 0, 21, 187, 28, 144, 71, 6, 70, 186, 99, 49, 99, 158, 40, 34, 192, 70, 66, 8, 151, 229, 22, 0, 255, 20, 212, 28, 144, 72, 6, 72, 186, 0, 0, 0, 0, 0, 0, 231, 213])
Download 14, o40448, c54759
packing 'D\t\x0e\x00\x00\x9e\x00\x00\x00\x01\xe7\xd5\x00\x00\x00\x00' in array('B', [68, 9, 14, 0, 0, 158, 0, 0, 0, 1, 231, 213, 0, 0, 0, 0]),<type 'array.array'>
send burst transfer 0
Send burst transfer, chan 0, data array('B', [68, 9, 14, 0, 0, 158, 0, 0, 0, 1, 231, 213, 0, 0, 0, 0])
Send burst transfer, packet 0, seq 0, data array('B', [68, 9, 14, 0, 0, 158, 0, 0])
Send burst transfer, packet 1, seq 5, data array('B', [0, 1, 231, 213, 0, 0, 0, 0])
wait for message matching <function match at 0x7f968b38be60>
looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))])
 - could not find response matching <function match at 0x7f968b38be60>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
Got broadcast data, examine queue to see if we should send anything back
Write data: [a4 09 50 00 44 09 0e 00 00 9e 00 00 20]
 - sent message from queue, <ant.base.Message 50:[00 44 09 0e 00 00 9e 00 00] (s:a4, l:9, c:20)>
Write data: [a4 09 50 a0 00 01 e7 d5 00 00 00 00 6e]
 - sent message from queue, <ant.base.Message 50:[a0 00 01 e7 d5 00 00 00 00] (s:a4, l:9, c:6e)>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 03 40 00 01 0a ec] (now have [a4 03 40 00 01 0a ec] in buffer)
Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)>
Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer)
Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)>
Read data: [a4 09 4e 00 43 24 03 03 39 05 00 00 b8] (now have [a4 09 4e 00 43 24 03 03 39 05 00 00 b8] in buffer)
looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [10])), (0, 1, array('B', [5]))])
 - response found (0, 1, array('B', [10]))
wait for message matching <function match at 0x7f968b38bf50>
looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [5]))])
 - response found (0, 1, array('B', [5]))
done sending burst transfer 0
Wait for response...
Get command, t5, s0
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 50 00 43 24 03 03 39 05 00 00 a6] (now have [a4 09 50 00 43 24 03 03 39 05 00 00 a6] in buffer)
Read data: [a4 09 50 20 44 89 00 00 00 02 00 00 12] (now have [a4 09 50 20 44 89 00 00 00 02 00 00 12] in buffer)
Read data: [a4 09 50 40 00 9e 00 00 cf d3 02 00 3d] (now have [a4 09 50 40 00 9e 00 00 cf d3 02 00 3d] in buffer)
Read data: [a4 09 50 60 63 31 79 9a 28 22 74 3f 6d] (now have [a4 09 50 60 63 31 79 9a 28 22 74 3f 6d] in buffer)

A longer sample would be

Read data: [a4 09 50 60 69 26 00 ed 16 52 1b 98 f8] (now have [a4 09 50 60 69 26 00 ed 16 52 1b 98 f8] in buffer)
Read data: [a4 09 50 20 44 06 b6 c0 63 31 84 83 bc] (now have [a4 09 50 20 44 06 b6 c0 63 31 84 83 bc] in buffer)
Read data: [a4 09 50 40 1a 22 23 d4 39 08 fc 6e d1] (now have [a4 09 50 40 1a 22 23 d4 39 08 fc 6e d1] in buffer)
Read data: [a4 09 50 60 26 00 ed 16 3e 1c 98 45 bf] (now have [a4 09 50 60 26 00 ed 16 3e 1c 98 45 bf] in buffer)
Read data: [a4 03 40 00 01 04 e2] (now have [a4 03 40 00 01 04 e2] in buffer)
Got channel event, <ant.base.Message 40:[00 01 04] (s:a4, l:3, c:e2)>
Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer)
Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer)
Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer)
Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer)
Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer)
Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Download 14 timeout
Download 14, o68096, c49511
packing 'D\t\x0e\x00\x00\n\x01\x00\x00\x01g\xc1\x00\x00\x00\x00' in array('B', [68, 9, 14, 0, 0, 10, 1, 0, 0, 1, 103, 193, 0, 0, 0, 0]),<type 'array.array'>
send burst transfer 0
Send burst transfer, chan 0, data array('B', [68, 9, 14, 0, 0, 10, 1, 0, 0, 1, 103, 193, 0, 0, 0, 0])
Send burst transfer, packet 0, seq 0, data array('B', [68, 9, 14, 0, 0, 10, 1, 0])
Send burst transfer, packet 1, seq 5, data array('B', [0, 1, 103, 193, 0, 0, 0, 0])
wait for message matching <function match at 0x7f968b38bf50>
looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))])
 - could not find response matching <function match at 0x7f968b38bf50>
Got broadcast data, examine queue to see if we should send anything back
Write data: [a4 09 50 00 44 09 0e 00 00 0a 01 00 b5]
 - sent message from queue, <ant.base.Message 50:[00 44 09 0e 00 00 0a 01 00] (s:a4, l:9, c:b5)>
Write data: [a4 09 50 a0 00 01 67 c1 00 00 00 00 fa]
 - sent message from queue, <ant.base.Message 50:[a0 00 01 67 c1 00 00 00 00] (s:a4, l:9, c:fa)>
Read data: [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] (now have [a4 09 4e 00 43 24 02 03 39 05 00 00 b9] in buffer)
No new data this period
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 03 40 00 01 0a ec] (now have [a4 03 40 00 01 0a ec] in buffer)
Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)>
Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer)
Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)>
Read data: [a4 09 4e 00 43 24 03 03 39 05 00 00 b8] (now have [a4 09 4e 00 43 24 03 03 39 05 00 00 b8] in buffer)
looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [10])), (0, 1, array('B', [5]))])
 - response found (0, 1, array('B', [10]))
wait for message matching <function match at 0x7f968b38be60>
looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [4])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [5]))])
 - response found (0, 1, array('B', [5]))
done sending burst transfer 0
Wait for response...
Get command, t5, s0
Got broadcast data, examine queue to see if we should send anything back
 - no messages in queue
Read data: [a4 09 50 00 43 24 03 03 39 05 00 00 a6] (now have [a4 09 50 00 43 24 03 03 39 05 00 00 a6] in buffer)
Read data: [a4 09 50 20 44 89 00 00 00 02 00 00 12] (now have [a4 09 50 20 44 89 00 00 00 02 00 00 12] in buffer)
Read data: [a4 09 50 40 00 0a 01 00 cf d3 02 00 a8] (now have [a4 09 50 40 00 0a 01 00 cf d3 02 00 a8] in buffer)
Read data: [a4 09 50 60 22 cb 39 08 4b 4c 26 00 64] (now have [a4 09 50 60 22 cb 39 08 4b 4c 26 00 64] in buffer)

I hope this helps in diagnozing the problem. I'm unsure what I would be looking for ...

joelcox commented 8 years ago

I can confirm that decreasing the timeout like @HelgeKrueger suggests, results in a more stable (albeit slower) transfer. Both Garmin Express, ANT Agent and antfs-cli had trouble transferring this file, but decreasing the timeout worked.

aspiers commented 8 years ago

Any more progress on this? Thanks!

Tigge commented 7 years ago

I'm afraid I haven't had time to look at this. But I think we can go ahead and merge a fix that increases the timeout since it seem to work for multiple people.