linux-bluetooth.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* Instable BLE connection - MTU Request, Attribute not found
       [not found] <CAJgPF1JLw40nRXyoXyuGd9hNLWCDeD4ONVM7S_CSE9wQg3gvyA@mail.gmail.com>
@ 2021-07-26 10:56 ` Peter Höller
  2021-07-26 15:34   ` Emil Lenngren
  0 siblings, 1 reply; 4+ messages in thread
From: Peter Höller @ 2021-07-26 10:56 UTC (permalink / raw)
  To: linux-bluetooth

Hello!

My name is peter. This is probably a bit off topic but:
Since about 2 years I am working ambitiously on connecting a GoPro to
an Odroid via HTTP, UDP and BLE in order to get a powerful node-red
controlled dashcam/balckbox for my cars (fleet control).
(please see: https://github.com/cepoon/GoProRemote,
https://github.com/KonradIT/goprowifihack,
https://github.com/sepp89117/GoPro-Multiple-Smart-Remote-ESP8266)

However I stumbled over a thread: #96, which's owner forwarded me to
your mailing list as my last resort:

and figured that you are deep into debugging of BLE connections.

because of our long developement period we are "stuck" in a somewhat
older hardware/kernel  config, unfortunately:

Odroid C2 with BluetoothModule2 (CSR8510 A10)
Ubuntu 18.04 (Kernel 3.16.85+)
WifiModule 5A (concurrent mode (STA+Client) on hostapd 2.9)
Bluez 5.53
btusb 0.7
(- GoPro Hero5 black)

However, we do suffer from an comparable annoying problem since more
than a year(!). We do have an unstable BLE Connection between Dongle
and Gopro. When just paired, the first connection stays up for about
30mins (abortion the is not btmon-itored yet, but can be done), but
the reconnect is a problem: gets connected but after 2 - 15 sec:
disconnect. Mainly because of:

#Issue 1: (btmon) Why is it disconnecting after MTU request?
@ Discovering: 0x00 (6)

HCI Event: Command Status (0x0f) plen 4 #111 [hci0] 55.051270
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
HCI Event: LE Meta Event (0x3e) plen 19 #112 [hci0] 55.626431
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 71
Role: Master (0x00)
Peer address type: Random (0x01)
Peer address: C9:0F:D9:47:48:B4 (Static)
Connection interval: 70.00 msec (0x0038)
Connection latency: 0 (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
@ Device Connected: C9:0F:D9:47:48:B4 (2) flags 0x0000
<< ACL Data TX: Handle 71 flags 0x00 dlen 7 #113 [hci0] 55.627789
ATT: Exchange MTU Request (0x02) len 2
Client RX MTU: 517
HCI Event: Disconnect Complete (0x05) plen 4 #114 [hci0] 56.035562
Status: Success (0x00)
Handle: 71
Reason: Connection Failed to be Established (0x3e)
@ Device Disconnected: C9:0F:D9:47:48:B4 (2) reason 0

#issue 2: btmon: Error: Timeout/ Disconnect after attribute not
found!? (main issue obviously)
@ Discovering: 0x00 (6)
<< HCI Command: LE Create Connect.. (0x08|0x000d) plen 25 #102 [hci0] 21.277573
Scan interval: 60.000 msec (0x0060)
Scan window: 30.000 msec (0x0030)
Filter policy: White list is not used (0x00)
Peer address type: Random (0x01)
Peer address: C9:0F:D9:47:48:B4 (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 #103 [hci0] 21.281234
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
HCI Event: LE Meta Event (0x3e) plen 19 #104 [hci0] 21.474300
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 71
Role: Master (0x00)
Peer address type: Random (0x01)
Peer address: C9:0F:D9:47:48:B4 (Static)
Connection interval: 70.00 msec (0x0038)
Connection latency: 0 (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
@ Device Connected: C9:0F:D9:47:48:B4 (2) flags 0x0000
<< ACL Data TX: Handle 71 flags 0x00 dlen 7 #105 [hci0] 21.475604
ATT: Exchange MTU Request (0x02) len 2
Client RX MTU: 517
HCI Event: Number of Completed Packets (0x13) plen 5 #106 [hci0] 21.786387
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 7 #107 [hci0] 21.849441
ATT: Exchange MTU Response (0x03) len 2
Server RX MTU: 517
<< ACL Data TX: Handle 71 flags 0x00 dlen 7 #108 [hci0] 21.849849
ATT: Read Request (0x0a) len 2
Handle: 0x0004
HCI Event: Number of Completed Packets (0x13) plen 5 #109 [hci0] 21.919448
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 15 #110 [hci0] 21.989485
ATT: Read Response (0x0b) len 10
Value: 476f50726f2038353339
<< ACL Data TX: Handle 71 flags 0x00 dlen 7 #111 [hci0] 21.989865
ATT: Read Request (0x0a) len 2
Handle: 0x0006
HCI Event: Number of Completed Packets (0x13) plen 5 #112 [hci0] 22.059476
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 7 #113 [hci0] 22.135894
ATT: Read Response (0x0b) len 2
Value: 8000
<< ACL Data TX: Handle 71 flags 0x00 dlen 7 #114 [hci0] 22.136253
ATT: Read Request (0x0a) len 2
Handle: 0x000e
HCI Event: Number of Completed Packets (0x13) plen 5 #115 [hci0] 22.199508
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 6 #116 [hci0] 22.269695
ATT: Read Response (0x0b) len 1
Value: 05
<< ACL Data TX: Handle 71 flags 0x00 dlen 7 #117 [hci0] 22.270106
ATT: Read Request (0x0a) len 2
Handle: 0x0020
HCI Event: Number of Completed Packets (0x13) plen 5 #118 [hci0] 22.339554
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 12 #119 [hci0] 22.409721
ATT: Read Response (0x0b) len 7
Value: 00000000000000
<< ACL Data TX: Handle 71 flags 0x00 dlen 11 #120 [hci0] 22.410113
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 #121 [hci0] 22.479592
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 27 #122 [hci0] 22.549760
ACL Data RX: Handle 71 flags 0x01 dlen 9 #123 [hci0] 22.551041
ATT: Read By Group Type Response (0x11) len 31
Attribute data length: 6
Attribute group list: 5 entries
Handle range: 0x0001-0x0001
UUID: Generic Attribute Profile (0x1801)
Handle range: 0x0002-0x0008
UUID: Generic Access Profile (0x1800)
Handle range: 0x0009-0x000b
UUID: Tx Power (0x1804)
Handle range: 0x000c-0x000f
UUID: Battery Service (0x180f)
Handle range: 0x0010-0x0020
UUID: Device Information (0x180a)
<< ACL Data TX: Handle 71 flags 0x00 dlen 9 #124 [hci0] 22.551281
ATT: Write Request (0x12) len 4
Handle: 0x000f
Data: 0100
HCI Event: Number of Completed Packets (0x13) plen 5 #125 [hci0] 22.695655
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 5 #126 [hci0] 22.759830
ATT: Write Response (0x13) len 0
<< ACL Data TX: Handle 71 flags 0x00 dlen 11 #127 [hci0] 22.760241
ATT: Read By Group Type Request (0x10) len 6
Handle range: 0x0021-0xffff
Attribute group type: Primary Service (0x2800)
HCI Event: Number of Completed Packets (0x13) plen 5 #128 [hci0] 22.829698
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 26 #129 [hci0] 22.899859
ATT: Read By Group Type Response (0x11) len 21
Attribute data length: 20
Attribute group list: 1 entry
Handle range: 0x0021-0x002c
UUID: Vendor specific (b5f90001-aa8d-11e3-9046-0002a5d5c51b)
<< ACL Data TX: Handle 71 flags 0x00 dlen 11 #130 [hci0] 22.900311
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 #131 [hci0] 23.039754
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 12 #132 [hci0] 23.109915
ATT: Read By Group Type Response (0x11) len 7
Attribute data length: 6
Attribute group list: 1 entry
Handle range: 0x002d-0x0041
UUID: GoPro, Inc. (0xfea6)
<< ACL Data TX: Handle 71 flags 0x00 dlen 11 #133 [hci0] 23.110286
ATT: Read By Group Type Request (0x10) len 6
Handle range: 0x0042-0xffff
Attribute group type: Primary Service (0x2800)
HCI Event: Number of Completed Packets (0x13) plen 5 #134 [hci0] 23.185785
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 26 #135 [hci0] 23.319981
ATT: Read By Group Type Response (0x11) len 21
Attribute data length: 20
Attribute group list: 1 entry
Handle range: 0x0042-0x0047
UUID: Vendor specific (b5f90090-aa8d-11e3-9046-0002a5d5c51b)
<< ACL Data TX: Handle 71 flags 0x00 dlen 11 #136 [hci0] 23.320349
ATT: Read By Group Type Request (0x10) len 6
Handle range: 0x0048-0xffff
Attribute group type: Primary Service (0x2800)
HCI Event: Number of Completed Packets (0x13) plen 5 #137 [hci0] 23.389838
Num handles: 1
Handle: 71
Count: 1
ACL Data RX: Handle 71 flags 0x02 dlen 9 #138 [hci0] 23.458793
ATT: Error Response (0x01) len 4
Read By Group Type Request (0x10)
Handle: 0x0048
Error: Attribute Not Found (0x0a)
HCI Event: Disconnect Complete (0x05) plen 4 #139 [hci0] 24.160066
Status: Success (0x00)
Handle: 71
Reason: Connection Timeout (0x08)
@ Device Disconnected: C9:0F:D9:47:48:B4 (2) reason 1

for sure there are Authentification failures too, but I cannot
btmon-capture 'em right now.

However, it is really hard to find somebody who has a glue what is
going on here, and where the best, we should start to debug.

So please can you help us any further.

We are struggeling for a solution on this for years.

greets

peter

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: Instable BLE connection - MTU Request, Attribute not found
  2021-07-26 10:56 ` Instable BLE connection - MTU Request, Attribute not found Peter Höller
@ 2021-07-26 15:34   ` Emil Lenngren
       [not found]     ` <CAJgPF1LG32ShzPsaPWC64VGRC+odvHYrUYXBiDkTdcZHH78sbQ@mail.gmail.com>
  0 siblings, 1 reply; 4+ messages in thread
From: Emil Lenngren @ 2021-07-26 15:34 UTC (permalink / raw)
  To: Peter Höller; +Cc: Bluez mailing list

Hi Peter,

Den mån 26 juli 2021 kl 12:58 skrev Peter Höller <drmedvet.hoeller@gmail.com>:
>
> Hello!
>
> My name is peter. This is probably a bit off topic but:
> Since about 2 years I am working ambitiously on connecting a GoPro to
> an Odroid via HTTP, UDP and BLE in order to get a powerful node-red
> controlled dashcam/balckbox for my cars (fleet control).
> (please see: https://github.com/cepoon/GoProRemote,
> https://github.com/KonradIT/goprowifihack,
> https://github.com/sepp89117/GoPro-Multiple-Smart-Remote-ESP8266)
>
> However I stumbled over a thread: #96, which's owner forwarded me to
> your mailing list as my last resort:
>
> and figured that you are deep into debugging of BLE connections.
>
> because of our long developement period we are "stuck" in a somewhat
> older hardware/kernel  config, unfortunately:
>
> Odroid C2 with BluetoothModule2 (CSR8510 A10)
> Ubuntu 18.04 (Kernel 3.16.85+)
> WifiModule 5A (concurrent mode (STA+Client) on hostapd 2.9)
> Bluez 5.53
> btusb 0.7
> (- GoPro Hero5 black)
>
> However, we do suffer from an comparable annoying problem since more
> than a year(!). We do have an unstable BLE Connection between Dongle
> and Gopro. When just paired, the first connection stays up for about
> 30mins (abortion the is not btmon-itored yet, but can be done), but
> the reconnect is a problem: gets connected but after 2 - 15 sec:
> disconnect. Mainly because of:
>
> #Issue 1: (btmon) Why is it disconnecting after MTU request?
> @ Discovering: 0x00 (6)
>
> HCI Event: Command Status (0x0f) plen 4 #111 [hci0] 55.051270
> LE Create Connection (0x08|0x000d) ncmd 1
> Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 #112 [hci0] 55.626431
> LE Connection Complete (0x01)
> Status: Success (0x00)
> Handle: 71
> Role: Master (0x00)
> Peer address type: Random (0x01)
> Peer address: C9:0F:D9:47:48:B4 (Static)
> Connection interval: 70.00 msec (0x0038)
> Connection latency: 0 (0x0000)
> Supervision timeout: 420 msec (0x002a)
> Master clock accuracy: 0x00
> @ Device Connected: C9:0F:D9:47:48:B4 (2) flags 0x0000
> << ACL Data TX: Handle 71 flags 0x00 dlen 7 #113 [hci0] 55.627789
> ATT: Exchange MTU Request (0x02) len 2
> Client RX MTU: 517
> HCI Event: Disconnect Complete (0x05) plen 4 #114 [hci0] 56.035562
> Status: Success (0x00)
> Handle: 71
> Reason: Connection Failed to be Established (0x3e)
> @ Device Disconnected: C9:0F:D9:47:48:B4 (2) reason 0
>
> #issue 2: btmon: Error: Timeout/ Disconnect after attribute not
> found!? (main issue obviously)
> @ Discovering: 0x00 (6)
> << HCI Command: LE Create Connect.. (0x08|0x000d) plen 25 #102 [hci0] 21.277573
> Scan interval: 60.000 msec (0x0060)
> Scan window: 30.000 msec (0x0030)
> Filter policy: White list is not used (0x00)
> Peer address type: Random (0x01)
> Peer address: C9:0F:D9:47:48:B4 (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 #103 [hci0] 21.281234
> LE Create Connection (0x08|0x000d) ncmd 1
> Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 #104 [hci0] 21.474300
> LE Connection Complete (0x01)
> Status: Success (0x00)
> Handle: 71
> Role: Master (0x00)
> Peer address type: Random (0x01)
> Peer address: C9:0F:D9:47:48:B4 (Static)
> Connection interval: 70.00 msec (0x0038)
> Connection latency: 0 (0x0000)
> Supervision timeout: 420 msec (0x002a)
> Master clock accuracy: 0x00
> @ Device Connected: C9:0F:D9:47:48:B4 (2) flags 0x0000
> << ACL Data TX: Handle 71 flags 0x00 dlen 7 #105 [hci0] 21.475604
> ATT: Exchange MTU Request (0x02) len 2
> Client RX MTU: 517
> HCI Event: Number of Completed Packets (0x13) plen 5 #106 [hci0] 21.786387
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 7 #107 [hci0] 21.849441
> ATT: Exchange MTU Response (0x03) len 2
> Server RX MTU: 517
> << ACL Data TX: Handle 71 flags 0x00 dlen 7 #108 [hci0] 21.849849
> ATT: Read Request (0x0a) len 2
> Handle: 0x0004
> HCI Event: Number of Completed Packets (0x13) plen 5 #109 [hci0] 21.919448
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 15 #110 [hci0] 21.989485
> ATT: Read Response (0x0b) len 10
> Value: 476f50726f2038353339
> << ACL Data TX: Handle 71 flags 0x00 dlen 7 #111 [hci0] 21.989865
> ATT: Read Request (0x0a) len 2
> Handle: 0x0006
> HCI Event: Number of Completed Packets (0x13) plen 5 #112 [hci0] 22.059476
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 7 #113 [hci0] 22.135894
> ATT: Read Response (0x0b) len 2
> Value: 8000
> << ACL Data TX: Handle 71 flags 0x00 dlen 7 #114 [hci0] 22.136253
> ATT: Read Request (0x0a) len 2
> Handle: 0x000e
> HCI Event: Number of Completed Packets (0x13) plen 5 #115 [hci0] 22.199508
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 6 #116 [hci0] 22.269695
> ATT: Read Response (0x0b) len 1
> Value: 05
> << ACL Data TX: Handle 71 flags 0x00 dlen 7 #117 [hci0] 22.270106
> ATT: Read Request (0x0a) len 2
> Handle: 0x0020
> HCI Event: Number of Completed Packets (0x13) plen 5 #118 [hci0] 22.339554
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 12 #119 [hci0] 22.409721
> ATT: Read Response (0x0b) len 7
> Value: 00000000000000
> << ACL Data TX: Handle 71 flags 0x00 dlen 11 #120 [hci0] 22.410113
> 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 #121 [hci0] 22.479592
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 27 #122 [hci0] 22.549760
> ACL Data RX: Handle 71 flags 0x01 dlen 9 #123 [hci0] 22.551041
> ATT: Read By Group Type Response (0x11) len 31
> Attribute data length: 6
> Attribute group list: 5 entries
> Handle range: 0x0001-0x0001
> UUID: Generic Attribute Profile (0x1801)
> Handle range: 0x0002-0x0008
> UUID: Generic Access Profile (0x1800)
> Handle range: 0x0009-0x000b
> UUID: Tx Power (0x1804)
> Handle range: 0x000c-0x000f
> UUID: Battery Service (0x180f)
> Handle range: 0x0010-0x0020
> UUID: Device Information (0x180a)
> << ACL Data TX: Handle 71 flags 0x00 dlen 9 #124 [hci0] 22.551281
> ATT: Write Request (0x12) len 4
> Handle: 0x000f
> Data: 0100
> HCI Event: Number of Completed Packets (0x13) plen 5 #125 [hci0] 22.695655
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 5 #126 [hci0] 22.759830
> ATT: Write Response (0x13) len 0
> << ACL Data TX: Handle 71 flags 0x00 dlen 11 #127 [hci0] 22.760241
> ATT: Read By Group Type Request (0x10) len 6
> Handle range: 0x0021-0xffff
> Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5 #128 [hci0] 22.829698
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 26 #129 [hci0] 22.899859
> ATT: Read By Group Type Response (0x11) len 21
> Attribute data length: 20
> Attribute group list: 1 entry
> Handle range: 0x0021-0x002c
> UUID: Vendor specific (b5f90001-aa8d-11e3-9046-0002a5d5c51b)
> << ACL Data TX: Handle 71 flags 0x00 dlen 11 #130 [hci0] 22.900311
> 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 #131 [hci0] 23.039754
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 12 #132 [hci0] 23.109915
> ATT: Read By Group Type Response (0x11) len 7
> Attribute data length: 6
> Attribute group list: 1 entry
> Handle range: 0x002d-0x0041
> UUID: GoPro, Inc. (0xfea6)
> << ACL Data TX: Handle 71 flags 0x00 dlen 11 #133 [hci0] 23.110286
> ATT: Read By Group Type Request (0x10) len 6
> Handle range: 0x0042-0xffff
> Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5 #134 [hci0] 23.185785
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 26 #135 [hci0] 23.319981
> ATT: Read By Group Type Response (0x11) len 21
> Attribute data length: 20
> Attribute group list: 1 entry
> Handle range: 0x0042-0x0047
> UUID: Vendor specific (b5f90090-aa8d-11e3-9046-0002a5d5c51b)
> << ACL Data TX: Handle 71 flags 0x00 dlen 11 #136 [hci0] 23.320349
> ATT: Read By Group Type Request (0x10) len 6
> Handle range: 0x0048-0xffff
> Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5 #137 [hci0] 23.389838
> Num handles: 1
> Handle: 71
> Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 9 #138 [hci0] 23.458793
> ATT: Error Response (0x01) len 4
> Read By Group Type Request (0x10)
> Handle: 0x0048
> Error: Attribute Not Found (0x0a)
> HCI Event: Disconnect Complete (0x05) plen 4 #139 [hci0] 24.160066
> Status: Success (0x00)
> Handle: 71
> Reason: Connection Timeout (0x08)
> @ Device Disconnected: C9:0F:D9:47:48:B4 (2) reason 1
>
> for sure there are Authentification failures too, but I cannot
> btmon-capture 'em right now.
>
> However, it is really hard to find somebody who has a glue what is
> going on here, and where the best, we should start to debug.
>
> So please can you help us any further.
>
> We are struggeling for a solution on this for years.
>
> greets
>
> peter

To understand the "Connection failed to be established" disconnect
reason, let me first explain the connection process in BLE:
1. Peripheral emits ADV_IND advertising packets repeatedly with some
interval, containing its Bluetooth device address and some optional
advertising data.
2. A central device which is currently in the initiating state scans
for these advertising packets and when one is found with the correct
target address, it will reply after exactly 150 microseconds with a
CONNECT_IND packet.
3. The central is now in the "connected" state and this fact is sent
to the host using a "LE Connection Complete Event".
4. At the peripheral side, the "connected" state is entered when it
receives the CONNECT_IND packet.

In the connected state, the central emits one packet (possibly empty)
once per connection interval and the peripheral must respond within
150 microseconds. If there is no response for the first six packets in
a connection, the central will treat the connection disconnected with
the reason "Connection failed to be established". If the peripheral
responds at least once, but after that at any time it doesn't respond
to a central's packet within the set supervision timeout, the
"Connection Timeout" disconnect reason will happen.

We can derive a few reasons why "Connection failed to be established" occurs:

1. If the CONNECT_IND packet is lost in the air, the peripheral does
not enter the connected state, but the central does. In this case the
peripheral will not respond to any other packet the central sends,
since the peripheral is not in the connected state.
2. The peripheral could use white listing to allow connections from
only specific centrals. In this case the central will always see a
connection complete immediately followed by a connection failed to be
established.
3. Bad signal quality could mean the peripheral detects the
CONNECT_IND but not any of the first six packets sent by the central.
4. A bad link layer scheduler in any of the two bluetooth controllers
could skip the first six connection events.

With the new extended advertising packet format introduced in
Bluetooth 5.0 that not many devices use, an extra acknowledgement is
sent from the peripheral after it receives the CONNECT_IND to mitigate
this confusion a bit.

Common reasons for the Connection Timeout are bad signal quality or a
bad link layer scheduler, or possibly too much overlapping work
scheduled for the radio.

Anyway, nothing is wrong at the host side (BlueZ) for these problems.
It just happened that the MTU Request and Attribute Not Found packets
were the last ones before the disconnection occurred. You should use
an air sniffer for BLE to maybe get some more insight.

/Emil

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: Instable BLE connection - MTU Request, Attribute not found
       [not found]     ` <CAJgPF1LG32ShzPsaPWC64VGRC+odvHYrUYXBiDkTdcZHH78sbQ@mail.gmail.com>
@ 2021-07-26 19:56       ` Emil Lenngren
       [not found]       ` <CAJgPF1+BJFyryVWzVYGp=qDHjruJWYq-eAHzm+QeR=BGNct+iw@mail.gmail.com>
  1 sibling, 0 replies; 4+ messages in thread
From: Emil Lenngren @ 2021-07-26 19:56 UTC (permalink / raw)
  To: Peter Höller, Bluez mailing list

Hi,

Den mån 26 juli 2021 kl 18:19 skrev Peter Höller <drmedvet.hoeller@gmail.com>:
>
> Hi Emil!
>
> Thanks for your input!!
>
> I do have to stabilze this connection, I do not have any other chance,
> unfortunately.
>
> What I fell in my guts right now is that most likely:
>  this >>>>
> 2. The peripheral could use white listing to allow connections from
> only specific centrals. In this case the central will always see a
> connection complete immediately followed by a connection failed to be
> established.
> >>>>>
>
> and this>>>>>
> If the peripheral
> responds at least once, but after that at any time it doesn't respond
> to a central's packet within the set supervision timeout, the
> "Connection Timeout" disconnect reason will happen.
> >>>>>
>
> plays a role in my issue!!
>
> However , just to be mentioned, I cannot set (or prolong) supervision
> timeout period, which was my intention initially.
>
> here is what I am able to read/set (sudo nano) under:
> root@odroid:/sys/kernel/debug/bluetooth/hci0#
>
> 6lowpan                     force_sc_support         random_address
> adv_channel_map             force_static_address     rpa_timeout
> auto_accept_delay           hci_revision             sc_only_mode
> blacklist                   hci_version              sniff_max_interval
> conn_info_max_age           identity                 sniff_min_interval
> conn_info_min_age           identity_resolving_keys  ssp_debug_mode
> conn_max_interval           idle_timeout             static_address
> conn_min_interval           inquiry_cache            uuids
> dev_class                   le_auto_conn             voice_setting
> discov_interleaved_timeout  link_keys                white_list
> dut_mode                    long_term_keys           white_list_size
> features                    manufacturer
>
> Do you have any suggestions for those parameters or am I tuning on the
> wrong place here?
>
> However, I am going for wireshark fur ubuntu now, if I understood you right?
>
> with kind regards
>
> Peter

Someone else should reply to the question about modifying the
supervision timeout. I think BlueZ hardcodes it but I might be wrong.
Either way you could always locate the code for it and recompile with
new parameters.

For a BLE sniffer you could for example use an nRF52 devkit, flash the
sniffer firmware at
https://www.nordicsemi.com/Products/Development-tools/nrf-sniffer-for-bluetooth-le
and then use Wireshark to analyze the traffic in real time.

/Emil

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: Instable BLE connection - MTU Request, Attribute not found - wireshark findings
       [not found]       ` <CAJgPF1+BJFyryVWzVYGp=qDHjruJWYq-eAHzm+QeR=BGNct+iw@mail.gmail.com>
@ 2021-07-26 20:17         ` Emil Lenngren
  0 siblings, 0 replies; 4+ messages in thread
From: Emil Lenngren @ 2021-07-26 20:17 UTC (permalink / raw)
  To: Peter Höller, Bluez mailing list

Den mån 26 juli 2021 kl 22:00 skrev Peter Höller <drmedvet.hoeller@gmail.com>:
>
> However, I installed wireshark ( I used the wireshark version instead
> of tshark, because I am not familiar with the shell commands in
> tshark. However, unfortunately I cannot copy any sniffed protocols for
> now)
>
> my connection status out of bluetoothctl is:
> paired, trusted and connected
>
>
> 1.) paired and connected I go to
> >menu gatt
> >select attribute b5f90074-aa8d-11e3-9046-0002a5d5c51b  (as I always do)
> this leads me to:
> GoPro8639:/service002d/char0033]#
> no I:
> write "0x03 0x01 0x01 0x01"  (which always started the shutter on
> peripheral, when we used btusb 0.6 (now we are using btusb 0.7!)
>
> but nothing happens at peripheral.
> on wireshark there is no error but I get on Write response packet:
> Bluetooth Attribute Protocol
> -->Opcode: Write Response (0x13)
> -->0... .... = Authentication Signature: False
> .0.. .... = Command: False
> ..01 0011 = Method: Write Respone (0x13)
>
> Can you debug this? Was there any change in syntax due to write <data
> = xx xx xx xx xx> [offset] [type] ?
>
> Hoever,
> sudo gatttool -t random -b xx:xx:xx:xx:xx:xx -I
> connect
> char-write-req 2f 03010101
>
> still works (!) and goes through to the peripheral !, unless there
> occurs no is no file descriptor Error
>
>
> 2.) due to the disconnect problem after longer connection ~15 min:
> there where no further findings:
> wireshark delivers an HCI event  - Disconnect Complete with
> Reason: Connection Timeout (0x08)
>
> 3.) due to the immediate disconnect problem (~1 - 10 sec after
> connection): there seems to be an encryption problem and /or
> Encryption change takes too long?:
> (I type for you...)
>
> from host to controller:          HCI_CMD           length: 29
> SENT           LE Create Connection
>
> from controller to host:          HCI_EVT            length: 7
>  Rcvd            Command Status (LE Create Connection)
>
> from controller to host:          HCI_EVT            lenght: 22
> Rcvd              LE Meta (LE Connection Complete)
>
> from host to controller:          HCI_CMD           length: 32
> Sent             LE Start Encryption
>
> from controller to host:          HCI_EVT            lenght: 7
> Rcvd             Command Status (LE Start Encryption)
>
> from controller to host:          HCI_EVT            lenght: 7
> Rcvd             Encryption Change
> ----->containg under BluetoothHCI Event:  Status: Connection timeout (0x08) and
>
> Encrytion Enable: Link Level Encryption is OFF (0x00)
>
> from host to controller:          HCI_CMD           length: 7
> Sent              Disconnect
> ----->containg under BluetoothHCI Command:   Reason: Authentication
> Failure (0x05)
>
> from controller to host:          HCI_EVT            lenght: 7
> Sent             Disconnect Complete
> ----->containg under BluetoothHCI Event:   Reason Connection Timeout(0x08)

If you have one method that works and one that fails, you should use
btmon to compare the exact write payloads. I don't know about GoPro so
can't help what kind of messages it expects.

You can see that it's the controller that first notifies of the
disconnection with the reason "Connection Timeout" (in a start
encryption result, as indicated by the result code). So likely it's
due to one of the reasons I wrote about earlier. Another reason for
connection timeout is if the firmware is buggy or just drops the
connection for example when you suddenly power off the device. What
also could happen is, during encryption setup, is if both devices
believe they share the same encryption key, but in fact they for some
reason have two different keys stored, then the peripheral will drop
the connection with the reason "Connection terminated due to MIC
failure" while the central will eventually get a "Connection Timeout".

/Emil

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, other threads:[~2021-07-26 20:17 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
     [not found] <CAJgPF1JLw40nRXyoXyuGd9hNLWCDeD4ONVM7S_CSE9wQg3gvyA@mail.gmail.com>
2021-07-26 10:56 ` Instable BLE connection - MTU Request, Attribute not found Peter Höller
2021-07-26 15:34   ` Emil Lenngren
     [not found]     ` <CAJgPF1LG32ShzPsaPWC64VGRC+odvHYrUYXBiDkTdcZHH78sbQ@mail.gmail.com>
2021-07-26 19:56       ` Emil Lenngren
     [not found]       ` <CAJgPF1+BJFyryVWzVYGp=qDHjruJWYq-eAHzm+QeR=BGNct+iw@mail.gmail.com>
2021-07-26 20:17         ` Instable BLE connection - MTU Request, Attribute not found - wireshark findings Emil Lenngren

This is a public inbox, see mirroring instructions
on how to clone and mirror all data and code used for this inbox