search

currantlabs / ble

BSD 3-Clause "New" or "Revised" License
210 stars 178 forks source link

linux: Unable to subscribe to GATT characteristic #7

Closed deadprogram closed 7 years ago

deadprogram commented 8 years ago

Hi, @roylee17

I have been testing this package with a WICED Sense device on Ubuntu 14.04. I was able to scan, and explore with no problems thus far. I then tried to subscribe to notifications, and received an error unexpected EOF.

$ sudo ./bin/explorer --name="WICED Sense Kit" --sub="10s"
2016/07/01 11:34:23 dev: hci0 up
2016/07/01 11:34:23 dev: hci0 reset
2016/07/01 11:34:23 dev: hci0 down
2016/07/01 11:34:23 dev: hci0 opened
Exploring Peripheral [ 20:73:77:65:43:21 ] ...
Service: 1801 Generic Attribute

Service: 1800 Generic Access
  Characteristic: 2A00, Property: 0x02, Device Name
    Value         57494345442053656e7365204b697400 | "WICED Sense Kit\x00"
  Characteristic: 2A01, Property: 0x02, Appearance
    Value         0002 | "\x00\x02"

Service: 739298B687B64984A5DCBDC18B068985 
  Characteristic: 33EF91133B55413EB553FEA1EAADA459, Property: 0x12, 
    Value         0000000000000000000000000000000000000000 | "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"
    Descriptor: 2902, Client Characteristic Configuration
    Value         0000 | "\x00\x00"

-- Subscribe to notification for 10s --
2016/07/01 11:34:26 subscribe failed: unexpected EOF

It appears that when the GATT client writes: https://github.com/currantlabs/ble/blob/master/linux/gatt/client.go#L273

that when it calls the ATT client's Write: https://github.com/currantlabs/ble/blob/master/linux/att/client.go#L336

the sendReq function here https://github.com/currantlabs/ble/blob/master/linux/att/client.go#L350

is returning the error from here: https://github.com/currantlabs/ble/blob/master/linux/att/client.go#L501

Perhaps this is related to some specific value or behaviour of the WICED Sense device. I was able to run the explorer on a LightBlue bean on Linux, and did not have this particular error.

deadprogram commented 8 years ago

Running the explorer on OS X for the same device, results in success:

rons-MacBook-Air:examples ron$ ./bin/explorer --name="WICED Sense Kit" --sub="10s"
Exploring Peripheral [ DC502E1E5B324007A869BAEF73E82C4F ] ...
Service: 739298B687B64984A5DCBDC18B068985 
  Characteristic: 33EF91133B55413EB553FEA1EAADA459, Property: 0x12, 
    Value         0000000000000000000000000000000000000000 | "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"
    Descriptor: 2902, Client Characteristic Configuration
    Value         0000 | "\x00\x00"

-- Subscribe to notification for 10s --
Notified: "\v\x06\x00\xff\xffT\x00\xb0\xff\x82\x00\x10\x00q\x03\xd1\xfc\\\xf9" [ 0B 06 00 FF FF 54 00 B0 FF 82 00 10 00 71 03 D1 FC 5C F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xba\xff{\x00\x19\x00s\x03\xd9\xfcd\xf9" [ 0B 05 00 FF FF 54 00 BA FF 7B 00 19 00 73 03 D9 FC 64 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00~\xff\x8b\x00\x17\x00c\x03\xcf\xfcU\xf9" [ 0B 05 00 FF FF 54 00 7E FF 8B 00 17 00 63 03 CF FC 55 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\x9e\xffo\x00$\x00^\x03\xcd\xfcZ\xf9" [ 0B 05 00 FF FF 55 00 9E FF 6F 00 24 00 5E 03 CD FC 5A F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xc4\xffq\x00\x1a\x00i\x03\xc6\xfc_\xf9" [ 0B 05 00 FF FF 54 00 C4 FF 71 00 1A 00 69 03 C6 FC 5F F9 ]
Notified: "\v\x04\x00\xff\xffT\x00\xb4\xff\x91\x00\x12\x00a\x03\xd3\xfcY\xf9" [ 0B 04 00 FF FF 54 00 B4 FF 91 00 12 00 61 03 D3 FC 59 F9 ]
Notified: "\v\x06\x00\x00\x00U\x00\xc5\xffi\x00\x17\x00[\x03\xd4\xfc^\xf9" [ 0B 06 00 00 00 55 00 C5 FF 69 00 17 00 5B 03 D4 FC 5E F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xb7\xffw\x00\x18\x00o\x03\xcd\xfcY\xf9" [ 0B 05 00 FF FF 54 00 B7 FF 77 00 18 00 6F 03 CD FC 59 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xa4\xffr\x00\x1c\x00e\x03\xd5\xfch\xf9" [ 0B 05 00 FF FF 54 00 A4 FF 72 00 1C 00 65 03 D5 FC 68 F9 ]
Notified: "4\xda\x02\xdc&\xca\x00" [ 34 DA 02 DC 26 CA 00 ]
Notified: "\v\x05\x00\xff\xffU\x00\xc6\xffo\x00\x17\x00g\x03\xd9\xfci\xf9" [ 0B 05 00 FF FF 55 00 C6 FF 6F 00 17 00 67 03 D9 FC 69 F9 ]
Notified: "\v\x06\x00\x00\x00T\x00\xb5\xffq\x00\x16\x00o\x03\xd2\xfcV\xf9" [ 0B 06 00 00 00 54 00 B5 FF 71 00 16 00 6F 03 D2 FC 56 F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\xac\xffk\x00\x1a\x00m\x03\xdc\xfc_\xf9" [ 0B 06 00 FF FF 54 00 AC FF 6B 00 1A 00 6D 03 DC FC 5F F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\xc0\xff\x80\x00\x1f\x00o\x03\xd0\xfcY\xf9" [ 0B 06 00 FF FF 54 00 C0 FF 80 00 1F 00 6F 03 D0 FC 59 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\x94\xff\x88\x00\x1f\x00r\x03\xca\xfcN\xf9" [ 0B 05 00 FF FF 55 00 94 FF 88 00 1F 00 72 03 CA FC 4E F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x9f\xff\x80\x00\x1c\x00o\x03\xd5\xfce\xf9" [ 0B 05 00 FF FF 54 00 9F FF 80 00 1C 00 6F 03 D5 FC 65 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\x8c\xff\x9a\x00\x0f\x00q\x03\xd4\xfcR\xf9" [ 0B 05 00 FF FF 55 00 8C FF 9A 00 0F 00 71 03 D4 FC 52 F9 ]
Notified: "\v\x05\x00\xff\xffS\x00\xa3\xff\x92\x00\b\x00h\x03\xd0\xfc`\xf9" [ 0B 05 00 FF FF 53 00 A3 FF 92 00 08 00 68 03 D0 FC 60 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x88\xff\x85\x00\x12\x00j\x03\xd1\xfc]\xf9" [ 0B 05 00 FF FF 54 00 88 FF 85 00 12 00 6A 03 D1 FC 5D F9 ]
Notified: "4\xda\x02\xdd&\xca\x00" [ 34 DA 02 DD 26 CA 00 ]
Notified: "\v\x05\x00\xff\xffU\x00\xaf\xffp\x00\x18\x00l\x03\xce\xfcc\xf9" [ 0B 05 00 FF FF 55 00 AF FF 70 00 18 00 6C 03 CE FC 63 F9 ]
Notified: "\v\x06\x00\xff\xffU\x00\x8d\xff\x89\x00,\x00j\x03\xcc\xfcW\xf9" [ 0B 06 00 FF FF 55 00 8D FF 89 00 2C 00 6A 03 CC FC 57 F9 ]
Notified: "\v\x05\x00\xfe\xffT\x00\xa7\xff\x94\x00$\x00^\x03\xc2\xfc`\xf9" [ 0B 05 00 FE FF 54 00 A7 FF 94 00 24 00 5E 03 C2 FC 60 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x9a\xff\x85\x00\x18\x00i\x03\xd4\xfcl\xf9" [ 0B 05 00 FF FF 54 00 9A FF 85 00 18 00 69 03 D4 FC 6C F9 ]
Notified: "\v\x05\x00\x00\x00U\x00\xa4\xff\x80\x00\x03\x00h\x03\xcf\xfca\xf9" [ 0B 05 00 00 00 55 00 A4 FF 80 00 03 00 68 03 CF FC 61 F9 ]
Notified: "\v\x06\x00\x00\x00T\x00\x9b\xff\x81\x00 \x00g\x03\xd3\xfcY\xf9" [ 0B 06 00 00 00 54 00 9B FF 81 00 20 00 67 03 D3 FC 59 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xab\xffy\x00%\x00s\x03\xcc\xfcY\xf9" [ 0B 05 00 FF FF 54 00 AB FF 79 00 25 00 73 03 CC FC 59 F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\x91\xff\xa0\x00\x10\x00m\x03\xd6\xfcP\xf9" [ 0B 06 00 FF FF 54 00 91 FF A0 00 10 00 6D 03 D6 FC 50 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xa6\xff\x8f\x00)\x00o\x03\xd9\xfcU\xf9" [ 0B 05 00 FF FF 54 00 A6 FF 8F 00 29 00 6F 03 D9 FC 55 F9 ]
Notified: "4\xda\x02\xdc&\xca\x00" [ 34 DA 02 DC 26 CA 00 ]
Notified: "\v\x05\x00\xff\xffT\x00\xb4\xff\x8d\x00\"\x00r\x03\xca\xfcZ\xf9" [ 0B 05 00 FF FF 54 00 B4 FF 8D 00 22 00 72 03 CA FC 5A F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\xa9\xff\x80\x00 \x00p\x03\xcf\xfcX\xf9" [ 0B 06 00 FF FF 54 00 A9 FF 80 00 20 00 70 03 CF FC 58 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\x96\xff\x92\x00\x12\x00s\x03\xd0\xfce\xf9" [ 0B 05 00 FF FF 55 00 96 FF 92 00 12 00 73 03 D0 FC 65 F9 ]
Notified: "\v\x06\x00\xff\xffU\x00\xb9\xffo\x00$\x00n\x03\xd4\xfc]\xf9" [ 0B 06 00 FF FF 55 00 B9 FF 6F 00 24 00 6E 03 D4 FC 5D F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x8b\xff\x91\x00\x13\x00v\x03\xce\xfcZ\xf9" [ 0B 05 00 FF FF 54 00 8B FF 91 00 13 00 76 03 CE FC 5A F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\x99\xff\\\x00%\x00x\x03\xc7\xfcS\xf9" [ 0B 06 00 FF FF 54 00 99 FF 5C 00 25 00 78 03 C7 FC 53 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\xa9\xffd\x00\n\x00c\x03\xd2\xfcd\xf9" [ 0B 05 00 FF FF 55 00 A9 FF 64 00 0A 00 63 03 D2 FC 64 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xa3\xffn\x00#\x00b\x03\xc4\xfcY\xf9" [ 0B 05 00 FF FF 54 00 A3 FF 6E 00 23 00 62 03 C4 FC 59 F9 ]
Notified: "\v\x05\x00\x00\x00T\x00\xa8\xffu\x00\x13\x00o\x03\xcc\xfce\xf9" [ 0B 05 00 00 00 54 00 A8 FF 75 00 13 00 6F 03 CC FC 65 F9 ]
Notified: "4\xda\x02\xdc&\xca\x00" [ 34 DA 02 DC 26 CA 00 ]
Notified: "\v\x06\x00\xff\xffT\x00\xa8\xffh\x00\x1c\x00j\x03\xc9\xfc_\xf9" [ 0B 06 00 FF FF 54 00 A8 FF 68 00 1C 00 6A 03 C9 FC 5F F9 ]
Notified: "\v\x06\x00\xff\xffT\x00y\xff\xb1\x00\x11\x00n\x03\xd3\xfcc\xf9" [ 0B 06 00 FF FF 54 00 79 FF B1 00 11 00 6E 03 D3 FC 63 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x9f\xff\x82\x00\x14\x00m\x03\xcf\xfc]\xf9" [ 0B 05 00 FF FF 54 00 9F FF 82 00 14 00 6D 03 CF FC 5D F9 ]
Notified: "\v\x06\x00\x00\x00T\x00v\xff\x9f\x00\x11\x00m\x03\xcc\xfc_\xf9" [ 0B 06 00 00 00 54 00 76 FF 9F 00 11 00 6D 03 CC FC 5F F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xae\xff\x90\x00\x1d\x00q\x03\xc9\xfc[\xf9" [ 0B 05 00 FF FF 54 00 AE FF 90 00 1D 00 71 03 C9 FC 5B F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\xbb\xff\x95\x00\x1c\x00t\x03\xd7\xfcd\xf9" [ 0B 06 00 FF FF 54 00 BB FF 95 00 1C 00 74 03 D7 FC 64 F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\x96\xff\xa6\x00$\x00o\x03\xd1\xfc]\xf9" [ 0B 06 00 FF FF 54 00 96 FF A6 00 24 00 6F 03 D1 FC 5D F9 ]
Notified: "\v\x06\x00\xff\xffU\x00\xa5\xff\x95\x00#\x00i\x03\xd4\xfcS\xf9" [ 0B 06 00 FF FF 55 00 A5 FF 95 00 23 00 69 03 D4 FC 53 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x96\xff\x8e\x00\x14\x00s\x03\xd4\xfc`\xf9" [ 0B 05 00 FF FF 54 00 96 FF 8E 00 14 00 73 03 D4 FC 60 F9 ]
Notified: "4\xda\x02\xda&\xca\x00" [ 34 DA 02 DA 26 CA 00 ]
Notified: "\v\x06\x00\xff\xffT\x00\x88\xff\x95\x00\x18\x00g\x03\xc3\xfcX\xf9" [ 0B 06 00 FF FF 54 00 88 FF 95 00 18 00 67 03 C3 FC 58 F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\xa1\xff\x94\x00-\x00d\x03\xcd\xfcl\xf9" [ 0B 06 00 FF FF 54 00 A1 FF 94 00 2D 00 64 03 CD FC 6C F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\xb4\xff\x8a\x00&\x00j\x03\xcc\xfcf\xf9" [ 0B 06 00 FF FF 54 00 B4 FF 8A 00 26 00 6A 03 CC FC 66 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x9c\xff\xac\x00\x1d\x00g\x03\xcd\xfcd\xf9" [ 0B 05 00 FF FF 54 00 9C FF AC 00 1D 00 67 03 CD FC 64 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x98\xff\xa4\x00\x19\x00i\x03\xd0\xfc_\xf9" [ 0B 05 00 FF FF 54 00 98 FF A4 00 19 00 69 03 D0 FC 5F F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\x90\xff\x97\x00!\x00f\x03\xcf\xfcU\xf9" [ 0B 06 00 FF FF 54 00 90 FF 97 00 21 00 66 03 CF FC 55 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\xa1\xff\x91\x00\x16\x00m\x03\xcd\xfc[\xf9" [ 0B 05 00 FF FF 55 00 A1 FF 91 00 16 00 6D 03 CD FC 5B F9 ]
Notified: "\v\x06\x00\xff\xffS\x00\x99\xff\xa0\x00\x12\x00j\x03\xc8\xfcR\xf9" [ 0B 06 00 FF FF 53 00 99 FF A0 00 12 00 6A 03 C8 FC 52 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x98\xff~\x00\x15\x00e\x03\xc5\xfcV\xf9" [ 0B 05 00 FF FF 54 00 98 FF 7E 00 15 00 65 03 C5 FC 56 F9 ]
Notified: "4\xda\x02\xdc&\xcb\x00" [ 34 DA 02 DC 26 CB 00 ]
Notified: "\v\x05\x00\x00\x00U\x00\x9d\xff\x8e\x00\x19\x00{\x03\xd7\xfc[\xf9" [ 0B 05 00 00 00 55 00 9D FF 8E 00 19 00 7B 03 D7 FC 5B F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x97\xff\x8b\x00\x03\x00x\x03\xe0\xfcZ\xf9" [ 0B 05 00 FF FF 54 00 97 FF 8B 00 03 00 78 03 E0 FC 5A F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x9f\xff\x8e\x00\x1e\x00y\x03\xd5\xfcW\xf9" [ 0B 05 00 FF FF 54 00 9F FF 8E 00 1E 00 79 03 D5 FC 57 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\xae\xff\x90\x00\n\x00t\x03\xd7\xfcX\xf9" [ 0B 05 00 FF FF 55 00 AE FF 90 00 0A 00 74 03 D7 FC 58 F9 ]
Notified: "\v\x06\x00\xff\xffV\x00\x96\xff\x82\x00\x1a\x00g\x03\xcd\xfch\xf9" [ 0B 06 00 FF FF 56 00 96 FF 82 00 1A 00 67 03 CD FC 68 F9 ]
Notified: "\v\x05\x00\x00\x00T\x00\xa7\xff|\x00'\x00i\x03\xd7\xfcV\xf9" [ 0B 05 00 00 00 54 00 A7 FF 7C 00 27 00 69 03 D7 FC 56 F9 ]
Notified: "\v\x05\x00\x00\x00T\x00[\xff\xb3\x00\r\x00o\x03\xca\xfcc\xf9" [ 0B 05 00 00 00 54 00 5B FF B3 00 0D 00 6F 03 CA FC 63 F9 ]
Notified: "\v\x05\x00\xff\xffS\x00\xb1\xff\x89\x00\v\x00i\x03\xbd\xfcb\xf9" [ 0B 05 00 FF FF 53 00 B1 FF 89 00 0B 00 69 03 BD FC 62 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x9e\xff\xb0\x00\x1a\x00`\x03\xce\xfc_\xf9" [ 0B 05 00 FF FF 54 00 9E FF B0 00 1A 00 60 03 CE FC 5F F9 ]
Notified: "4\xda\x02\xdc&\xcb\x00" [ 34 DA 02 DC 26 CB 00 ]
Notified: "\v\x05\x00\xff\xffT\x00\x9d\xff}\x00\"\x00i\x03\xc0\xfca\xf9" [ 0B 05 00 FF FF 54 00 9D FF 7D 00 22 00 69 03 C0 FC 61 F9 ]
Notified: "\v\x06\x00\xff\xffT\x00\x8a\xff\xa1\x00\x18\x00h\x03\xd1\xfci\xf9" [ 0B 06 00 FF FF 54 00 8A FF A1 00 18 00 68 03 D1 FC 69 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xa3\xff\x96\x00\x18\x00j\x03\xc5\xfc]\xf9" [ 0B 05 00 FF FF 54 00 A3 FF 96 00 18 00 6A 03 C5 FC 5D F9 ]
Notified: "\v\x05\x00\xff\xffT\x00y\xff\x91\x00\v\x00e\x03\xd2\xfcb\xf9" [ 0B 05 00 FF FF 54 00 79 FF 91 00 0B 00 65 03 D2 FC 62 F9 ]
Notified: "\v\x06\x00\xff\xffS\x00\xa6\xffu\x00\x0e\x00X\x03\xe0\xfcb\xf9" [ 0B 06 00 FF FF 53 00 A6 FF 75 00 0E 00 58 03 E0 FC 62 F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x85\xff\xa2\x00\x0f\x00o\x03\xd1\xfc^\xf9" [ 0B 05 00 FF FF 54 00 85 FF A2 00 0F 00 6F 03 D1 FC 5E F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x8a\xff\xa7\x00\x0f\x00q\x03\xc9\xfc[\xf9" [ 0B 05 00 FF FF 54 00 8A FF A7 00 0F 00 71 03 C9 FC 5B F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\xab\xffx\x00\x11\x00c\x03\xbf\xfc_\xf9" [ 0B 05 00 FF FF 54 00 AB FF 78 00 11 00 63 03 BF FC 5F F9 ]
Notified: "\v\x06\x00\xff\xffT\x00z\xff\xa5\x00 \x00k\x03\xd7\xfcj\xf9" [ 0B 06 00 FF FF 54 00 7A FF A5 00 20 00 6B 03 D7 FC 6A F9 ]
Notified: "4\xda\x02\xdb&\xcb\x00" [ 34 DA 02 DB 26 CB 00 ]
Notified: "\v\x06\x00\xff\xffT\x00\xa5\xff\x8b\x00\x04\x00g\x03\xc7\xfcW\xf9" [ 0B 06 00 FF FF 54 00 A5 FF 8B 00 04 00 67 03 C7 FC 57 F9 ]
Notified: "\v\x05\x00\x00\x00T\x00\x85\xff\x8a\x00\x13\x00o\x03\xc7\xfco\xf9" [ 0B 05 00 00 00 54 00 85 FF 8A 00 13 00 6F 03 C7 FC 6F F9 ]
Notified: "\v\x05\x00\xff\xffT\x00\x83\xff\x95\x00\x0f\x00n\x03\xd3\xfcU\xf9" [ 0B 05 00 FF FF 54 00 83 FF 95 00 0F 00 6E 03 D3 FC 55 F9 ]
Notified: "\v\x05\x00\xff\xffU\x00\x9f\xffv\x00\f\x00r\x03\xc1\xfck\xf9" [ 0B 05 00 FF FF 55 00 9F FF 76 00 0C 00 72 03 C1 FC 6B F9 ]
Notified: "\v\x05\x00\xfe\xffS\x00g\xff\xce\x00\t\x00j\x03\xcd\xfco\xf9" [ 0B 05 00 FE FF 53 00 67 FF CE 00 09 00 6A 03 CD FC 6F F9 ]
-- Unsubscribe to notification --

Service: 180A Device Information
  Characteristic: 2A29, Property: 0x02, Manufacturer Name String
    Value         42726f6164636f6d | "Broadcom"
  Characteristic: 2A24, Property: 0x02, Model Number String
    Value         3030303100000000 | "0001\x00\x00\x00\x00"
  Characteristic: 2A23, Property: 0x02, System ID
    Value         a5dcbdc18b068985 | "\xa5ܽ\xc1\x8b\x06\x89\x85"

Service: 180F Battery Service
  Characteristic: 2A19, Property: 0x02, Battery Level
    Value         26 | "&"

Service: A86ABC2DD44C442E99F780059A873E36 
  Characteristic: 1BD19C14B78A4E0FAEB58E0352BAC382, Property: 0x18, 
    Descriptor: 2902, Client Characteristic Configuration
    Value         0000 | "\x00\x00"

-- Subscribe to notification for 10s --
-- Unsubscribe to notification --
  Characteristic: 279F9DAB79BE4663AF1D24407347AF13, Property: 0x08, 
  Characteristic: 6AA5711B037644F1BCA18647B48BDB55, Property: 0x02, 
    Value         203a0101 | " :\x01\x01"

Disconnecting [ DC502E1E5B324007A869BAEF73E82C4F ]... (this might take up to few seconds on OS X)
roylee17 commented 8 years ago

I add some logs to dump the ATT requests and responses . Could you try again with it enabled?

sudo LOGXI=att go run explorer/main.go -sub 3

And a hcidump in case those logs didn't catch the culprit.

Thanks!

deadprogram commented 8 years ago

Here is the output with extra logging:

$ sudo LOGXI=* ./bin/explorer -name="WICED Sense Kit" -sub=3s
2016/07/02 09:46:26 dev: hci0 up
2016/07/02 09:46:26 dev: hci0 reset
2016/07/02 09:46:26 dev: hci0 down
2016/07/02 09:46:26 dev: hci0 opened
09:46:26.456164 INF state AdvertisingUpdated +
09:46:26.459008 INF state AdvertisingUpdated -
09:46:26.459182 INF state ScanningUpdated +
09:46:26.460015 INF state ScanningUpdated -
09:46:26.460148 INF state Scanning +
09:46:26.461068 INF state Scanning -
09:46:26.484274 INF state StopScanning +
09:46:26.487068 INF state StopScanning -
09:46:26.487194 INF state StopScanning +
09:46:26.487270 INF state StopScanning -
09:46:26.487318 INF state Dialing +
09:46:26.489100 INF state Dialing -
09:46:26.501157 INF state StopDialing +
09:46:26.501225 INF state StopDialing -
Exploring Peripheral [ 20:73:77:65:43:21 ] ...
Service: 1801 Generic Attribute

Service: 1800 Generic Access
  Characteristic: 2A00, Property: 0x02, Device Name
    Value         57494345442053656e7365204b697400 | "WICED Sense Kit\x00"
  Characteristic: 2A01, Property: 0x02, Appearance
    Value         0002 | "\x00\x02"

Service: 739298B687B64984A5DCBDC18B068985 
  Characteristic: 33EF91133B55413EB553FEA1EAADA459, Property: 0x12, 
    Value         0000000000000000000000000000000000000000 | "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"
    Descriptor: 2902, Client Characteristic Configuration
    Value         0000 | "\x00\x00"

-- Subscribe to notification for 3s --
09:46:27.428094 INF state PeripheralDisconnected +
09:46:27.428146 INF state PeripheralDisconnected -
2016/07/02 09:46:27 subscribe failed: unexpected EOF

You will find the HCIDUMP output as an attached file.

Thanks! wiced.txt

deadprogram commented 8 years ago

I noticed you updated the repo to add additional ATT logging. Here is the new output:

$ sudo LOGXI=* ./bin/explorer -name="WICED Sense Kit" -sub=3s
[sudo] password for ron: 
2016/07/02 10:28:01 dev: hci0 up
2016/07/02 10:28:01 dev: hci0 reset
2016/07/02 10:28:01 dev: hci0 down
2016/07/02 10:28:01 dev: hci0 opened
10:28:01.101439 INF hci state +: AdvertisingUpdated
10:28:01.104297 INF hci state -: AdvertisingUpdated
10:28:01.104411 INF hci state +: ScanningUpdated
10:28:01.105348 INF hci state -: ScanningUpdated
10:28:01.105450 INF hci state +: Scanning
10:28:01.106340 INF hci state -: Scanning
10:28:08.241484 INF hci state +: StopScanning
10:28:08.244303 INF hci state -: StopScanning
10:28:08.244353 INF hci state +: StopScanning
10:28:08.244379 INF hci state -: StopScanning
10:28:08.244413 INF hci state +: Dialing
10:28:08.245342 INF hci state -: Dialing
10:28:08.259659 INF hci state +: StopDialing
10:28:08.259801 INF hci state -: StopDialing
Exploring Peripheral [ 20:73:77:65:43:21 ] ...
10:28:08.259961 DBG att client req: 10 01 00 FF FF 00 28
10:28:08.285068 DBG att client rsp: 11 06 01 00 01 00 01 18 14 00 18 00 00 18
10:28:08.285163 DBG att client req: 10 19 00 FF FF 00 28
10:28:08.298880 DBG att client
   rsp: 11 14 28 00 2B 00 85 89 06 8B C1 BD DC A5 84 49 B6 87 B6 98 92 73
10:28:08.298952 DBG att client req: 10 2C 00 FF FF 00 28
10:28:08.313809 DBG att client rsp: 11 06 4D 00 53 00 0A 18 61 00 63 00 0F 18
10:28:08.313882 DBG att client req: 10 64 00 FF FF 00 28
10:28:08.328913 DBG att client
   rsp: 11 14 00 FF 07 FF 36 3E 87 9A 05 80 F7 99 2E 44 4C D4 2D BC 6A A8
10:28:08.328978 DBG att client req: 10 08 FF FF FF 00 28
10:28:08.343752 DBG att client rsp: 01 10 08 FF 0A
Service: 1801 Generic Attribute
10:28:08.343819 DBG att client req: 08 01 00 01 00 03 28
10:28:08.358769 DBG att client rsp: 01 08 01 00 0A

Service: 1800 Generic Access
10:28:08.358845 DBG att client req: 08 14 00 18 00 03 28
10:28:08.373830 DBG att client
   rsp: 09 07 15 00 02 16 00 00 2A 17 00 02 18 00 01 2A
  Characteristic: 2A00, Property: 0x02 (R), Device Name
10:28:08.373915 DBG att client req: 0A 16 00
10:28:08.388868 DBG att client
   rsp: 0B 57 49 43 45 44 20 53 65 6E 73 65 20 4B 69 74 00
    Value         57494345442053656e7365204b697400 | "WICED Sense Kit\x00"
  Characteristic: 2A01, Property: 0x02 (R), Appearance
10:28:08.388939 DBG att client req: 0A 18 00
10:28:08.403743 DBG att client rsp: 0B 00 02
    Value         0002 | "\x00\x02"

Service: 739298B687B64984A5DCBDC18B068985 
10:28:08.403807 DBG att client req: 08 28 00 2B 00 03 28
10:28:08.418862 DBG att client
   rsp: 09 15 29 00 12 2A 00 59 A4 AD EA A1 FE 53 B5 3E 41 55 3B 13 91 EF 33
10:28:08.418926 DBG att client req: 08 2B 00 2B 00 03 28
10:28:08.433744 DBG att client rsp: 01 08 2B 00 0A
  Characteristic: 33EF91133B55413EB553FEA1EAADA459, Property: 0x12 (RN), 
10:28:08.433824 DBG att client req: 0A 2A 00
10:28:08.448915 DBG att client
   rsp: 0B 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    Value         0000000000000000000000000000000000000000 | "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"
10:28:08.448996 DBG att client req: 04 2B 00 2B 00
10:28:08.463747 DBG att client rsp: 05 01 2B 00 02 29
    Descriptor: 2902, Client Characteristic Configuration
10:28:08.463810 DBG att client req: 0A 2B 00
10:28:08.478804 DBG att client rsp: 0B 00 00
    Value         0000 | "\x00\x00"

-- Subscribe to notification for 3s --
10:28:08.478885 DBG att client req: 12 2B 00 01 00
10:28:09.199449 INF hci state +: PeripheralDisconnected
10:28:09.199498 INF hci state -: PeripheralDisconnected
10:28:09.199580 DBG att client rsp: 
2016/07/02 10:28:09 subscribe failed: ATT request failed: input channel closed: io: read/write on closed pipe
roylee17 commented 8 years ago

It seems that we got a SMP request without properly handling it, and the peripheral disconnects us on timeout.

> ACL data: handle 3585 flags 0x02 dlen 6
    SMP: Security Request (0x0b)
      auth req 0x01
...

> HCI Event: Disconn Complete (0x05) plen 4
    status 0x00 handle 3585 reason 0x08
    Reason: Connection Timeout

Currently, we don't support SMP. Let's at least respond a "pairing is not support" in the meantime, and see if it continues without disconnection. It might fail to reading/writing to some of Char/Desc values on that peripheral due to security though. Let me know how the current tip commit works, thanks.

deadprogram commented 8 years ago

Hi @roylee17

Just tried the latest commit, and same result with the WICED Sense: subscribe failed

roylee17 commented 8 years ago

Not sure it's the SMP packet still not handled correctly, or the peripheral refuses to move on if the security request is rejected.

I added some more logs to dump l2cap and sig for debugging. Could you try again with the tip commit, and also hcidump with -Xt flags?

deadprogram commented 8 years ago

Hi, @roylee17

Here is the new output:

$ sudo LOGXI=* ./bin/explorer -name="WICED Sense Kit" -sub="3s"
2016/07/06 11:27:06 dev: hci0 up
2016/07/06 11:27:06 dev: hci0 reset
2016/07/06 11:27:06 dev: hci0 down
2016/07/06 11:27:06 dev: hci0 opened
11:27:06.218814 INF hci state +: AdvertisingUpdated
11:27:06.221778 INF hci state -: AdvertisingUpdated
11:27:06.222020 INF hci state +: ScanningUpdated
11:27:06.222709 INF hci state -: ScanningUpdated
11:27:06.222767 INF hci state +: Scanning
11:27:06.223835 INF hci state -: Scanning
11:27:06.230785 INF hci state +: StopScanning
11:27:06.234717 INF hci state -: StopScanning
11:27:06.234758 INF hci state +: StopScanning
11:27:06.234778 INF hci state -: StopScanning
11:27:06.234812 INF hci state +: Dialing
11:27:06.235789 INF hci state -: Dialing
11:27:06.250805 INF hci state +: StopDialing
11:27:06.250855 INF hci state -: StopDialing
Exploring Peripheral [ 20:73:77:65:43:21 ] ...
11:27:06.250896 DBG att client req: 10 01 00 FF FF 00 28
11:27:06.262927 DBG hci sig recv: [0C00050012010800400060000000F401]
11:27:06.263006 DBG hci sig send: [0400050001010000]
11:27:06.263037 DBG hci sig send: [0400050001010000]
11:27:06.263448 DBG hci smp recv: [020006000B01]
11:27:06.263480 DBG hci smp send: [06000500]
11:27:06.264178 DBG att client rsp: 11 06 01 00 01 00 01 18 14 00 18 00 00 18
11:27:06.264230 DBG att client req: 10 19 00 FF FF 00 28
11:27:06.277454 DBG att client
   rsp: 11 14 28 00 2B 00 85 89 06 8B C1 BD DC A5 84 49 B6 87 B6 98 92 73
11:27:06.277540 DBG att client req: 10 2C 00 FF FF 00 28
11:27:06.292445 DBG att client rsp: 11 06 4D 00 53 00 0A 18 61 00 63 00 0F 18
11:27:06.292500 DBG att client req: 10 64 00 FF FF 00 28
11:27:06.307442 DBG att client
   rsp: 11 14 00 FF 07 FF 36 3E 87 9A 05 80 F7 99 2E 44 4C D4 2D BC 6A A8
11:27:06.307504 DBG att client req: 10 08 FF FF FF 00 28
11:27:06.322272 DBG att client rsp: 01 10 08 FF 0A
Service: 1801 Generic Attribute
11:27:06.322336 DBG att client req: 08 01 00 01 00 03 28
11:27:06.337363 DBG att client rsp: 01 08 01 00 0A

Service: 1800 Generic Access
11:27:06.337440 DBG att client req: 08 14 00 18 00 03 28
11:27:06.352528 DBG att client
   rsp: 09 07 15 00 02 16 00 00 2A 17 00 02 18 00 01 2A
  Characteristic: 2A00, Property: 0x02 (R), Device Name
11:27:06.352778 DBG att client req: 0A 16 00
11:27:06.367475 DBG att client
   rsp: 0B 57 49 43 45 44 20 53 65 6E 73 65 20 4B 69 74 00
    Value         57494345442053656e7365204b697400 | "WICED Sense Kit\x00"
  Characteristic: 2A01, Property: 0x02 (R), Appearance
11:27:06.367559 DBG att client req: 0A 18 00
11:27:06.382333 DBG att client rsp: 0B 00 02
    Value         0002 | "\x00\x02"

Service: 739298B687B64984A5DCBDC18B068985 
11:27:06.382407 DBG att client req: 08 28 00 2B 00 03 28
11:27:06.397487 DBG att client
   rsp: 09 15 29 00 12 2A 00 59 A4 AD EA A1 FE 53 B5 3E 41 55 3B 13 91 EF 33
11:27:06.397558 DBG att client req: 08 2B 00 2B 00 03 28
11:27:06.412422 DBG att client rsp: 01 08 2B 00 0A
  Characteristic: 33EF91133B55413EB553FEA1EAADA459, Property: 0x12 (RN), 
11:27:06.412604 DBG att client req: 0A 2A 00
11:27:06.427524 DBG att client
   rsp: 0B 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    Value         0000000000000000000000000000000000000000 | "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"
11:27:06.427603 DBG att client req: 04 2B 00 2B 00
11:27:06.442479 DBG att client rsp: 05 01 2B 00 02 29
    Descriptor: 2902, Client Characteristic Configuration
11:27:06.442657 DBG att client req: 0A 2B 00
11:27:06.464861 DBG att client rsp: 0B 00 00
    Value         0000 | "\x00\x00"

-- Subscribe to notification for 3s --
11:27:06.464953 DBG att client req: 12 2B 00 01 00
11:27:07.184756 INF hci state +: PeripheralDisconnected
11:27:07.184802 INF hci state -: PeripheralDisconnected
11:27:07.184845 DBG att client rsp: 
2016/07/06 11:27:07 subscribe failed: ATT request failed: input channel closed: io: read/write on closed pipe

Attached is the HCIDUMP file.

Thanks! wiced-dump.txt

roylee17 commented 8 years ago

Give it another shot, and if it still not working, I'll put more effort tomorrow. Thanks for reporting and those nice logs.

deadprogram commented 8 years ago

Same error even with the updated code.

roylee17 commented 8 years ago

There should be at least some difference in the log/hcidump. I'd like to see if we did respond a legit SMP reject packet, and the peripheral decide to not move on, or we didn't craft the packet correctly.

Also, since noble works in this case, a log&hcidump may help to find the difference.

roylee17 commented 8 years ago

BTW, which model of WICED kit are you using, and what other devices you're testing? I can get some of those and reproduce the issues locally.

deadprogram commented 8 years ago

I am using the v1 WICED Sense tag for this particular bug report.

More generally, I have many different BLE devices. The particular ones I'm using for quick testing are:

deadprogram commented 7 years ago

This issue is just too out of date with the state of the current code. Closing to get out of the way.