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

Set Time on vivofit [not really an issue more a question] #130

Closed balu- closed 9 years ago

balu- commented 9 years ago

At first, thanks for all the work. I'm using antfs-cli to get the .fit files of my vivofit like a charm (and thereby freed it from the garmin cloud ;) ).

But today i ran into kind of a problem: Cause by the change to daylight savings time i need change the time on my vivofit. Has anyone any Idea how changing the time could be done? or what i can try to find it out ?

[my guess would be that the settings are somehow mapped to the file system, but i'm new to all this]

balu- commented 9 years ago

By accident i kind of found the solution to my problem, Can be found here https://github.com/balu-/antfs-cli/commit/e7b70aa8fe882bf8da52c8d3151662ffd36c1b5d

Had to modify openant for this to work (https://github.com/balu-/openant/commit/85e896927f64f25374981045152d7114dd0a4929).

Don't know whether this is in anyway conform with the standard, but i would really appriciate if anyone with expierience can take a look at it so that maybe one day the changes can go upstream :wink:

Tigge commented 9 years ago

Very good! I only have a Garmin Forerunner and it seems it doesn't support either setting or getting the time. I've pushed some modification of your commit to https://github.com/Tigge/openant/commit/7a76eb99a496677dc738d5a37085683ae4b522f2 on the https://github.com/Tigge/openant/tree/time branch.

@balu- could you try with this commit on the openant side? I'm interested in two things here:

  1. What is the response to a time request, i.e. self._send_commandpipe(Request(CommandPipe.Type.TIME))? I'm wondering if the vivofit just returns a structure identical to the Time command that is being sent or if it comes in form of a Response with additional data.
  2. Do setting the time work with this code as well?

But yes, using the command pipe to set time is how this would be done. In addition to this it would probably be good to add in some ANT-FS to python date conversions in the Application.

balu- commented 9 years ago

hi @Tigge Thanks for taking the time. to 1. I didn't get your exact statement to work (it resulted in this [1]). But i grabbed the Result of setting the time, in commandpipe-parse function (don't know if that helps) [2].

to 2.it worked, but i had to change the assert (see https://github.com/Tigge/openant/pull/11)

[1]

Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/antfs_cli-0.2-py2.7.egg/antfs_cli/program.py", line 357, in main
    g.start()
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 212, in start
    self._main()
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 150, in _main
    self.on_transport(beacon)
  File "/usr/local/lib/python2.7/dist-packages/antfs_cli-0.2-py2.7.egg/antfs_cli/program.py", line 194, in on_transport
    print("request", self._send_commandpipe(Request(CommandPipe.Type.TIME)))
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 219, in _send_commandpipe
    self.upload(0xfffe, data)
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 256, in upload
    self._send_command(UploadRequest(index, len(data), request_offset))
TypeError: object of type 'Request' has no len()
Interrupted: object of type 'Request' has no len()

[2]

Request:
 x = datetime.datetime.utcnow() - datetime.datetime(1989, 12, 31, 0, 0, 0)
   t = Time(int(x.total_seconds()), 0xffffffff, 0)
  self._send_commandpipe(t.get())

Data:
array('B', [2, 0, 0, 0, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0])
Tigge commented 9 years ago

Ops, for [1] I meant self._send_commandpipe(Request(CommandPipe.Type.TIME).get()). It might not be correctly parsed but I would be interested in what comes into the commandpipe.parse function. A simple print at the start of the function should do the trick. That would also be interesting for [2] to see why it triggers that assert.

balu- commented 9 years ago

seems like not supported or something

Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/antfs_cli-0.2-py2.7.egg/antfs_cli/program.py", line 357, in main
    g.start()
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 212, in start
    self._main()
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 150, in _main
    self.on_transport(beacon)
  File "/usr/local/lib/python2.7/dist-packages/antfs_cli-0.2-py2.7.egg/antfs_cli/program.py", line 194, in on_transport
    print("request", self._send_commandpipe(Request(CommandPipe.Type.TIME).get()))
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 219, in _send_commandpipe
    self.upload(0xfffe, data)
  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 287, in upload
    upload_data_response._get_argument("response"))
AntFSUploadException: ('Upload data failed', 1)
Tigge commented 9 years ago

Hm, might have been a temporary error? It should not fail like that even if it is not supported. The 1 there indicate a "Data Upload Failed" error, so it is probably a temporary transmission error.

        self._send_commandpipe(Request(CommandPipe.Type.TIME).get())
        result = self._get_commandpipe()

I'm using this and get a Response object back with get_response() == Response.Response.NOT_SUPPORTED.

balu- commented 9 years ago

Tried it multiple times, same result

AntFSUploadException: ('Upload data failed', 1)

Tigge commented 9 years ago

Odd, but things might differ between models I guess. Perhaps some more logging could shed some light on this. Do you have full logs from openant saved?

balu- commented 9 years ago

I have (also this might not be the perfect place for a log, here it comes)

MainThread 2015-03-31 17:53:52,072  ant.base.driver   DEBUG     USB Find device, vendor 0xfcf, product 0x1009 (driver.py:158)
MainThread 2015-03-31 17:53:52,093  ant.base.driver   DEBUG     USB Config values: (driver.py:165)
MainThread 2015-03-31 17:53:52,098  ant.base.driver   DEBUG      Config 1 (driver.py:167)
MainThread 2015-03-31 17:53:52,103  ant.base.driver   DEBUG       Interface 0, Alt 0 (driver.py:169)
MainThread 2015-03-31 17:53:52,108  ant.base.driver   DEBUG        Endpoint 129 (driver.py:171)
MainThread 2015-03-31 17:53:52,113  ant.base.driver   DEBUG        Endpoint 1 (driver.py:171)
MainThread 2015-03-31 17:53:52,119  ant.base.driver   DEBUG     No kernel driver active (driver.py:179)
MainThread 2015-03-31 17:53:52,343  ant.base.driver   DEBUG     UBS Endpoint out:       ENDPOINT 0x1: Bulk OUT ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x1 OUT
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :   0x40 (64 bytes)
       bInterval        :    0x1, 1 (driver.py:207)
MainThread 2015-03-31 17:53:52,349  ant.base.driver   DEBUG     UBS Endpoint in:       ENDPOINT 0x81: Bulk IN ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x81 IN
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :   0x40 (64 bytes)
       bInterval        :    0x1, 129 (driver.py:218)
ant.base   2015-03-31 17:53:52,362  ant.base.ant      DEBUG     Ant runner started (ant.py:112)
MainThread 2015-03-31 17:53:52,376  ant.base.ant      DEBUG     Write data: [a4 01 4a 00 ef] (ant.py:212)
ant.base   2015-03-31 17:53:52,380  ant.base.ant      DEBUG     Read data: [a4 01 6f 20 ea] (now have [a4 01 6f 20 ea] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:53,387  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
MainThread 2015-03-31 17:53:53,391  ant.base.ant      DEBUG     Write data: [a4 09 46 00 a8 a4 23 b9 f5 5e 63 c1 74] (ant.py:212)
MainThread 2015-03-31 17:53:53,397  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,402  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
ant.base   2015-03-31 17:53:53,401  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:227)
MainThread 2015-03-31 17:53:53,411  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15620f0> (filter.py:58)
MainThread 2015-03-31 17:53:53,419  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 70, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,423  ant.easy.filter   DEBUG      - response found (0, 70, array('B', [0])) (filter.py:47)
MainThread 2015-03-31 17:53:53,428  ant.easy.node     DEBUG     requesting message 0x54 (node.py:71)
ant.base   2015-03-31 17:53:53,435  ant.base.ant      DEBUG     Read data: [a4 07 54 08 08 00 ba 36 00 df a4] (now have [a4 07 54 08 08 00 ba 36 00 df a4] in buffer) (ant.py:227)
MainThread 2015-03-31 17:53:53,441  ant.base.ant      DEBUG     Write data: [a4 02 4d 00 54 bf] (ant.py:212)
MainThread 2015-03-31 17:53:53,444  ant.easy.node     DEBUG     done requesting message 0x54 (node.py:73)
MainThread 2015-03-31 17:53:53,447  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,451  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,454  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15620f0> (filter.py:58)
MainThread 2015-03-31 17:53:53,461  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (None, 84, array('B', [8, 8, 0, 186, 54, 0, 223]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,469  ant.easy.filter   DEBUG      - response found (None, 84, array('B', [8, 8, 0, 186, 54, 0, 223])) (filter.py:47)
ant.base   2015-03-31 17:53:53,484  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:227)
MainThread 2015-03-31 17:53:53,490  ant.base.ant      DEBUG     Write data: [a4 03 42 00 00 00 e5] (ant.py:212)
MainThread 2015-03-31 17:53:53,495  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,500  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 66, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,504  ant.easy.filter   DEBUG      - response found (0, 66, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:53:53,512  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:227)
MainThread 2015-03-31 17:53:53,516  ant.base.ant      DEBUG     Write data: [a4 03 43 00 00 10 f4] (ant.py:212)
MainThread 2015-03-31 17:53:53,522  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,525  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,529  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15620f0> (filter.py:58)
MainThread 2015-03-31 17:53:53,534  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 67, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,539  ant.easy.filter   DEBUG      - response found (0, 67, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:53:53,546  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:227)
MainThread 2015-03-31 17:53:53,545  ant.base.ant      DEBUG     Write data: [a4 02 44 00 ff 1d] (ant.py:212)
MainThread 2015-03-31 17:53:53,555  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,559  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 68, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,563  ant.easy.filter   DEBUG      - response found (0, 68, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:53:53,571  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:227)
MainThread 2015-03-31 17:53:53,569  ant.base.ant      DEBUG     Write data: [a4 02 45 00 32 d1] (ant.py:212)
MainThread 2015-03-31 17:53:53,580  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,585  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,591  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15620f0> (filter.py:58)
MainThread 2015-03-31 17:53:53,599  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 69, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,605  ant.easy.filter   DEBUG      - response found (0, 69, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:53:53,613  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:227)
MainThread 2015-03-31 17:53:53,612  ant.base.ant      DEBUG     Write data: [a4 03 49 00 53 00 bd] (ant.py:212)
MainThread 2015-03-31 17:53:53,622  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,625  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,630  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15620f0> (filter.py:58)
MainThread 2015-03-31 17:53:53,635  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 73, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,639  ant.easy.filter   DEBUG      - response found (0, 73, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:53:53,647  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:227)
MainThread 2015-03-31 17:53:53,646  ant.base.ant      DEBUG     Write data: [a4 05 51 00 00 00 01 00 f1] (ant.py:212)
MainThread 2015-03-31 17:53:53,657  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,661  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 81, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,665  ant.easy.filter   DEBUG      - response found (0, 81, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:53:53,672  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:227)
MainThread 2015-03-31 17:53:53,671  ant.base.ant      DEBUG     Write data: [a4 01 4b 00 ee] (ant.py:212)
MainThread 2015-03-31 17:53:53,681  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15620f0> (filter.py:40)
MainThread 2015-03-31 17:53:53,687  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,691  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15620f0> (filter.py:58)
MainThread 2015-03-31 17:53:53,697  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 75, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:53:53,704  ant.easy.filter   DEBUG      - response found (0, 75, array('B', [0])) (filter.py:47)
MainThread 2015-03-31 17:53:53,849  ant.fs.manager    DEBUG     Link level (manager.py:140)
ant.base   2015-03-31 17:53:54,677  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-03-31 17:53:55,683  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-03-31 17:53:56,688  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-03-31 17:53:57,693  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-03-31 17:53:58,697  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-03-31 17:53:59,263  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
MainThread 2015-03-31 17:53:59,291  root              DEBUG     on link, 67373, (1837, 1) (program.py:158)
MainThread 2015-03-31 17:53:59,294  ant.easy.channel  DEBUG     requesting message 0x51 (channel.py:91)
MainThread 2015-03-31 17:53:59,300  ant.base.ant      DEBUG     Write data: [a4 02 4d 00 51 ba] (ant.py:212)
MainThread 2015-03-31 17:53:59,304  ant.easy.channel  DEBUG     done requesting message 0x51 (channel.py:93)
MainThread 2015-03-31 17:53:59,307  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bcef0> (filter.py:40)
MainThread 2015-03-31 17:53:59,310  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-03-31 17:53:59,314  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15bcef0> (filter.py:58)
ant.base   2015-03-31 17:53:59,367  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:53:59,372  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:53:59,377  ant.base.ant      DEBUG     Read data: [a4 05 51 00 21 0b 01 05 de] (now have [a4 05 51 00 21 0b 01 05 de] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:59,386  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:59,390  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-03-31 17:53:59,432  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 81, array('B', [33, 11, 1, 5]))]) (filter.py:43)
MainThread 2015-03-31 17:53:59,437  ant.easy.filter   DEBUG      - response found (0, 81, array('B', [33, 11, 1, 5])) (filter.py:47)
MainThread 2015-03-31 17:53:59,444  ant.fs.command    DEBUG     packing 'D\x02\x13\x049\x05\x00\x00' in array('B', [68, 2, 19, 4, 57, 5, 0, 0]),<type 'array.array'> (command.py:79)
MainThread 2015-03-31 17:53:59,448  ant.easy.channel  DEBUG     send acknowledged data 0 (channel.py:98)
MainThread 2015-03-31 17:53:59,452  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6d4bd70> (filter.py:40)
MainThread 2015-03-31 17:53:59,459  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-03-31 17:53:59,463  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6d4bd70> (filter.py:58)
ant.base   2015-03-31 17:53:59,512  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:59,616  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:53:59,621  ant.base.ant      DEBUG     Write data: [a4 09 4f 00 44 02 13 04 39 05 00 00 8f] (ant.py:212)
ant.base   2015-03-31 17:53:59,624  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 4f:[00 44 02 13 04 39 05 00 00] (s:a4, l:9, c:8f)> (ant.py:173)
ant.base   2015-03-31 17:53:59,637  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:59,641  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-03-31 17:53:59,734  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-03-31 17:53:59,738  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6d4bd70> (filter.py:58)
ant.base   2015-03-31 17:53:59,763  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:59,867  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:53:59,870  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:53:59,875  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 06 e0] (now have [a4 03 40 00 01 06 e0] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:59,878  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 06] (s:a4, l:3, c:e0)> (ant.py:157)
ant.base   2015-03-31 17:53:59,887  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-03-31 17:53:59,890  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-03-31 17:53:59,958  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [6])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-03-31 17:53:59,965  ant.easy.filter   WARNING   Transfer send failed: (filter.py:53)
MainThread 2015-03-31 17:53:59,972  ant.easy.filter   WARNING   (0, 1, array('B', [6])) (filter.py:54)
MainThread 2015-03-31 17:53:59,976  ant.easy.channel  WARNING   failed to send acknowledged data 0, retrying (channel.py:103)
MainThread 2015-03-31 17:53:59,980  ant.easy.channel  DEBUG     send acknowledged data 0 (channel.py:98)
MainThread 2015-03-31 17:53:59,984  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bcf70> (filter.py:40)
MainThread 2015-03-31 17:53:59,989  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-03-31 17:53:59,995  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15bcf70> (filter.py:58)
ant.base   2015-03-31 17:54:00,013  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,117  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:00,123  ant.base.ant      DEBUG     Write data: [a4 09 4f 00 44 02 13 04 39 05 00 00 8f] (ant.py:212)
ant.base   2015-03-31 17:54:00,126  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 4f:[00 44 02 13 04 39 05 00 00] (s:a4, l:9, c:8f)> (ant.py:173)
ant.base   2015-03-31 17:54:00,136  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,140  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-03-31 17:54:00,167  ant.easy.filter   DEBUG     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]))]) (filter.py:43)
MainThread 2015-03-31 17:54:00,172  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15bcf70> (filter.py:58)
ant.base   2015-03-31 17:54:00,262  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,367  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:00,370  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:00,375  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,379  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-03-31 17:54:00,387  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,391  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-03-31 17:54:00,441  ant.easy.filter   DEBUG     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', [5])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-03-31 17:54:00,446  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-03-31 17:54:00,449  ant.easy.channel  DEBUG     done sending acknowledged data 0 (channel.py:101)
ant.base   2015-03-31 17:54:00,457  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:227)
MainThread 2015-03-31 17:54:00,462  ant.base.ant      DEBUG     Write data: [a4 03 43 00 00 10 f4] (ant.py:212)
MainThread 2015-03-31 17:54:00,468  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6d4bd70> (filter.py:40)
MainThread 2015-03-31 17:54:00,473  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 67, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:54:00,477  ant.easy.filter   DEBUG      - response found (0, 67, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:54:00,484  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:227)
MainThread 2015-03-31 17:54:00,489  ant.base.ant      DEBUG     Write data: [a4 02 44 00 03 e1] (ant.py:212)
MainThread 2015-03-31 17:54:00,494  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6d4bd70> (filter.py:40)
MainThread 2015-03-31 17:54:00,498  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-03-31 17:54:00,502  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6d4bd70> (filter.py:58)
MainThread 2015-03-31 17:54:00,507  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 68, array('B', [0]))]) (filter.py:43)
ant.base   2015-03-31 17:54:00,512  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,516  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-03-31 17:54:00,517  ant.easy.filter   DEBUG      - response found (0, 68, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:54:00,528  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:227)
MainThread 2015-03-31 17:54:00,525  ant.base.ant      DEBUG     Write data: [a4 02 45 00 13 f0] (ant.py:212)
MainThread 2015-03-31 17:54:00,537  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6d4bd70> (filter.py:40)
MainThread 2015-03-31 17:54:00,544  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 69, array('B', [0]))]) (filter.py:43)
MainThread 2015-03-31 17:54:00,549  ant.easy.filter   DEBUG      - response found (0, 69, array('B', [0])) (filter.py:47)
ant.base   2015-03-31 17:54:00,637  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
MainThread 2015-03-31 17:54:00,692  ant.fs.manager    DEBUG     Auth layer (manager.py:146)
MainThread 2015-03-31 17:54:00,696  root              DEBUG     on authentication (program.py:163)
MainThread 2015-03-31 17:54:00,701  ant.easy.channel  DEBUG     send acknowledged data 0 (channel.py:98)
MainThread 2015-03-31 17:54:00,704  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6d4bd70> (filter.py:40)
MainThread 2015-03-31 17:54:00,708  ant.easy.filter   DEBUG     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]))]) (filter.py:43)
MainThread 2015-03-31 17:54:00,712  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6d4bd70> (filter.py:58)
ant.base   2015-03-31 17:54:00,742  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:00,749  ant.base.ant      DEBUG     Write data: [a4 09 4f 00 44 04 01 00 39 05 00 00 9f] (ant.py:212)
ant.base   2015-03-31 17:54:00,753  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 4f:[00 44 04 01 00 39 05 00 00] (s:a4, l:9, c:9f)> (ant.py:173)
ant.base   2015-03-31 17:54:00,763  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,768  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:00,871  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:00,874  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:00,880  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,883  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-03-31 17:54:00,889  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,897  ant.base.ant      DEBUG     Read data: [a4 09 50 20 44 84 00 10 21 0b 1c e8 d3] (now have [a4 09 50 20 44 84 00 10 21 0b 1c e8 d3] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,903  ant.base.ant      DEBUG     Read data: [a4 09 50 40 76 c3 ad 76 6f 66 69 74 c7] (now have [a4 09 50 40 76 c3 ad 76 6f 66 69 74 c7] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:00,909  ant.base.ant      DEBUG     Read data: [a4 09 50 e0 00 00 00 00 00 00 00 00 1d] (now have [a4 09 50 e0 00 00 00 00 00 00 00 00 1d] in buffer) (ant.py:227)
MainThread 2015-03-31 17:54:00,933  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-03-31 17:54:00,938  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-03-31 17:54:00,942  ant.easy.channel  DEBUG     done sending acknowledged data 0 (channel.py:101)
MainThread 2015-03-31 17:54:00,946  ant.fs.manager    DEBUG     Get command, t15, s0 (manager.py:180)
ant.fs     2015-03-31 17:54:00,960  ant.fs.command    DEBUG     parsing data array('B', [68, 132, 0, 16, 33, 11, 28, 232, 118, 195, 173, 118, 111, 102, 105, 116, 0, 0, 0, 0, 0, 0, 0, 0]) (command.py:363)
ant.base   2015-03-31 17:54:01,012  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,116  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:01,122  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:01,137  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,142  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:01,248  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:01,251  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:01,262  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,271  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:01,375  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:01,378  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:01,387  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,391  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:01,494  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:01,499  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:01,512  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,515  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:01,619  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:01,622  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:01,638  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,641  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:01,746  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:01,750  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:01,762  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,766  ant.base.ant      DEBUG     No new data this period (ant.py:163)
MainThread 2015-03-31 17:54:01,784  root              DEBUG     loaded authfile: array('B', [154, 81, 61, 149, 39, 52, 165, 170]) (program.py:116)
MainThread 2015-03-31 17:54:01,791  root              DEBUG     serial vívofit, 3894151969L, array('B', [154, 81, 61, 149, 39, 52, 165, 170]) (program.py:169)
MainThread 2015-03-31 17:54:01,798  ant.easy.channel  DEBUG     send burst transfer 0 (channel.py:112)
MainThread 2015-03-31 17:54:01,802  ant.base.ant      DEBUG     Send burst transfer, chan 0, data array('B', [68, 4, 3, 8, 57, 5, 0, 0, 154, 81, 61, 149, 39, 52, 165, 170]) (ant.py:294)
MainThread 2015-03-31 17:54:01,807  ant.base.ant      DEBUG     Send burst transfer, packet 0, seq 0, data array('B', [68, 4, 3, 8, 57, 5, 0, 0]) (ant.py:304)
MainThread 2015-03-31 17:54:01,811  ant.base.ant      DEBUG     Send burst transfer, packet 1, seq 5, data array('B', [154, 81, 61, 149, 39, 52, 165, 170]) (ant.py:304)
MainThread 2015-03-31 17:54:01,815  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bc9f0> (filter.py:40)
MainThread 2015-03-31 17:54:01,818  ant.easy.filter   DEBUG     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]))]) (filter.py:43)
MainThread 2015-03-31 17:54:01,823  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15bc9f0> (filter.py:58)
ant.base   2015-03-31 17:54:01,870  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:01,875  ant.base.ant      DEBUG     Write data: [a4 09 50 00 44 04 03 08 39 05 00 00 8a] (ant.py:212)
ant.base   2015-03-31 17:54:01,878  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[00 44 04 03 08 39 05 00 00] (s:a4, l:9, c:8a)> (ant.py:173)
ant.base   2015-03-31 17:54:01,885  ant.base.ant      DEBUG     Write data: [a4 09 50 a0 9a 51 3d 95 27 34 a5 aa 22] (ant.py:212)
ant.base   2015-03-31 17:54:01,888  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[a0 9a 51 3d 95 27 34 a5 aa] (s:a4, l:9, c:22)> (ant.py:173)
ant.base   2015-03-31 17:54:01,897  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:01,902  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:02,008  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:02,011  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:02,017  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,020  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)> (ant.py:157)
ant.base   2015-03-31 17:54:02,025  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-03-31 17:54:02,032  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,038  ant.base.ant      DEBUG     Read data: [a4 09 50 a0 44 84 01 00 21 0b 1c e8 42] (now have [a4 09 50 a0 44 84 01 00 21 0b 1c e8 42] in buffer) (ant.py:227)
ant.fs     2015-03-31 17:54:02,062  ant.fs.command    DEBUG     parsing data array('B', [68, 132, 1, 0, 33, 11, 28, 232]) (command.py:363)
MainThread 2015-03-31 17:54:02,092  ant.easy.filter   DEBUG     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', [10])), (0, 1, array('B', [5]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,097  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [10])) (filter.py:47)
MainThread 2015-03-31 17:54:02,101  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bcef0> (filter.py:40)
MainThread 2015-03-31 17:54:02,105  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,109  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-03-31 17:54:02,113  ant.easy.channel  DEBUG     done sending burst transfer 0 (channel.py:116)
MainThread 2015-03-31 17:54:02,117  ant.fs.manager    DEBUG     Get command, t15, s1 (manager.py:180)
MainThread 2015-03-31 17:54:02,123  ant.fs.manager    DEBUG     Authenticated (manager.py:148)
MainThread 2015-03-31 17:54:02,128  ant.fs.commandpipe  DEBUG     packing '\x01\x00\x00\x01\x03\x00\x00\x00' in array('B', [1, 0, 0, 1, 3, 0, 0, 0]),<type 'array.array'> (commandpipe.py:78)
MainThread 2015-03-31 17:54:02,134  ant.fs.command    DEBUG     packing 'D\n\xfe\xff\x08\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' in array('B', [68, 10, 254, 255, 8, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]),<type 'array.array'> (command.py:79)
ant.base   2015-03-31 17:54:02,137  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
MainThread 2015-03-31 17:54:02,144  ant.easy.channel  DEBUG     send burst transfer 0 (channel.py:112)
MainThread 2015-03-31 17:54:02,146  ant.base.ant      DEBUG     Send burst transfer, chan 0, data array('B', [68, 10, 254, 255, 8, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]) (ant.py:294)
MainThread 2015-03-31 17:54:02,149  ant.base.ant      DEBUG     Send burst transfer, packet 0, seq 0, data array('B', [68, 10, 254, 255, 8, 0, 0, 0]) (ant.py:304)
MainThread 2015-03-31 17:54:02,155  ant.base.ant      DEBUG     Send burst transfer, packet 1, seq 5, data array('B', [0, 0, 0, 0, 0, 0, 0, 0]) (ant.py:304)
MainThread 2015-03-31 17:54:02,160  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bcf70> (filter.py:40)
MainThread 2015-03-31 17:54:02,164  ant.easy.filter   DEBUG     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]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,171  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15bcf70> (filter.py:58)
ant.base   2015-03-31 17:54:02,244  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:02,249  ant.base.ant      DEBUG     Write data: [a4 09 50 00 44 0a fe ff 08 00 00 00 ba] (ant.py:212)
ant.base   2015-03-31 17:54:02,252  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[00 44 0a fe ff 08 00 00 00] (s:a4, l:9, c:ba)> (ant.py:173)
ant.base   2015-03-31 17:54:02,258  ant.base.ant      DEBUG     Write data: [a4 09 50 a0 00 00 00 00 00 00 00 00 5d] (ant.py:212)
ant.base   2015-03-31 17:54:02,261  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[a0 00 00 00 00 00 00 00 00] (s:a4, l:9, c:5d)> (ant.py:173)
ant.base   2015-03-31 17:54:02,267  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,271  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-03-31 17:54:02,374  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:02,377  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:02,382  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 0a ec] (now have [a4 03 40 00 01 0a ec] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,386  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)> (ant.py:157)
ant.base   2015-03-31 17:54:02,392  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,396  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-03-31 17:54:02,403  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5 a4 09 50 20 44 8a 00 00 00 00 00 00 13] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5 a4 09 50 20 44 8a 00 00 00 00 00 00 13] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,410  ant.base.ant      DEBUG     Read data: [a4 09 50 40 10 00 00 00 10 00 00 00 bd a4 09 50 e0 00 00 00 00 00 00 00 00 1d] (now have [a4 09 50 40 10 00 00 00 10 00 00 00 bd a4 09 50 e0 00 00 00 00 00 00 00 00 1d] in buffer) (ant.py:227)
MainThread 2015-03-31 17:54:02,442  ant.easy.filter   DEBUG     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', [10])), (0, 1, array('B', [5]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,447  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [10])) (filter.py:47)
MainThread 2015-03-31 17:54:02,451  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bcef0> (filter.py:40)
ant.fs     2015-03-31 17:54:02,455  ant.fs.command    DEBUG     parsing data array('B', [68, 138, 0, 0, 0, 0, 0, 0, 16, 0, 0, 0, 16, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]) (command.py:363)
MainThread 2015-03-31 17:54:02,462  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,466  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-03-31 17:54:02,473  ant.easy.channel  DEBUG     done sending burst transfer 0 (channel.py:116)
MainThread 2015-03-31 17:54:02,478  ant.fs.manager    DEBUG     Get command, t15, s1 (manager.py:180)
MainThread 2015-03-31 17:54:02,490  ant.easy.channel  DEBUG     send burst transfer 0 (channel.py:112)
MainThread 2015-03-31 17:54:02,494  ant.base.ant      DEBUG     Send burst transfer, chan 0, data array('B', [68, 12, 0, 0, 0, 0, 0, 0, 1, 0, 0, 1, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 252, 72]) (ant.py:294)
MainThread 2015-03-31 17:54:02,498  ant.base.ant      DEBUG     Send burst transfer, packet 0, seq 0, data array('B', [68, 12, 0, 0, 0, 0, 0, 0]) (ant.py:304)
MainThread 2015-03-31 17:54:02,504  ant.base.ant      DEBUG     Send burst transfer, packet 1, seq 1, data array('B', [1, 0, 0, 1, 3, 0, 0, 0]) (ant.py:304)
MainThread 2015-03-31 17:54:02,509  ant.base.ant      DEBUG     Send burst transfer, packet 2, seq 6, data array('B', [0, 0, 0, 0, 0, 0, 252, 72]) (ant.py:304)
ant.base   2015-03-31 17:54:02,514  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 00 00 00 00 00 00 00 00 e3] (now have [a4 09 4e 00 00 00 00 00 00 00 00 00 e3] in buffer) (ant.py:227)
MainThread 2015-03-31 17:54:02,518  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bcef0> (filter.py:40)
MainThread 2015-03-31 17:54:02,522  ant.easy.filter   DEBUG     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]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,527  ant.easy.filter   DEBUG      - could not find response matching <function match at 0x15bcef0> (filter.py:58)
ant.base   2015-03-31 17:54:02,618  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:02,623  ant.base.ant      DEBUG     Write data: [a4 09 50 00 44 0c 00 00 00 00 00 00 b5] (ant.py:212)
ant.base   2015-03-31 17:54:02,627  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[00 44 0c 00 00 00 00 00 00] (s:a4, l:9, c:b5)> (ant.py:173)
ant.base   2015-03-31 17:54:02,632  ant.base.ant      DEBUG     Write data: [a4 09 50 20 01 00 00 01 03 00 00 00 de] (ant.py:212)
ant.base   2015-03-31 17:54:02,635  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[20 01 00 00 01 03 00 00 00] (s:a4, l:9, c:de)> (ant.py:173)
ant.base   2015-03-31 17:54:02,642  ant.base.ant      DEBUG     Write data: [a4 09 50 c0 00 00 00 00 00 00 fc 48 89] (ant.py:212)
ant.base   2015-03-31 17:54:02,646  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[c0 00 00 00 00 00 00 fc 48] (s:a4, l:9, c:89)> (ant.py:173)
ant.base   2015-03-31 17:54:02,653  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,758  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-03-31 17:54:02,762  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-03-31 17:54:02,767  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,771  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)> (ant.py:157)
ant.base   2015-03-31 17:54:02,775  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-03-31 17:54:02,781  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,787  ant.base.ant      DEBUG     Read data: [a4 09 50 a0 44 8c 01 00 00 00 00 00 94] (now have [a4 09 50 a0 44 8c 01 00 00 00 00 00 94] in buffer) (ant.py:227)
MainThread 2015-03-31 17:54:02,798  ant.easy.filter   DEBUG     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', [10])), (0, 1, array('B', [5]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,804  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [10])) (filter.py:47)
MainThread 2015-03-31 17:54:02,809  ant.easy.filter   DEBUG     wait for message matching <function match at 0x15bcfb0> (filter.py:40)
ant.fs     2015-03-31 17:54:02,814  ant.fs.command    DEBUG     parsing data array('B', [68, 140, 1, 0, 0, 0, 0, 0]) (command.py:363)
MainThread 2015-03-31 17:54:02,819  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-03-31 17:54:02,826  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-03-31 17:54:02,832  ant.easy.channel  DEBUG     done sending burst transfer 0 (channel.py:116)
MainThread 2015-03-31 17:54:02,837  ant.fs.manager    DEBUG     Get command, t15, s1 (manager.py:180)
MainThread 2015-03-31 17:54:02,841  ant.fs.manager    DEBUG     Run 5 (manager.py:154)
MainThread 2015-03-31 17:54:02,845  ant.easy.node     DEBUG     Stoping ant.easy (node.py:133)
MainThread 2015-03-31 17:54:02,849  ant.base.ant      DEBUG     Stoping ant.base (ant.py:80)
ant.base   2015-03-31 17:54:02,887  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
ant.base   2015-03-31 17:54:02,890  ant.base.ant      DEBUG     Ant runner stopped (ant.py:187)
MainThread 2015-03-31 17:54:03,831  root              ERROR     'Traceback (most recent call last):' (program.py:370)
MainThread 2015-03-31 17:54:03,835  root              ERROR     '  File "/usr/local/lib/python2.7/dist-packages/antfs_cli-0.2-py2.7.egg/antfs_cli/program.py", line 357, in main' (program.py:370)
MainThread 2015-03-31 17:54:03,838  root              ERROR     '    g.start()' (program.py:370)
MainThread 2015-03-31 17:54:03,842  root              ERROR     '  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 212, in start' (program.py:370)
MainThread 2015-03-31 17:54:03,845  root              ERROR     '    self._main()' (program.py:370)
MainThread 2015-03-31 17:54:03,848  root              ERROR     '  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 150, in _main' (program.py:370)
MainThread 2015-03-31 17:54:03,852  root              ERROR     '    self.on_transport(beacon)' (program.py:370)
MainThread 2015-03-31 17:54:03,855  root              ERROR     '  File "/usr/local/lib/python2.7/dist-packages/antfs_cli-0.2-py2.7.egg/antfs_cli/program.py", line 194, in on_transport' (program.py:370)
MainThread 2015-03-31 17:54:03,859  root              ERROR     '    print("request", self._send_commandpipe(Request(CommandPipe.Type.TIME).get()))' (program.py:370)
MainThread 2015-03-31 17:54:03,864  root              ERROR     '  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 219, in _send_commandpipe' (program.py:370)
MainThread 2015-03-31 17:54:03,867  root              ERROR     '    self.upload(0xfffe, data)' (program.py:370)
MainThread 2015-03-31 17:54:03,871  root              ERROR     '  File "/usr/local/lib/python2.7/dist-packages/ant/fs/manager.py", line 287, in upload' (program.py:370)
MainThread 2015-03-31 17:54:03,874  root              ERROR     '    upload_data_response._get_argument("response"))' (program.py:370)
MainThread 2015-03-31 17:54:03,877  root              ERROR     "AntFSUploadException: ('Upload data failed', 1)" (program.py:370)
Tigge commented 9 years ago

@balu- Thank you very much! I can't see anything wrong here really. I've asked for some clarification on how this should work in the ANT+ forums http://www.thisisant.com/forum/viewthread/4618/. We'll see if I get any responses there. But let's skip that part until that is figured out.

Is it possible to get a log like this for the other case as well? Setting the time and the response to that that triggered that assert? Hopefully it is a simple fix and something I've missed. I think it would be great to get that pull request in, very useful for Vivofit users, and I think I've seen the garmin ant agent trying to do this as well.

balu- commented 9 years ago

I'm just wildly guessing here, but i think it has to do with the change of line 194 link. Caused by this, the type of the response is no longer of Type '2'(Response) as sugested by the first byte of data, but its Type '3' (Time).

But here goes the log part, (hope i haven't cut it to soon)

MainThread 2015-04-03 19:20:53,588  ant.base.driver   DEBUG     USB Find device, vendor 0xfcf, product 0x1009 (driver.py:158)
MainThread 2015-04-03 19:20:53,609  ant.base.driver   DEBUG     USB Config values: (driver.py:165)
MainThread 2015-04-03 19:20:53,615  ant.base.driver   DEBUG      Config 1 (driver.py:167)
MainThread 2015-04-03 19:20:53,620  ant.base.driver   DEBUG       Interface 0, Alt 0 (driver.py:169)
MainThread 2015-04-03 19:20:53,626  ant.base.driver   DEBUG        Endpoint 129 (driver.py:171)
MainThread 2015-04-03 19:20:53,631  ant.base.driver   DEBUG        Endpoint 1 (driver.py:171)
MainThread 2015-04-03 19:20:53,636  ant.base.driver   DEBUG     No kernel driver active (driver.py:179)
MainThread 2015-04-03 19:20:53,843  ant.base.driver   DEBUG     UBS Endpoint out:       ENDPOINT 0x1: Bulk OUT ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :    0x1 OUT
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :   0x40 (64 bytes)
       bInterval        :    0x1, 1 (driver.py:207)
MainThread 2015-04-03 19:20:53,849  ant.base.driver   DEBUG     UBS Endpoint in:       ENDPOINT 0x81: Bulk IN ===============================
       bLength          :    0x7 (7 bytes)
       bDescriptorType  :    0x5 Endpoint
       bEndpointAddress :   0x81 IN
       bmAttributes     :    0x2 Bulk
       wMaxPacketSize   :   0x40 (64 bytes)
       bInterval        :    0x1, 129 (driver.py:218)
ant.base   2015-04-03 19:20:53,862  ant.base.ant      DEBUG     Ant runner started (ant.py:112)
MainThread 2015-04-03 19:20:53,877  ant.base.ant      DEBUG     Write data: [a4 01 4a 00 ef] (ant.py:212)
ant.base   2015-04-03 19:20:53,881  ant.base.ant      DEBUG     Read data: [a4 01 6f 20 ea] (now have [a4 01 6f 20 ea] in buffer) (ant.py:227)
ant.base   2015-04-03 19:20:54,888  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
MainThread 2015-04-03 19:20:54,894  ant.base.ant      DEBUG     Write data: [a4 09 46 00 a8 a4 23 b9 f5 5e 63 c1 74] (ant.py:212)
MainThread 2015-04-03 19:20:54,902  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
ant.base   2015-04-03 19:20:54,900  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:227)
MainThread 2015-04-03 19:20:54,912  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 70, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:54,917  ant.easy.filter   DEBUG      - response found (0, 70, array('B', [0])) (filter.py:47)
MainThread 2015-04-03 19:20:54,923  ant.easy.node     DEBUG     requesting message 0x54 (node.py:71)
ant.base   2015-04-03 19:20:54,932  ant.base.ant      DEBUG     Read data: [a4 07 54 08 08 00 ba 36 00 df a4] (now have [a4 07 54 08 08 00 ba 36 00 df a4] in buffer) (ant.py:227)
MainThread 2015-04-03 19:20:54,939  ant.base.ant      DEBUG     Write data: [a4 02 4d 00 54 bf] (ant.py:212)
MainThread 2015-04-03 19:20:54,944  ant.easy.node     DEBUG     done requesting message 0x54 (node.py:73)
MainThread 2015-04-03 19:20:54,948  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:54,953  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (None, 84, array('B', [8, 8, 0, 186, 54, 0, 223]))]) (filter.py:43)
MainThread 2015-04-03 19:20:54,957  ant.easy.filter   DEBUG      - response found (None, 84, array('B', [8, 8, 0, 186, 54, 0, 223])) (filter.py:47)
ant.base   2015-04-03 19:20:54,970  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:227)
MainThread 2015-04-03 19:20:54,975  ant.base.ant      DEBUG     Write data: [a4 03 42 00 00 00 e5] (ant.py:212)
MainThread 2015-04-03 19:20:54,978  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:54,983  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 66, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:54,988  ant.easy.filter   DEBUG      - response found (0, 66, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:20:54,996  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:227)
MainThread 2015-04-03 19:20:54,994  ant.base.ant      DEBUG     Write data: [a4 03 43 00 00 10 f4] (ant.py:212)
MainThread 2015-04-03 19:20:55,004  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:55,008  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,012  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb68a30f0> (filter.py:58)
MainThread 2015-04-03 19:20:55,017  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 67, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,022  ant.easy.filter   DEBUG      - response found (0, 67, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:20:55,033  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:227)
MainThread 2015-04-03 19:20:55,030  ant.base.ant      DEBUG     Write data: [a4 02 44 00 ff 1d] (ant.py:212)
MainThread 2015-04-03 19:20:55,042  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:55,045  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,049  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb68a30f0> (filter.py:58)
MainThread 2015-04-03 19:20:55,056  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 68, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,060  ant.easy.filter   DEBUG      - response found (0, 68, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:20:55,068  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:227)
MainThread 2015-04-03 19:20:55,066  ant.base.ant      DEBUG     Write data: [a4 02 45 00 32 d1] (ant.py:212)
MainThread 2015-04-03 19:20:55,076  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:55,080  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 69, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,083  ant.easy.filter   DEBUG      - response found (0, 69, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:20:55,090  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:227)
MainThread 2015-04-03 19:20:55,096  ant.base.ant      DEBUG     Write data: [a4 03 49 00 53 00 bd] (ant.py:212)
MainThread 2015-04-03 19:20:55,100  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:55,105  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,110  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb68a30f0> (filter.py:58)
MainThread 2015-04-03 19:20:55,114  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 73, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,121  ant.easy.filter   DEBUG      - response found (0, 73, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:20:55,128  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:227)
MainThread 2015-04-03 19:20:55,135  ant.base.ant      DEBUG     Write data: [a4 05 51 00 00 00 01 00 f1] (ant.py:212)
MainThread 2015-04-03 19:20:55,140  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:55,144  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,149  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb68a30f0> (filter.py:58)
MainThread 2015-04-03 19:20:55,155  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 81, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,160  ant.easy.filter   DEBUG      - response found (0, 81, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:20:55,168  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:227)
MainThread 2015-04-03 19:20:55,174  ant.base.ant      DEBUG     Write data: [a4 01 4b 00 ee] (ant.py:212)
MainThread 2015-04-03 19:20:55,177  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb68a30f0> (filter.py:40)
MainThread 2015-04-03 19:20:55,182  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,187  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb68a30f0> (filter.py:58)
MainThread 2015-04-03 19:20:55,192  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 75, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:20:55,197  ant.easy.filter   DEBUG      - response found (0, 75, array('B', [0])) (filter.py:47)
MainThread 2015-04-03 19:20:55,356  ant.fs.manager    DEBUG     Link level (manager.py:140)
ant.base   2015-04-03 19:20:56,178  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:20:57,183  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:20:58,188  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:20:59,193  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:00,199  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:01,204  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:02,209  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:03,214  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:04,219  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:05,224  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:06,229  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:07,234  ant.base.ant      WARNING   <class 'usb.core.USBError'>, (110, 'Operation timed out') (ant.py:185)
ant.base   2015-04-03 19:21:07,628  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:07,707  root              DEBUG     on link, 67373, (1837, 1) (program.py:158)
MainThread 2015-04-03 19:21:07,711  ant.easy.channel  DEBUG     requesting message 0x51 (channel.py:91)
MainThread 2015-04-03 19:21:07,716  ant.base.ant      DEBUG     Write data: [a4 02 4d 00 51 ba] (ant.py:212)
MainThread 2015-04-03 19:21:07,721  ant.easy.channel  DEBUG     done requesting message 0x51 (channel.py:93)
MainThread 2015-04-03 19:21:07,724  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669ef0> (filter.py:40)
MainThread 2015-04-03 19:21:07,727  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-04-03 19:21:07,730  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6669ef0> (filter.py:58)
ant.base   2015-04-03 19:21:07,733  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:07,737  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:07,743  ant.base.ant      DEBUG     Read data: [a4 05 51 00 21 0b 01 05 de] (now have [a4 05 51 00 21 0b 01 05 de] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:07,752  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:07,755  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-04-03 19:21:07,806  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 81, array('B', [33, 11, 1, 5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:07,810  ant.easy.filter   DEBUG      - response found (0, 81, array('B', [33, 11, 1, 5])) (filter.py:47)
MainThread 2015-04-03 19:21:07,817  ant.fs.command    DEBUG     packing 'D\x02\x13\x049\x05\x00\x00' in array('B', [68, 2, 19, 4, 57, 5, 0, 0]),<type 'array.array'> (command.py:79)
MainThread 2015-04-03 19:21:07,821  ant.easy.channel  DEBUG     send acknowledged data 0 (channel.py:98)
MainThread 2015-04-03 19:21:07,825  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6cf7d70> (filter.py:40)
MainThread 2015-04-03 19:21:07,829  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:07,833  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6cf7d70> (filter.py:58)
ant.base   2015-04-03 19:21:07,878  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:07,982  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:07,987  ant.base.ant      DEBUG     Write data: [a4 09 4f 00 44 02 13 04 39 05 00 00 8f] (ant.py:212)
ant.base   2015-04-03 19:21:07,990  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 4f:[00 44 02 13 04 39 05 00 00] (s:a4, l:9, c:8f)> (ant.py:173)
ant.base   2015-04-03 19:21:08,001  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,005  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-04-03 19:21:08,053  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,057  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6cf7d70> (filter.py:58)
ant.base   2015-04-03 19:21:08,127  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] (now have [a4 09 4e 00 43 33 00 00 2d 07 01 00 b8] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,232  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:08,236  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:08,242  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,246  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-04-03 19:21:08,252  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 02 e4] (now have [a4 03 40 00 01 02 e4] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,255  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 02] (s:a4, l:3, c:e4)> (ant.py:157)
MainThread 2015-04-03 19:21:08,276  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [5])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,281  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-04-03 19:21:08,285  ant.easy.channel  DEBUG     done sending acknowledged data 0 (channel.py:101)
ant.base   2015-04-03 19:21:08,292  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:227)
MainThread 2015-04-03 19:21:08,298  ant.base.ant      DEBUG     Write data: [a4 03 43 00 00 10 f4] (ant.py:212)
MainThread 2015-04-03 19:21:08,302  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6cf7d70> (filter.py:40)
MainThread 2015-04-03 19:21:08,307  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 67, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,313  ant.easy.filter   DEBUG      - response found (0, 67, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:21:08,321  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:227)
MainThread 2015-04-03 19:21:08,326  ant.base.ant      DEBUG     Write data: [a4 02 44 00 03 e1] (ant.py:212)
MainThread 2015-04-03 19:21:08,331  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6cf7d70> (filter.py:40)
MainThread 2015-04-03 19:21:08,337  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 68, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,341  ant.easy.filter   DEBUG      - response found (0, 68, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:21:08,348  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:227)
MainThread 2015-04-03 19:21:08,353  ant.base.ant      DEBUG     Write data: [a4 02 45 00 13 f0] (ant.py:212)
MainThread 2015-04-03 19:21:08,356  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6cf7d70> (filter.py:40)
MainThread 2015-04-03 19:21:08,359  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,363  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6cf7d70> (filter.py:58)
MainThread 2015-04-03 19:21:08,368  ant.easy.filter   DEBUG     looking for matching message in deque([(None, 111, array('B', [32])), (0, 69, array('B', [0]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,372  ant.easy.filter   DEBUG      - response found (0, 69, array('B', [0])) (filter.py:47)
ant.base   2015-04-03 19:21:08,377  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:08,415  ant.fs.manager    DEBUG     Auth layer (manager.py:146)
MainThread 2015-04-03 19:21:08,420  root              DEBUG     on authentication (program.py:163)
MainThread 2015-04-03 19:21:08,424  ant.easy.channel  DEBUG     send acknowledged data 0 (channel.py:98)
MainThread 2015-04-03 19:21:08,428  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6cf7d70> (filter.py:40)
MainThread 2015-04-03 19:21:08,430  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,435  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6cf7d70> (filter.py:58)
ant.base   2015-04-03 19:21:08,481  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:08,486  ant.base.ant      DEBUG     Write data: [a4 09 4f 00 44 04 01 00 39 05 00 00 9f] (ant.py:212)
ant.base   2015-04-03 19:21:08,489  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 4f:[00 44 04 01 00 39 05 00 00] (s:a4, l:9, c:9f)> (ant.py:173)
ant.base   2015-04-03 19:21:08,503  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,507  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-04-03 19:21:08,612  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:08,615  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:08,620  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,624  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-04-03 19:21:08,629  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,636  ant.base.ant      DEBUG     Read data: [a4 09 50 20 44 84 00 10 21 0b 1c e8 d3] (now have [a4 09 50 20 44 84 00 10 21 0b 1c e8 d3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,642  ant.base.ant      DEBUG     Read data: [a4 09 50 40 76 c3 ad 76 6f 66 69 74 c7] (now have [a4 09 50 40 76 c3 ad 76 6f 66 69 74 c7] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,652  ant.base.ant      DEBUG     Read data: [a4 09 50 e0 00 00 00 00 00 00 00 00 1d] (now have [a4 09 50 e0 00 00 00 00 00 00 00 00 1d] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:08,656  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:08,661  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-04-03 19:21:08,666  ant.easy.channel  DEBUG     done sending acknowledged data 0 (channel.py:101)
MainThread 2015-04-03 19:21:08,671  ant.fs.manager    DEBUG     Get command, t15, s0 (manager.py:180)
ant.fs     2015-04-03 19:21:08,687  ant.fs.command    DEBUG     parsing data array('B', [68, 132, 0, 16, 33, 11, 28, 232, 118, 195, 173, 118, 111, 102, 105, 116, 0, 0, 0, 0, 0, 0, 0, 0]) (command.py:363)
ant.base   2015-04-03 19:21:08,752  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,856  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:08,860  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:08,878  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:08,881  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-04-03 19:21:08,984  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:08,987  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:09,002  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,006  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-04-03 19:21:09,111  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:09,114  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:09,127  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,131  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-04-03 19:21:09,234  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:09,237  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:09,253  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,256  ant.base.ant      DEBUG     No new data this period (ant.py:163)
MainThread 2015-04-03 19:21:09,304  root              DEBUG     loaded authfile: array('B', [154, 81, 61, 149, 39, 52, 165, 170]) (program.py:116)
MainThread 2015-04-03 19:21:09,312  root              DEBUG     serial vívofit, 3894151969L, array('B', [154, 81, 61, 149, 39, 52, 165, 170]) (program.py:169)
MainThread 2015-04-03 19:21:09,318  ant.easy.channel  DEBUG     send burst transfer 0 (channel.py:112)
MainThread 2015-04-03 19:21:09,321  ant.base.ant      DEBUG     Send burst transfer, chan 0, data array('B', [68, 4, 3, 8, 57, 5, 0, 0, 154, 81, 61, 149, 39, 52, 165, 170]) (ant.py:294)
MainThread 2015-04-03 19:21:09,324  ant.base.ant      DEBUG     Send burst transfer, packet 0, seq 0, data array('B', [68, 4, 3, 8, 57, 5, 0, 0]) (ant.py:304)
MainThread 2015-04-03 19:21:09,328  ant.base.ant      DEBUG     Send burst transfer, packet 1, seq 5, data array('B', [154, 81, 61, 149, 39, 52, 165, 170]) (ant.py:304)
MainThread 2015-04-03 19:21:09,332  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669ef0> (filter.py:40)
MainThread 2015-04-03 19:21:09,336  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:09,339  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6669ef0> (filter.py:58)
ant.base   2015-04-03 19:21:09,359  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:09,365  ant.base.ant      DEBUG     Write data: [a4 09 50 00 44 04 03 08 39 05 00 00 8a] (ant.py:212)
ant.base   2015-04-03 19:21:09,369  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[00 44 04 03 08 39 05 00 00] (s:a4, l:9, c:8a)> (ant.py:173)
ant.base   2015-04-03 19:21:09,375  ant.base.ant      DEBUG     Write data: [a4 09 50 a0 9a 51 3d 95 27 34 a5 aa 22] (ant.py:212)
ant.base   2015-04-03 19:21:09,379  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[a0 9a 51 3d 95 27 34 a5 aa] (s:a4, l:9, c:22)> (ant.py:173)
ant.base   2015-04-03 19:21:09,385  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] (now have [a4 09 4e 00 43 34 01 00 39 05 00 00 a9] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,388  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-04-03 19:21:09,492  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:09,496  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:09,501  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,506  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)> (ant.py:157)
ant.base   2015-04-03 19:21:09,510  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
MainThread 2015-04-03 19:21:09,518  ant.easy.filter   DEBUG     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', [10])), (0, 1, array('B', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:09,522  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [10])) (filter.py:47)
MainThread 2015-04-03 19:21:09,526  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb66699f0> (filter.py:40)
ant.base   2015-04-03 19:21:09,524  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:09,534  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
ant.base   2015-04-03 19:21:09,538  ant.base.ant      DEBUG     Read data: [a4 09 50 a0 44 84 01 00 21 0b 1c e8 42] (now have [a4 09 50 a0 44 84 01 00 21 0b 1c e8 42] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:09,546  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-04-03 19:21:09,550  ant.easy.channel  DEBUG     done sending burst transfer 0 (channel.py:116)
MainThread 2015-04-03 19:21:09,555  ant.fs.manager    DEBUG     Get command, t15, s0 (manager.py:180)
ant.fs     2015-04-03 19:21:09,592  ant.fs.command    DEBUG     parsing data array('B', [68, 132, 1, 0, 33, 11, 28, 232]) (command.py:363)
MainThread 2015-04-03 19:21:09,601  ant.fs.manager    DEBUG     Authenticated (manager.py:148)
MainThread 2015-04-03 19:21:09,608  ant.fs.commandpipe  DEBUG     packing '\x03\x00\x00\x01\x05\x80\x81/\xff\xff\xff\xff\x00\x00\x00\x00' in array('B', [3, 0, 0, 1, 5, 128, 129, 47, 255, 255, 255, 255, 0, 0, 0, 0]),<type 'array.array'> (commandpipe.py:78)
MainThread 2015-04-03 19:21:09,614  ant.fs.command    DEBUG     packing 'D\n\xfe\xff\x10\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' in array('B', [68, 10, 254, 255, 16, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]),<type 'array.array'> (command.py:79)
MainThread 2015-04-03 19:21:09,618  ant.easy.channel  DEBUG     send burst transfer 0 (channel.py:112)
MainThread 2015-04-03 19:21:09,622  ant.base.ant      DEBUG     Send burst transfer, chan 0, data array('B', [68, 10, 254, 255, 16, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]) (ant.py:294)
MainThread 2015-04-03 19:21:09,625  ant.base.ant      DEBUG     Send burst transfer, packet 0, seq 0, data array('B', [68, 10, 254, 255, 16, 0, 0, 0]) (ant.py:304)
ant.base   2015-04-03 19:21:09,628  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:09,634  ant.base.ant      DEBUG     Send burst transfer, packet 1, seq 5, data array('B', [0, 0, 0, 0, 0, 0, 0, 0]) (ant.py:304)
MainThread 2015-04-03 19:21:09,638  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669ef0> (filter.py:40)
MainThread 2015-04-03 19:21:09,641  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:09,645  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6669ef0> (filter.py:58)
ant.base   2015-04-03 19:21:09,734  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:09,739  ant.base.ant      DEBUG     Write data: [a4 09 50 00 44 0a fe ff 10 00 00 00 a2] (ant.py:212)
ant.base   2015-04-03 19:21:09,744  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[00 44 0a fe ff 10 00 00 00] (s:a4, l:9, c:a2)> (ant.py:173)
ant.base   2015-04-03 19:21:09,749  ant.base.ant      DEBUG     Write data: [a4 09 50 a0 00 00 00 00 00 00 00 00 5d] (ant.py:212)
ant.base   2015-04-03 19:21:09,752  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[a0 00 00 00 00 00 00 00 00] (s:a4, l:9, c:5d)> (ant.py:173)
ant.base   2015-04-03 19:21:09,758  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,762  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-04-03 19:21:09,865  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:09,868  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:09,873  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,877  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)> (ant.py:157)
ant.base   2015-04-03 19:21:09,881  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-04-03 19:21:09,887  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,895  ant.base.ant      DEBUG     Read data: [a4 09 50 20 44 8a 00 00 00 00 00 00 13 a4 09 50 40 10 00 00 00 10 00 00 00 bd] (now have [a4 09 50 20 44 8a 00 00 00 00 00 00 13 a4 09 50 40 10 00 00 00 10 00 00 00 bd] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:09,902  ant.base.ant      DEBUG     Read data: [a4 09 50 e0 00 00 00 00 00 00 00 00 1d] (now have [a4 09 50 e0 00 00 00 00 00 00 00 00 1d] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:09,913  ant.easy.filter   DEBUG     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', [10])), (0, 1, array('B', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:09,917  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [10])) (filter.py:47)
MainThread 2015-04-03 19:21:09,921  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669fb0> (filter.py:40)
MainThread 2015-04-03 19:21:09,924  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:09,928  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-04-03 19:21:09,932  ant.easy.channel  DEBUG     done sending burst transfer 0 (channel.py:116)
ant.fs     2015-04-03 19:21:09,938  ant.fs.command    DEBUG     parsing data array('B', [68, 138, 0, 0, 0, 0, 0, 0, 16, 0, 0, 0, 16, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]) (command.py:363)
MainThread 2015-04-03 19:21:09,937  ant.fs.manager    DEBUG     Get command, t15, s0 (manager.py:180)
MainThread 2015-04-03 19:21:09,954  ant.easy.channel  DEBUG     send burst transfer 0 (channel.py:112)
MainThread 2015-04-03 19:21:09,958  ant.base.ant      DEBUG     Send burst transfer, chan 0, data array('B', [68, 12, 0, 0, 0, 0, 0, 0, 3, 0, 0, 1, 5, 128, 129, 47, 255, 255, 255, 255, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 41, 178]) (ant.py:294)
MainThread 2015-04-03 19:21:09,962  ant.base.ant      DEBUG     Send burst transfer, packet 0, seq 0, data array('B', [68, 12, 0, 0, 0, 0, 0, 0]) (ant.py:304)
MainThread 2015-04-03 19:21:09,966  ant.base.ant      DEBUG     Send burst transfer, packet 1, seq 1, data array('B', [3, 0, 0, 1, 5, 128, 129, 47]) (ant.py:304)
MainThread 2015-04-03 19:21:09,974  ant.base.ant      DEBUG     Send burst transfer, packet 2, seq 2, data array('B', [255, 255, 255, 255, 0, 0, 0, 0]) (ant.py:304)
MainThread 2015-04-03 19:21:09,979  ant.base.ant      DEBUG     Send burst transfer, packet 3, seq 7, data array('B', [0, 0, 0, 0, 0, 0, 41, 178]) (ant.py:304)
MainThread 2015-04-03 19:21:09,983  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669fb0> (filter.py:40)
MainThread 2015-04-03 19:21:09,987  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:09,993  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6669fb0> (filter.py:58)
ant.base   2015-04-03 19:21:10,002  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 00 00 00 00 00 00 00 00 e3] (now have [a4 09 4e 00 00 00 00 00 00 00 00 00 e3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,106  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:10,111  ant.base.ant      DEBUG     Write data: [a4 09 50 00 44 0c 00 00 00 00 00 00 b5] (ant.py:212)
ant.base   2015-04-03 19:21:10,114  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[00 44 0c 00 00 00 00 00 00] (s:a4, l:9, c:b5)> (ant.py:173)
ant.base   2015-04-03 19:21:10,120  ant.base.ant      DEBUG     Write data: [a4 09 50 20 03 00 00 01 05 80 81 2f f4] (ant.py:212)
ant.base   2015-04-03 19:21:10,123  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[20 03 00 00 01 05 80 81 2f] (s:a4, l:9, c:f4)> (ant.py:173)
ant.base   2015-04-03 19:21:10,128  ant.base.ant      DEBUG     Write data: [a4 09 50 40 ff ff ff ff 00 00 00 00 bd] (ant.py:212)
ant.base   2015-04-03 19:21:10,131  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[40 ff ff ff ff 00 00 00 00] (s:a4, l:9, c:bd)> (ant.py:173)
ant.base   2015-04-03 19:21:10,136  ant.base.ant      DEBUG     Write data: [a4 09 50 e0 00 00 00 00 00 00 29 b2 86] (ant.py:212)
ant.base   2015-04-03 19:21:10,139  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[e0 00 00 00 00 00 00 29 b2] (s:a4, l:9, c:86)> (ant.py:173)
ant.base   2015-04-03 19:21:10,145  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,249  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:10,252  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:10,258  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 0a ec a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,262  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)> (ant.py:157)
ant.base   2015-04-03 19:21:10,266  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-04-03 19:21:10,273  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5 a4 09 50 a0 44 8c 00 00 00 00 00 00 95] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5 a4 09 50 a0 44 8c 00 00 00 00 00 00 95] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:10,319  ant.easy.filter   DEBUG     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', [10])), (0, 1, array('B', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:10,324  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [10])) (filter.py:47)
MainThread 2015-04-03 19:21:10,328  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669ef0> (filter.py:40)
MainThread 2015-04-03 19:21:10,331  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:10,336  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-04-03 19:21:10,340  ant.easy.channel  DEBUG     done sending burst transfer 0 (channel.py:116)
MainThread 2015-04-03 19:21:10,343  ant.fs.manager    DEBUG     Get command, t15, s0 (manager.py:180)
ant.fs     2015-04-03 19:21:10,356  ant.fs.command    DEBUG     parsing data array('B', [68, 140, 0, 0, 0, 0, 0, 0]) (command.py:363)
MainThread 2015-04-03 19:21:10,363  ant.fs.manager    DEBUG     Download 65534, o0, c0 (manager.py:305)
MainThread 2015-04-03 19:21:10,370  ant.fs.command    DEBUG     packing 'D\t\xfe\xff\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00' in array('B', [68, 9, 254, 255, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0]),<type 'array.array'> (command.py:79)
ant.base   2015-04-03 19:21:10,377  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:10,375  ant.easy.channel  DEBUG     send burst transfer 0 (channel.py:112)
MainThread 2015-04-03 19:21:10,383  ant.base.ant      DEBUG     Send burst transfer, chan 0, data array('B', [68, 9, 254, 255, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0]) (ant.py:294)
MainThread 2015-04-03 19:21:10,387  ant.base.ant      DEBUG     Send burst transfer, packet 0, seq 0, data array('B', [68, 9, 254, 255, 0, 0, 0, 0]) (ant.py:304)
MainThread 2015-04-03 19:21:10,392  ant.base.ant      DEBUG     Send burst transfer, packet 1, seq 5, data array('B', [0, 1, 0, 0, 0, 0, 0, 0]) (ant.py:304)
MainThread 2015-04-03 19:21:10,395  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669f70> (filter.py:40)
MainThread 2015-04-03 19:21:10,398  ant.easy.filter   DEBUG     looking for matching message in deque([(0, 1, array('B', [2])), (0, 1, array('B', [2])), (0, 1, array('B', [2]))]) (filter.py:43)
MainThread 2015-04-03 19:21:10,404  ant.easy.filter   DEBUG      - could not find response matching <function match at 0xb6669f70> (filter.py:58)
ant.base   2015-04-03 19:21:10,481  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:10,486  ant.base.ant      DEBUG     Write data: [a4 09 50 00 44 09 fe ff 00 00 00 00 b1] (ant.py:212)
ant.base   2015-04-03 19:21:10,489  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[00 44 09 fe ff 00 00 00 00] (s:a4, l:9, c:b1)> (ant.py:173)
ant.base   2015-04-03 19:21:10,495  ant.base.ant      DEBUG     Write data: [a4 09 50 a0 00 01 00 00 00 00 00 00 5c] (ant.py:212)
ant.base   2015-04-03 19:21:10,498  ant.base.ant      DEBUG      - sent message from queue, <ant.base.Message 50:[a0 00 01 00 00 00 00 00 00] (s:a4, l:9, c:5c)> (ant.py:173)
ant.base   2015-04-03 19:21:10,504  ant.base.ant      DEBUG     Read data: [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] (now have [a4 09 4e 00 43 34 02 00 39 05 00 00 aa] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,508  ant.base.ant      DEBUG     No new data this period (ant.py:163)
ant.base   2015-04-03 19:21:10,611  ant.base.ant      DEBUG     Got broadcast data, examine queue to see if we should send anything back (ant.py:168)
ant.base   2015-04-03 19:21:10,614  ant.base.ant      DEBUG      - no messages in queue (ant.py:179)
ant.base   2015-04-03 19:21:10,619  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 0a ec] (now have [a4 03 40 00 01 0a ec] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,623  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 0a] (s:a4, l:3, c:ec)> (ant.py:157)
ant.base   2015-04-03 19:21:10,629  ant.base.ant      DEBUG     Read data: [a4 03 40 00 01 05 e3] (now have [a4 03 40 00 01 05 e3] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,632  ant.base.ant      DEBUG     Got channel event, <ant.base.Message 40:[00 01 05] (s:a4, l:3, c:e3)> (ant.py:157)
ant.base   2015-04-03 19:21:10,639  ant.base.ant      DEBUG     Read data: [a4 09 50 00 43 34 03 00 39 05 00 00 b5] (now have [a4 09 50 00 43 34 03 00 39 05 00 00 b5] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,650  ant.base.ant      DEBUG     Read data: [a4 09 50 20 44 89 00 00 10 00 00 00 00 a4 09 50 40 00 00 00 00 10 00 00 00 ad a4 09 50 60 02 00 00 00 03 00 00 00 9c] (now have [a4 09 50 20 44 89 00 00 10 00 00 00 00 a4 09 50 40 00 00 00 00 10 00 00 00 ad a4 09 50 60 02 00 00 00 03 00 00 00 9c] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,658  ant.base.ant      DEBUG     Read data: [a4 09 50 20 00 00 00 00 00 00 00 00 dd] (now have [a4 09 50 20 00 00 00 00 00 00 00 00 dd] in buffer) (ant.py:227)
ant.base   2015-04-03 19:21:10,666  ant.base.ant      DEBUG     Read data: [a4 09 50 c0 00 00 00 00 00 00 85 65 dd] (now have [a4 09 50 c0 00 00 00 00 00 00 85 65 dd] in buffer) (ant.py:227)
MainThread 2015-04-03 19:21:10,673  ant.easy.filter   DEBUG     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', [10])), (0, 1, array('B', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:10,677  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [10])) (filter.py:47)
MainThread 2015-04-03 19:21:10,683  ant.easy.filter   DEBUG     wait for message matching <function match at 0xb6669fb0> (filter.py:40)
MainThread 2015-04-03 19:21:10,688  ant.easy.filter   DEBUG     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', [5]))]) (filter.py:43)
MainThread 2015-04-03 19:21:10,692  ant.easy.filter   DEBUG      - response found (0, 1, array('B', [5])) (filter.py:47)
MainThread 2015-04-03 19:21:10,697  ant.easy.channel  DEBUG     done sending burst transfer 0 (channel.py:116)
ant.fs     2015-04-03 19:21:10,701  ant.fs.command    DEBUG     parsing data array('B', [68, 137, 0, 0, 16, 0, 0, 0, 0, 0, 0, 0, 16, 0, 0, 0, 2, 0, 0, 0, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 133, 101]) (command.py:363)
MainThread 2015-04-03 19:21:10,709  ant.fs.manager    DEBUG     Wait for response... (manager.py:307)
MainThread 2015-04-03 19:21:10,713  ant.fs.manager    DEBUG     Get command, t15, s1 (manager.py:180)
MainThread 2015-04-03 19:21:10,718  ant.fs.commandpipe  DEBUG     args[0] != cls._id: 2 != 3 (commandpipe.py:89)

Edit less has skipped lines

Tigge commented 9 years ago

Thank you very much @balu-! I've updated the https://github.com/Tigge/openant/tree/time branch to fix this. I also moved the set time code to openant, added some error checking, fixed the tests and a UTC to TAI conversion (could use a library here to avoid having to update the code every other year or so due to the UTC leap seconds).

As before I haven't been able to test this, especially the https://github.com/Tigge/openant/commit/8166dc6c0672870cdf5edc65a3c549ea4ec1653f commit.

balu- commented 9 years ago

Thank you so much @Tigge for all your efforts.

works like a charm, especialy setting the time via the code of https://github.com/Tigge/openant/commit/8166dc6c0672870cdf5edc65a3c549ea4ec1653f (at least with vivofit).

Tigge commented 9 years ago

I manually merged part of your pull request @balu-, so this should now work. See https://github.com/Tigge/antfs-cli/commit/99bee7f9c7fc958d640dda08f77b3a2d1bc26ace.

psukys commented 8 years ago

Can somebody confirm that this still works? I've tried to manually (edit source, install via setup.py and rerun) set a different time, although without any success.

AndreasPapageorgiou commented 8 years ago

@psukys I just added a similar comment in Tigge/openant#11. I have the same problem.

Tigge commented 8 years ago

@psukys and @AndreasPapageorgiou: Let's continue the discussion in https://github.com/Tigge/openant/pull/11.