Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unexpected response. Expected Read By Group Response got Read By Type Request #34

Open
bgromov opened this issue Aug 22, 2018 · 17 comments

Comments

@bgromov
Copy link

bgromov commented Aug 22, 2018

I am getting the following error when attempt to connect to some devices:

Unexpected response. Expected Read By Group Response got Read By Type Request

At the same time I am able to connect to the same device with the gatttool, like so:

$ gatttool -I -t random -b AA:BB:CC:DD:EE:FF

and can list, read, and write characteristics.

One of the affected devices is Adafruit Feather nRF52 Bluefruit based on Nordic nRF52832 chip. Interesting that there are no problems with another device (mbientlab MetaMotion R) that is also based on Nordic nRF52 chip. The other device that fail to connect is iPhone 7 with the virtual device advertised via the LightBlue Explorer; I tried couple of different combinations of advertised services/characteristics, but it fails in all the cases.

Note: I am using libblepp via Warble library of mbientlab (it connects using random address as well).

OS: Ubuntu 18.04
Bluez: v5.48 / v5.50 (tried both)
BLE dongle: CSR 4.0

Any idea what can be the problem?

bgromov added a commit to bgromov/neopixel_ble that referenced this issue Aug 27, 2018
While the libblepp bug on Linux is not fixed we will fallback to bluepy
(See libblepp issue here edrosten/libblepp#34)
@edrosten
Copy link
Owner

edrosten commented Sep 5, 2018

Hi, sorry for the slow response. Is this still causing a problem? If so, would you be able to run the library in super verbose mode and paste the log?

@bgromov
Copy link
Author

bgromov commented Sep 5, 2018

Yes, certainly. How can I enable this mode?

Side note: I am now sporadically having the same problem with bluepy (unexpected response), also with the Bluez v5.50 but on Ubuntu 16.04. On Ubuntu 18.04 it still seams to run without problems. This mainly happens when I initiate connections simultaneously to multiple devices, so I had to add little random delay on startup for each peripheral.

@edrosten
Copy link
Owner

edrosten commented Sep 5, 2018 via email

@bgromov
Copy link
Author

bgromov commented Sep 6, 2018

It didn't produce that much output, basically it fails on connect:

Connecting to E3:BF:35:60:19:36
info  1536227335.956335 log_fd_: Socket success: 226 (src/blestatemachine.cc)
info  1536227335.956446 log_fd_: Socket success: 269 (src/blestatemachine.cc)
info  1536227335.956501 log_fd_: Socket success: 174 (src/blestatemachine.cc)
info  1536227335.956552 log_l2cap_options: options.omtu = 672
info  1536227335.956596 log_l2cap_options: options.imtu = 672
info  1536227335.956657 log_l2cap_options: options.flush_to = 65535
info  1536227335.956699 log_l2cap_options: options.mode = 0
info  1536227335.956748 log_l2cap_options: options.fcs = 1
info  1536227335.956797 log_l2cap_options: options.max_tx = 3
info  1536227335.956841 log_l2cap_options: options.txwin_size = 63
debug 1536227335.956901 connect: address = E3:BF:35:60:19:36
debug 1536227335.956944 connect: str2ba = 0
error 1536227335.957011 log_fd_: Error on line: 296 (src/blestatemachine.cc): Operation now in progress
debug 1536227336.335788 write_and_process_next: State is: 1
info  1536227336.335866 log_fd_: Socket success: 488 (src/blestatemachine.cc)
info  1536227336.335929 write_and_process_next: errval = Success
debug 1536227336.336002 test_fd_: System call on 112( src/bledevice.cc): Operation now in progress ret = 7
debug 1536227336.385066 test_fd_: System call on 155( src/bledevice.cc): Operation now in progress ret = 7
debug: ---PDU packet ---
debug: 08 01 00 ff ff 00 2a 
debug: \x08\x01\x00\xff\xff\x00*
debug: Packet type: 08 Read By Type Request
debug: --no pretty printer available--
debug:
error 1536227336.385405 read_and_process_next: Unexpected response. Expected Read By Group Response got Read By Type Request
info  1536227336.385518 log_fd_: Socket success: 151 (src/blestatemachine.cc)
^C

Hope it helps.

Thanks

@bgromov
Copy link
Author

bgromov commented Sep 6, 2018

Here is a slightly longer log for a virtual device on iPhone made with LightBlue app:

Connecting to 5c:94:a0:ae:9b:49
info  1536229712.481205 log_fd_: Socket success: 226 (src/blestatemachine.cc)
info  1536229712.481339 log_fd_: Socket success: 269 (src/blestatemachine.cc)
info  1536229712.481421 log_fd_: Socket success: 174 (src/blestatemachine.cc)
info  1536229712.481521 log_l2cap_options: options.omtu = 672
info  1536229712.481588 log_l2cap_options: options.imtu = 672
info  1536229712.481649 log_l2cap_options: options.flush_to = 65535
info  1536229712.481710 log_l2cap_options: options.mode = 0
info  1536229712.481768 log_l2cap_options: options.fcs = 1
info  1536229712.481833 log_l2cap_options: options.max_tx = 3
info  1536229712.481894 log_l2cap_options: options.txwin_size = 63
debug 1536229712.481956 connect: address = 5c:94:a0:ae:9b:49
debug 1536229712.482014 connect: str2ba = 0
error 1536229712.482090 log_fd_: Error on line: 296 (src/blestatemachine.cc): Operation now in progress
debug 1536229712.677915 write_and_process_next: State is: 1
info  1536229712.677996 log_fd_: Socket success: 488 (src/blestatemachine.cc)
info  1536229712.678060 write_and_process_next: errval = Success
debug 1536229712.678151 test_fd_: System call on 112( src/bledevice.cc): Operation now in progress ret = 7
debug 1536229712.776831 test_fd_: System call on 155( src/bledevice.cc): Operation now in progress ret = 14
debug: ---PDU packet ---
debug: 11 06 01 00 05 00 00 18 06 00 09 00 01 18
debug: \x11\x06\x01\x00\x05\x00\x00\x18\x06\x00\x09\x00\x01\x18
debug: Packet type: 11 Read By Group Response
debug: elements = 2
debug: value size = 2
debug: [ 0001, 0005) :\x00\x18
debug: [ 0006, 0009) :\x01\x18
debug:                             
debug 1536229712.777372 test_fd_: System call on 112( src/bledevice.cc): Operation now in progress ret = 7
debug 1536229712.777500 test_fd_: System call on 155( src/bledevice.cc): Operation now in progress ret = 7
debug: ---PDU packet ---
debug: 10 01 00 ff ff 00 28
debug: \x10\x01\x00\xff\xff\x00(
debug: Packet type: 10 Read By Group Request
debug: --no pretty printer available--
debug:
error 1536229712.777748 read_and_process_next: Unexpected response. Expected Read By Group Response got Read By Group Request
info  1536229712.777826 log_fd_: Socket success: 151 (src/blestatemachine.cc)
^C

@edrosten
Copy link
Owner

edrosten commented Oct 7, 2018

Sorry for the rather slow response, things have been a bit busy recently.

This is very odd, and I don't really understand what's going on. It looks like the ble device is replying to your laptop with a request to read data which shouldn't happen.

As best I can see no only should that device never send one of those packets, it's not even a well formed packet (maybe). It appears to be trying to read a 32 bit UUID. My version of the standard (admittedly old) allows or only 16 and 128 bit UUIDs for those packets.

I don't think my tool has quite enough logging to debug this problem. Would you be able to run an HCI sniffer?

The options are hcidump or btmon. I weakly prefer the latter since it has nice syntax highlighting. If you could capture highlighted packet dumps that would be really great, but anything would help at this point.

@edrosten
Copy link
Owner

edrosten commented Oct 7, 2018

Additional:

It's trying to read a 32 bit UUID with the ID ffff0028. Or more likely 2800ffff. Does that have any significance to you?

@bgromov
Copy link
Author

bgromov commented Feb 23, 2019

Sorry, took me a while to get back to this problem.

Additional:

It's trying to read a 32 bit UUID with the ID ffff0028. Or more likely 2800ffff. Does that have any significance to you?

I don't do anything like this explicitly, though I am not sure how it is implemented in the underlying Warble library. The custom characteristics I am trying to access are all 128-bit, plus a standard Battery characteristic that is 16-bit.

Below is the dump from btmon (here is pastebin as well) while I was attempting to connect to a real device:

demo@demo:~$ sudo btmon
Bluetooth monitor ver 5.50
= New Index: 00:15:83:EC:7F:7C (Primary,USB,hci0)                                                                                                                                           [hci0] 0.735072
= Open Index: 00:15:83:EC:7F:7C                                                                                                                                                             [hci0] 0.735072
= Index Info: 00:15:83:EC:7F:7C (Cambridge Silicon Radio)                                                                                                                                   [hci0] 0.735073
< HCI Command: LE Add Device To White List (0x08|0x0011) plen 7                                                                                                                          #1 [hci0] 6.488065
        Address type: Random (0x01)
        Address: ED:AE:B7:BB:59:C2 (Static)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                              #2 [hci0] 6.489001
      LE Add Device To White List (0x08|0x0011) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7                                                                                                                               #3 [hci0] 6.489044
        Type: Passive (0x00)
        Interval: 60.000 msec (0x0060)
        Window: 30.000 msec (0x0030)
        Own address type: Public (0x00)
        Filter policy: Ignore not in white list (0x01)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                              #4 [hci0] 6.490020
      LE Set Scan Parameters (0x08|0x000b) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2                                                                                                                                   #5 [hci0] 6.490090
        Scanning: Enabled (0x01)
        Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                              #6 [hci0] 6.492002
      LE Set Scan Enable (0x08|0x000c) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 43                                                                                                                                                #7 [hci0] 6.575130
      LE Advertising Report (0x02)
        Num reports: 1
        Event type: Connectable undirected - ADV_IND (0x00)
        Address type: Random (0x01)
        Address: ED:AE:B7:BB:59:C2 (Static)
        Data length: 31
        Flags: 0x06
          LE General Discoverable Mode
          BR/EDR Not Supported
        TX power: 0 dBm
        128-bit Service UUIDs (complete): 1 entry
          Vendor specific (427c0000-97c7-413b-8de7-490917d220aa)
        Name (short): NeoPi
        RSSI: -85 dBm (0xab)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2                                                                                                                                   #8 [hci0] 6.575198
        Scanning: Disabled (0x00)
        Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                                              #9 [hci0] 6.581184
      LE Set Scan Enable (0x08|0x000c) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25                                                                                                                               #10 [hci0] 6.581266
        Scan interval: 60.000 msec (0x0060)
        Scan window: 60.000 msec (0x0060)
        Filter policy: White list is not used (0x00)
        Peer address type: Random (0x01)
        Peer address: ED:AE:B7:BB:59:C2 (Static)
        Own address type: Public (0x00)
        Min connection interval: 50.00 msec (0x0028)
        Max connection interval: 70.00 msec (0x0038)
        Connection latency: 0 (0x0000)
        Supervision timeout: 420 msec (0x002a)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4                                                                                                                                               #11 [hci0] 6.588942
      LE Create Connection (0x08|0x000d) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19                                                                                                                                               #12 [hci0] 6.741112
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 70
        Role: Master (0x00)
        Peer address type: Random (0x01)
        Peer address: ED:AE:B7:BB:59:C2 (Static)
        Connection interval: 70.00 msec (0x0038)
        Connection latency: 0 (0x0000)
        Supervision timeout: 420 msec (0x002a)
        Master clock accuracy: 0x00
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2                                                                                                                        #13 [hci0] 6.741331
        Handle: 70
@ Device Connected: ED:AE:B7:BB:59:C2 (2) flags 0x0000
        02 01 06 02 0a 00 11 07 aa 20 d2 17 09 49 e7 8d  ......... ...I..
        3b 41 c7 97 00 00 7c 42 06 08 4e 65 6f 50 69     ;A....|B..NeoPi
> HCI Event: Command Status (0x0f) plen 4                                                                                                                                               #14 [hci0] 6.746930
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
> ACL Data RX: Handle 70 flags 0x02 dlen 16                                                                                                                                             #15 [hci0] 6.795015
      LE L2CAP: Connection Parameter Update Request (0x12) ident 3 len 8
        Min interval: 12
        Max interval: 16
        Slave latency: 0
        Timeout multiplier: 200
> HCI Event: LE Meta Event (0x3e) plen 12                                                                                                                                               #16 [hci0] 6.866163
      LE Read Remote Used Features (0x04)
        Status: Success (0x00)
        Handle: 70
        Features: 0x01 0x41 0x00 0x00 0x00 0x00 0x00 0x00
          LE Encryption
          LE 2M PHY
          Channel Selection Algorithm #2
< ACL Data TX: Handle 70 flags 0x00 dlen 10                                                                                                                                             #17 [hci0] 6.866249
      LE L2CAP: Connection Parameter Update Response (0x13) ident 3 len 2
        Result: Connection Parameters accepted (0x0000)
< HCI Command: LE Connection Update (0x08|0x0013) plen 14                                                                                                                               #18 [hci0] 6.866258
        Handle: 70
        Min connection interval: 15.00 msec (0x000c)
        Max connection interval: 20.00 msec (0x0010)
        Connection latency: 0 (0x0000)
        Supervision timeout: 2000 msec (0x00c8)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #19 [hci0] 6.866332
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
@ New Conn Param: ED:AE:B7:BB:59:C2 (2) hint 0 min 0x000c max 0x0010 latency 0x0000 timeout 0x00c8
> HCI Event: Command Status (0x0f) plen 4                                                                                                                                               #20 [hci0] 6.867976
      LE Connection Update (0x08|0x0013) ncmd 1
        Status: Success (0x00)
> ACL Data RX: Handle 70 flags 0x02 dlen 11                                                                                                                                             #21 [hci0] 6.934889
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Device Name (0x2a00)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #22 [hci0] 7.075167
        Num handles: 1
        Handle: 70
        Count: 1
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #23 [hci0] 7.152191
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 18                                                                                                                                             #24 [hci0] 7.214947
      ATT: Read By Group Type Response (0x11) len 13
        Attribute data length: 6
        Attribute group list: 2 entries
        Handle range: 0x0001-0x0009
        UUID: Generic Access Profile (0x1800)
        Handle range: 0x000a-0x000d
        UUID: Generic Attribute Profile (0x1801)
> HCI Event: LE Meta Event (0x3e) plen 10                                                                                                                                               #25 [hci0] 7.424003
      LE Connection Update Complete (0x03)
        Status: Success (0x00)
        Handle: 70
        Connection interval: 20.00 msec (0x0010)
        Connection latency: 0 (0x0000)
        Supervision timeout: 2000 msec (0x00c8)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #26 [hci0] 7.939550
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #27 [hci0] 7.945107
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 18                                                                                                                                             #28 [hci0] 7.964922
      ATT: Read By Group Type Response (0x11) len 13
        Attribute data length: 6
        Attribute group list: 2 entries
        Handle range: 0x0001-0x0009
        UUID: Generic Access Profile (0x1800)
        Handle range: 0x000a-0x000d
        UUID: Generic Attribute Profile (0x1801)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #29 [hci0] 7.965115
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x000e-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #30 [hci0] 7.985106
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 26                                                                                                                                             #31 [hci0] 8.004964
      ATT: Read By Group Type Response (0x11) len 21
        Attribute data length: 20
        Attribute group list: 1 entry
        Handle range: 0x000e-0x0015
        UUID: Vendor specific (00001530-1212-efde-1523-785feabcd123)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #32 [hci0] 8.005128
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0016-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #33 [hci0] 8.025159
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 18                                                                                                                                             #34 [hci0] 8.044984
      ATT: Read By Group Type Response (0x11) len 13
        Attribute data length: 6
        Attribute group list: 2 entries
        Handle range: 0x0016-0x0020
        UUID: Device Information (0x180a)
        Handle range: 0x0021-0x0024
        UUID: Battery Service (0x180f)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #35 [hci0] 8.045211
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0025-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #36 [hci0] 8.064996
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 26                                                                                                                                             #37 [hci0] 8.085071
      ATT: Read By Group Type Response (0x11) len 21
        Attribute data length: 20
        Attribute group list: 1 entry
        Handle range: 0x0025-0x002c
        UUID: Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #38 [hci0] 8.085309
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x002d-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #39 [hci0] 8.105144
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 26                                                                                                                                             #40 [hci0] 8.125022
      ATT: Read By Group Type Response (0x11) len 21
        Attribute data length: 20
        Attribute group list: 1 entry
        Handle range: 0x002d-0xffff
        UUID: Vendor specific (427c0000-97c7-413b-8de7-490917d220aa)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #41 [hci0] 8.125243
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #42 [hci0] 8.145175
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #43 [hci0] 8.165096
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 7
        Attribute data list: 3 entries
        Handle: 0x0002
        Value: 0a0300002a
        Handle: 0x0004
        Value: 020500012a
        Handle: 0x0006
        Value: 020700042a
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #44 [hci0] 8.165345
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0007-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #45 [hci0] 8.185176
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 20                                                                                                                                             #46 [hci0] 8.204923
      ATT: Read By Type Response (0x09) len 15
        Attribute data length: 7
        Attribute data list: 2 entries
        Handle: 0x0008
        Value: 020900a62a
        Handle: 0x000b
        Value: 200c00052a
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #47 [hci0] 8.205150
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x000c-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #48 [hci0] 8.245175
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #49 [hci0] 8.245443
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x000f
        Value: 04100023d1bcea5f782315deef121232150000
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #50 [hci0] 8.245642
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0010-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #51 [hci0] 8.265176
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #52 [hci0] 8.291649
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x0011
        Value: 18120023d1bcea5f782315deef121231150000
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #53 [hci0] 8.291877
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0012-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #54 [hci0] 8.305175
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #55 [hci0] 8.345096
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x0014
        Value: 02150023d1bcea5f782315deef121234150000
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #56 [hci0] 8.345323
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0015-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #57 [hci0] 8.365022
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #58 [hci0] 8.385003
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 7
        Attribute data list: 3 entries
        Handle: 0x0017
        Value: 021800242a
        Handle: 0x0019
        Value: 021a00252a
        Handle: 0x001b
        Value: 021c00262a
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #59 [hci0] 8.385233
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x001c-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #60 [hci0] 8.404983
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #61 [hci0] 8.425082
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 7
        Attribute data list: 3 entries
        Handle: 0x001d
        Value: 021e00282a
        Handle: 0x001f
        Value: 022000292a
        Handle: 0x0022
        Value: 122300192a
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #62 [hci0] 8.425309
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0023-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #63 [hci0] 8.445178
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #64 [hci0] 8.465098
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x0026
        Value: 1027009ecadc240ee5a9e093f3a3b50300406e
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #65 [hci0] 8.465328
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0027-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #66 [hci0] 8.485178
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #67 [hci0] 8.504898
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x002a
        Value: 0c2b009ecadc240ee5a9e093f3a3b50200406e
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #68 [hci0] 8.505032
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x002b-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #69 [hci0] 8.525153
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #70 [hci0] 8.545099
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x002e
        Value: 0a2f00aa20d2170949e78d3b41c79701107c42
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #71 [hci0] 8.545297
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x002f-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #72 [hci0] 8.565173
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #73 [hci0] 8.605096
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x0030
        Value: 0a3100aa20d2170949e78d3b41c79702107c42
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #74 [hci0] 8.605328
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0031-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #75 [hci0] 8.625135
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 27                                                                                                                                             #76 [hci0] 8.651679
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 21
        Attribute data list: 1 entry
        Handle: 0x0032
        Value: 0a3300aa20d2170949e78d3b41c797ff107c42
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #77 [hci0] 8.651906
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0033-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #78 [hci0] 8.665185
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 9                                                                                                                                              #79 [hci0] 8.684843
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0033
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #80 [hci0] 8.685063
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Client Characteristic Configuration (0x2902)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #81 [hci0] 8.705172
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 22                                                                                                                                             #82 [hci0] 8.785040
      ATT: Read By Type Response (0x09) len 17
        Attribute data length: 4
        Attribute data list: 4 entries
        Handle: 0x000d
        Value: 0000
        Handle: 0x0013
        Value: 0000
        Handle: 0x0024
        Value: 0000
        Handle: 0x0028
        Value: 0000
< ACL Data TX: Handle 70 flags 0x00 dlen 11                                                                                                                                             #83 [hci0] 8.785237
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0029-0xffff
        Attribute type: Client Characteristic Configuration (0x2902)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #84 [hci0] 8.805096
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 9                                                                                                                                              #85 [hci0] 8.844826
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0029
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 70 flags 0x00 dlen 7                                                                                                                                              #86 [hci0] 8.847891
      ATT: Read Request (0x0a) len 2
        Handle: 0x002f
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                                                  #87 [hci0] 8.864973
        Num handles: 1
        Handle: 70
        Count: 1
> ACL Data RX: Handle 70 flags 0x02 dlen 9                                                                                                                                              #88 [hci0] 8.884730
      ATT: Read Response (0x0b) len 4
        Value: 181e5200
< HCI Command: Disconnect (0x01|0x0006) plen 3                                                                                                                                         #89 [hci0] 10.996243
        Handle: 70
        Reason: Remote User Terminated Connection (0x13)
> HCI Event: Command Status (0x0f) plen 4                                                                                                                                              #90 [hci0] 10.998100
      Disconnect (0x01|0x0006) ncmd 1
        Status: Success (0x00)
> HCI Event: Disconnect Complete (0x05) plen 4                                                                                                                                         #91 [hci0] 11.006022
        Status: Success (0x00)
        Handle: 70
        Reason: Connection Terminated By Local Host (0x16)
@ Device Disconnected: ED:AE:B7:BB:59:C2 (2) reason 2

@edrosten
Copy link
Owner

edrosten commented Feb 25, 2019 via email

@XavierXin
Copy link

XavierXin commented Mar 17, 2019

Having the same issue. My program is a variance of example:


#include <iostream>
#include <iomanip>
#include <blepp/blestatemachine.h>
#include <blepp/float.h>  //BLE uses the obscure IEEE11073 decimal exponent floating point values
#include <unistd.h>
#include <thread>
#include <chrono>
#include <mutex>
#include <blepp/logging.h>

using namespace std;
using namespace chrono;
using namespace BLEPP;

int main(int argc, char **argv)
{
	log_level = Debug;

	BLEGATTStateMachine gatt;

    std::function<void()> connected_cb = [&gatt](){
        cerr << "connected\n ";
        gatt.read_primary_services();
        cerr << "service discovery called.\n ";
    };
    std::function<void()> services_read_cb = [&gatt](){
        cerr << "service discovered\n ";
        gatt.find_all_characteristics();
    };
    std::function<void()> find_characteristics_cb = [&gatt](){
        cerr << "char discovered\n ";
        gatt.get_client_characteristic_configuration();
    };
    std::function<void()> cb_get_client_characteristic_configuration = [&gatt](){	
        cerr << "char discovered ";
        for(auto& service: gatt.primary_services) {
            cerr << "Found service, type: " << service.uuid.type;
			for(auto& characteristic: service.characteristics) {
                cerr << "Found characteristic, type: " << service.uuid.type;
            }
        }
    };
	
	gatt.cb_connected = connected_cb;
    gatt.cb_services_read = services_read_cb;
    gatt.cb_find_characteristics = find_characteristics_cb;
    gatt.cb_get_client_characteristic_configuration = cb_get_client_characteristic_configuration;

	//I think this one is reasonably clear?
	gatt.cb_disconnected = [](BLEGATTStateMachine::Disconnect d) {
		if(d.reason != BLEGATTStateMachine::Disconnect::ConnectionClosed)
		{
			cerr << "Disconnect for reason " << BLEGATTStateMachine::get_disconnect_string(d) << endl;
			exit(1);
		}
		else
			exit(0);
	};
	
	//This is how to use the blocking interface. It is very simple. You provide the main 
	//loop and just hammer on the state machine struct. 
	gatt.connect_blocking("00:25:DF:1B:43:23");

    cerr << "connect blocking returned\n";

    for(;;) gatt.read_and_process_next();
	
    std::this_thread::sleep_for(seconds(20));
}

The log is here (services_read_cb never got called)

info  1552790293.804509 log_fd_: Socket success: 224 (/home/pi/libblepp/src/blestatemachine.cc)
info  1552790293.810488 log_fd_: Socket success: 269 (/home/pi/libblepp/src/blestatemachine.cc)
info  1552790293.811675 log_fd_: Socket success: 174 (/home/pi/libblepp/src/blestatemachine.cc)
info  1552790293.813169 log_l2cap_options: options.omtu = 672
info  1552790293.814296 log_l2cap_options: options.imtu = 672
info  1552790293.815518 log_l2cap_options: options.flush_to = 65535
info  1552790293.816577 log_l2cap_options: options.mode = 0
info  1552790293.817614 log_l2cap_options: options.fcs = 1
info  1552790293.818642 log_l2cap_options: options.max_tx = 3
info  1552790293.820075 log_l2cap_options: options.txwin_size = 63
debug 1552790293.821188 connect: address = 00:25:DF:1B:43:23
debug 1552790293.822194 connect: str2ba = 0
info  1552790297.527470 log_fd_: Socket success: 296 (/home/pi/libblepp/src/blestatemachine.cc)
info  1552790297.527762 log_fd_: Socket success: 174 (/home/pi/libblepp/src/blestatemachine.cc)
info  1552790297.527957 log_l2cap_options: options.omtu = 672
info  1552790297.528129 log_l2cap_options: options.imtu = 672
info  1552790297.528296 log_l2cap_options: options.flush_to = 65535
info  1552790297.528461 log_l2cap_options: options.mode = 0
info  1552790297.528622 log_l2cap_options: options.fcs = 1
info  1552790297.528783 log_l2cap_options: options.max_tx = 3
info  1552790297.528947 log_l2cap_options: options.txwin_size = 63
connected
 debug 1552790297.532178 test_fd_: System call on 112( /home/pi/libblepp/src/bledevice.cc): Success ret = 7
service discovery called.
 connect blocking returned
debug 1552790297.624782 test_fd_: System call on 220( /home/pi/libblepp/src/bledevice.cc): Success ret = 7
debug: ---PDU packet ---
debug: 10 01 00 ff ff 00 28 
debug: \x10\x01\x00\xff\xff\x00(
debug: Packet type: 10 Read By Group Request
debug: --no pretty printer available--
debug:
error 1552790297.633151 read_and_process_next: Unexpected response. Expected Read By Group Response got Read By Group Request
info  1552790297.634732 log_fd_: Socket success: 151 (/home/pi/libblepp/src/blestatemachine.cc)
Disconnect for reason Unexpected Response.

Any help is appreciated!

I am on Raspberry Pi, and i was able to read primary service by gatttool

@edrosten
Copy link
Owner

edrosten commented Mar 18, 2019 via email

@bgromov
Copy link
Author

bgromov commented Mar 24, 2019

I'm having a lot of difficulty debugging this without a device to try.

@edrosten If you have access to an Apple iPhone/iPad, you could get the same error with a virtual peripheral (as I mentioned here). It happens even with a virtual Heart Rate sensor which has very few services. You can create one with the free LightBlue Explorer app.

@edrosten
Copy link
Owner

edrosten commented Mar 25, 2019 via email

@WeekendWar
Copy link

Any movement on this issue? I'm seeing the same problem when trying to connect to an RPI 3B+ running the bluez 5.50 example-advertisement and example-gatt-server Python apps that come with bluez 5.50. Works find if I subscribe to the service using bluepy on another RPI 3B+ or from the nRF Connect app on my Galaxy S10. Is there any easy way to just throw away the unexpected Read By Group Type Request and move on? Looking in a wireshark capture, it appears the expected Read By Group Type Response is the next packet in the chute.
I attached the file. The extension should be pcapng, but that was an unrecognized type so I changed it to txt. The pcapng contains the details for the screenshot. Hope it helps debug the issue. Appreciate it your efforts.
image

libblepp_ReadByGroupTypeRequestUnexpected.txt

@edrosten
Copy link
Owner

edrosten commented Aug 8, 2019 via email

@dylanetaft
Copy link
Contributor

dylanetaft commented Aug 8, 2019 via email

@mengguang
Copy link

same problem on NRF52832 device.

info 1575713182.960487 log_fd_: Socket success: 224 (/root/src/libblepp/src/blestatemachine.cc)
info 1575713182.960731 log_fd_: Socket success: 269 (/root/src/libblepp/src/blestatemachine.cc)
info 1575713182.960816 log_fd_: Socket success: 174 (/root/src/libblepp/src/blestatemachine.cc)
info 1575713182.960884 log_l2cap_options: options.omtu = 672
info 1575713182.960941 log_l2cap_options: options.imtu = 672
info 1575713182.960992 log_l2cap_options: options.flush_to = 65535
info 1575713182.961041 log_l2cap_options: options.mode = 0
info 1575713182.961087 log_l2cap_options: options.fcs = 1
info 1575713182.961130 log_l2cap_options: options.max_tx = 3
info 1575713182.961180 log_l2cap_options: options.txwin_size = 63
debug 1575713182.961242 connect: address = e3:e1:30:d5:55:0a
debug 1575713182.961292 connect: str2ba = 0
info 1575713183.718725 log_fd_: Socket success: 296 (/root/src/libblepp/src/blestatemachine.cc)
info 1575713183.718981 log_fd_: Socket success: 174 (/root/src/libblepp/src/blestatemachine.cc)
info 1575713183.719133 log_l2cap_options: options.omtu = 672
info 1575713183.719253 log_l2cap_options: options.imtu = 672
info 1575713183.719356 log_l2cap_options: options.flush_to = 65535
info 1575713183.719474 log_l2cap_options: options.mode = 0
info 1575713183.719585 log_l2cap_options: options.fcs = 1
info 1575713183.719694 log_l2cap_options: options.max_tx = 3
info 1575713183.719796 log_l2cap_options: options.txwin_size = 63
debug 1575713183.720015 test_fd_: System call on 112( /root/src/libblepp/src/bledevice.cc): Success ret = 7
debug 1575713183.767214 test_fd_: System call on 220( /root/src/libblepp/src/bledevice.cc): Success ret = 7
debug: ---PDU packet ---
debug: 08 01 00 ff ff 00 2a
debug: \x08\x01\x00\xff\xff\x00*
debug: Packet type: 08 Read By Type Request
debug: --no pretty printer available--
debug:
error 1575713183.768088 read_and_process_next: Unexpected response. Expected Read By Group Response got Read By Type Request
info 1575713183.768273 log_fd_: Socket success: 151 (/root/src/libblepp/src/blestatemachine.cc)
Disconnect for reason Unexpected Response.

Process finished with exit code 1

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants