Tigge/antfs-cli

WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)

Opened this issue · 3 comments

I am not able to get this working at all on my work computer. It is running fine at home on an old machine running 64bit xubuntu but I cannot get it working on 64bit ubuntu. I'm trying to sync my 910xt.

LSB Version: core-2.0-amd64:core-2.0-noarch:core-3.0-amd64:core-3.0-noarch:core-3.1-amd64:core-3.1-noarch:core-3.2-amd64:core-3.2-noarch:core-4.0-amd64:core-4.0-noarch
Distributor ID: Ubuntu
Description: Ubuntu 13.04
Release: 13.04
Codename: raring

Garmin Log:
MainThread 2013-05-31 09:17:55,256 garmin.ant.base.ant DEBUG USB Find device, vendor 0xfcf, product 0x1008 (ant.py:44)
MainThread 2013-05-31 09:17:55,269 garmin.ant.base.ant DEBUG USB Config values: (ant.py:51)
MainThread 2013-05-31 09:17:55,270 garmin.ant.base.ant DEBUG Config 1 (ant.py:53)
MainThread 2013-05-31 09:17:55,270 garmin.ant.base.ant DEBUG Interface 0, Alt 0 (ant.py:55)
MainThread 2013-05-31 09:17:55,270 garmin.ant.base.ant DEBUG Endpoint 129 (ant.py:57)
MainThread 2013-05-31 09:17:55,270 garmin.ant.base.ant DEBUG Endpoint 1 (ant.py:57)
MainThread 2013-05-31 09:17:55,271 garmin.ant.base.ant DEBUG No kernel driver active (ant.py:65)
MainThread 2013-05-31 09:17:55,442 garmin.ant.base.ant DEBUG UBS Endpoint out: <usb.core.Endpoint object at 0x1361990>, 1 (ant.py:93)
MainThread 2013-05-31 09:17:55,443 garmin.ant.base.ant DEBUG UBS Endpoint in: <usb.core.Endpoint object at 0x1361910>, 129 (ant.py:104)
ant.base 2013-05-31 09:17:55,443 garmin.ant.base.ant DEBUG Ant runner started (ant.py:159)
MainThread 2013-05-31 09:17:55,444 garmin.ant.easy.node DEBUG requesting message 0x3e (node.py:62)
MainThread 2013-05-31 09:17:55,445 garmin.ant.base.ant DEBUG Write data: a4 02 4d 00 3e d5
MainThread 2013-05-31 09:17:55,445 garmin.ant.easy.node DEBUG done requesting message 0x3e (node.py:64)
MainThread 2013-05-31 09:17:55,446 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x12d57d0> (filter.py:37)
MainThread 2013-05-31 09:17:55,446 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,446 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x12d57d0> (filter.py:55)
ant.base 2013-05-31 09:17:55,446 garmin.ant.base.ant DEBUG Read data: [a4 0b 3e 41 4a 4b 31 2e 30 34 52 41 46 00 9f](now have [a4 0b 3e 41 4a 4b 31 2e 30 34 52 41 46 00 9f] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,449 garmin.ant.easy.filter DEBUG looking for matching message in deque([(None, 62, array('B', [65, 74, 75, 49, 46, 48, 52, 82, 65, 70, 0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,449 garmin.ant.easy.filter DEBUG - response found (None, 62, array('B', [65, 74, 75, 49, 46, 48, 52, 82, 65, 70, 0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,449 garmin.ant.easy.node DEBUG requesting message 0x54 (node.py:62)
MainThread 2013-05-31 09:17:55,450 garmin.ant.base.ant DEBUG Write data: a4 02 4d 00 54 bf
MainThread 2013-05-31 09:17:55,450 garmin.ant.easy.node DEBUG done requesting message 0x54 (node.py:64)
MainThread 2013-05-31 09:17:55,450 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x1354cf8> (filter.py:37)
MainThread 2013-05-31 09:17:55,450 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,450 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x1354cf8> (filter.py:55)
ant.base 2013-05-31 09:17:55,450 garmin.ant.base.ant DEBUG Read data: [a4 06 54 08 03 00 ba 36 00 71](now have [a4 06 54 08 03 00 ba 36 00 71] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,451 garmin.ant.easy.filter DEBUG looking for matching message in deque([(None, 84, array('B', [8, 3, 0, 186, 54, 0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,451 garmin.ant.easy.filter DEBUG - response found (None, 84, array('B', [8, 3, 0, 186, 54, 0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,452 garmin.ant.easy.node DEBUG requesting message 0x61 (node.py:62)
MainThread 2013-05-31 09:17:55,452 garmin.ant.base.ant DEBUG Write data: a4 02 4d 00 61 8a
MainThread 2013-05-31 09:17:55,452 garmin.ant.easy.node DEBUG done requesting message 0x61 (node.py:64)
MainThread 2013-05-31 09:17:55,452 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x12d57d0> (filter.py:37)
MainThread 2013-05-31 09:17:55,452 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,452 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x12d57d0> (filter.py:55)
ant.base 2013-05-31 09:17:55,453 garmin.ant.base.ant DEBUG Read data: [a4 04 61 6d 7e 32 00 e0](now have [a4 04 61 6d 7e 32 00 e0] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,456 garmin.ant.easy.filter DEBUG looking for matching message in deque([(None, 97, array('B', [109, 126, 50, 0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,456 garmin.ant.easy.filter DEBUG - response found (None, 97, array('B', [109, 126, 50, 0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,457 garmin.ant.base.ant DEBUG Write data: a4 01 4a 00 ef
MainThread 2013-05-31 09:17:55,457 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x1354cf8> (filter.py:37)
MainThread 2013-05-31 09:17:55,457 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,457 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x1354cf8> (filter.py:55)
ant.base 2013-05-31 09:17:55,457 garmin.ant.base.ant DEBUG Read data: [a4 01 6f 20 ea](now have [a4 01 6f 20 ea] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,458 garmin.ant.easy.filter DEBUG looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,458 garmin.ant.easy.filter DEBUG - response found (None, 111, array('B', [32])) (filter.py:44)
MainThread 2013-05-31 09:17:55,459 garmin.ant.base.ant DEBUG Write data: a4 09 46 00 a8 a4 23 b9 f5 5e 63 c1 74
MainThread 2013-05-31 09:17:55,459 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x12d57d0> (filter.py:37)
MainThread 2013-05-31 09:17:55,459 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,459 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x12d57d0> (filter.py:55)
ant.base 2013-05-31 09:17:55,459 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 46 00 a1](now have [a4 03 40 00 46 00 a1] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,462 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 70, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,462 garmin.ant.easy.filter DEBUG - response found (0, 70, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,463 garmin.ant.base.ant DEBUG Write data: a4 03 42 00 00 00 e5
MainThread 2013-05-31 09:17:55,463 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x1354cf8> (filter.py:37)
MainThread 2013-05-31 09:17:55,463 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,463 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x1354cf8> (filter.py:55)
ant.base 2013-05-31 09:17:55,464 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 42 00 a5](now have [a4 03 40 00 42 00 a5] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,465 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 66, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,465 garmin.ant.easy.filter DEBUG - response found (0, 66, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,465 garmin.ant.base.ant DEBUG Write data: a4 03 43 00 00 10 f4
MainThread 2013-05-31 09:17:55,465 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x12d57d0> (filter.py:37)
MainThread 2013-05-31 09:17:55,465 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,465 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x12d57d0> (filter.py:55)
ant.base 2013-05-31 09:17:55,466 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 43 00 a4](now have [a4 03 40 00 43 00 a4] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,469 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 67, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,469 garmin.ant.easy.filter DEBUG - response found (0, 67, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,469 garmin.ant.base.ant DEBUG Write data: a4 02 44 00 ff 1d
MainThread 2013-05-31 09:17:55,469 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x1354cf8> (filter.py:37)
MainThread 2013-05-31 09:17:55,470 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
ant.base 2013-05-31 09:17:55,470 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 44 00 a3](now have [a4 03 40 00 44 00 a3] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,470 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x1354cf8> (filter.py:55)
MainThread 2013-05-31 09:17:55,471 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 68, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,471 garmin.ant.easy.filter DEBUG - response found (0, 68, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,472 garmin.ant.base.ant DEBUG Write data: a4 02 45 00 32 d1
MainThread 2013-05-31 09:17:55,472 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x12d57d0> (filter.py:37)
MainThread 2013-05-31 09:17:55,472 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
ant.base 2013-05-31 09:17:55,472 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 45 00 a2](now have [a4 03 40 00 45 00 a2] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,472 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x12d57d0> (filter.py:55)
MainThread 2013-05-31 09:17:55,476 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 69, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,476 garmin.ant.easy.filter DEBUG - response found (0, 69, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,476 garmin.ant.base.ant DEBUG Write data: a4 03 49 00 53 00 bd
MainThread 2013-05-31 09:17:55,476 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x1354cf8> (filter.py:37)
MainThread 2013-05-31 09:17:55,477 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,477 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x1354cf8> (filter.py:55)
ant.base 2013-05-31 09:17:55,477 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 49 00 ae](now have [a4 03 40 00 49 00 ae] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,478 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 73, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,478 garmin.ant.easy.filter DEBUG - response found (0, 73, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,479 garmin.ant.base.ant DEBUG Write data: a4 05 51 00 00 00 01 00 f1
MainThread 2013-05-31 09:17:55,479 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x12d57d0> (filter.py:37)
MainThread 2013-05-31 09:17:55,479 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,479 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x12d57d0> (filter.py:55)
ant.base 2013-05-31 09:17:55,479 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 51 00 b6](now have [a4 03 40 00 51 00 b6] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,482 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 81, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,482 garmin.ant.easy.filter DEBUG - response found (0, 81, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,483 garmin.ant.base.ant DEBUG Write data: a4 01 4b 00 ee
MainThread 2013-05-31 09:17:55,483 garmin.ant.easy.filter DEBUG wait for message matching <function match at 0x1354cf8> (filter.py:37)
MainThread 2013-05-31 09:17:55,483 garmin.ant.easy.filter DEBUG looking for matching message in deque([]) (filter.py:40)
MainThread 2013-05-31 09:17:55,483 garmin.ant.easy.filter DEBUG - could not find response matching <function match at 0x1354cf8> (filter.py:55)
ant.base 2013-05-31 09:17:55,483 garmin.ant.base.ant DEBUG Read data: [a4 03 40 00 4b 00 ac](now have [a4 03 40 00 4b 00 ac] in buffer) (ant.py:271)
MainThread 2013-05-31 09:17:55,484 garmin.ant.easy.filter DEBUG looking for matching message in deque([(0, 75, array('B', [0]))]) (filter.py:40)
MainThread 2013-05-31 09:17:55,484 garmin.ant.easy.filter DEBUG - response found (0, 75, array('B', [0])) (filter.py:44)
MainThread 2013-05-31 09:17:55,484 garmin DEBUG Creating directories (garmin.py:58)
MainThread 2013-05-31 09:17:55,485 garmin.ant.fs.manager DEBUG Link level (manager.py:95)
ant.base 2013-05-31 09:17:56,484 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)
ant.base 2013-05-31 09:17:57,485 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)
ant.base 2013-05-31 09:17:58,486 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)
ant.base 2013-05-31 09:17:59,487 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)
ant.base 2013-05-31 09:18:00,488 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)
ant.base 2013-05-31 09:18:01,490 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)
ant.base 2013-05-31 09:18:02,491 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)
ant.base 2013-05-31 09:18:03,492 garmin.ant.base.ant WARNING <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:229)

In the console I just see "searching...". but the log file will continue to fill up with the error message until I kill the process.

This is a duplicate of issue #10.

If this helps at all:

➜ ~ dpkg --get-selections | grep usb
libgusb2:amd64 install
libusb-0.1-4:amd64 install
libusb-0.1-4:i386 install
libusb-1.0-0:amd64 install
libusb-1.0-0:i386 install
libusb-1.0-0-dev install
libusb-dev install
libusbmuxd2 install
usb-creator-common install
usb-creator-gtk install
usb-modeswitch install
usb-modeswitch-data install
usbmuxd install
usbutils install
xserver-xorg-video-sisusb install
➜ ~ pip freeze | grep usb
libusb1==1.1.0
pyusb==1.0.0a3

Yes, that will probably help though this issue is kinda hard to debug afaik, not sure exactly where it originates. When I tried to debug last year it suddenly stopped occurring which made it impossible to debug but I actually experienced it earlier this week again. The difference from last year is that now I only get the error for a few seconds and then it works for me again.