Connection issue on iOS/macOS device

[HaoboGu]

The issue is from https://github.com/embassy-rs/trouble/issues/82#issuecomment-2347925811 .

I did some more investigation, on both my own implementation and examples in latest version. I can reproduce the issue on latest commit d9d2e80b6b2ed6c3aeae1de534de557906353522:

when connecting to iOS/macOS devices, there's an error reported: [gatt] Error processing GATT events: NotFound

The device could successfully connect to the host, but not functional. Then the host would terminate the connection. The following is the full trace log:

$ cargo run --release --bin ble_bas_peripheral     
   Compiling embassy-nrf v0.2.0 (https://github.com/embassy-rs/embassy.git?rev=1cfd5370ac012814b7b386ba9ad8499529bdde4e#1cfd5370)
   Compiling nrf-mpsl v0.1.0 (https://github.com/alexmoon/nrf-sdc.git?rev=3702af909d31cd81c62f15e1aa9d5f637ec935fa#3702af90)
   Compiling nrf-sdc v0.1.0 (https://github.com/alexmoon/nrf-sdc.git?rev=3702af909d31cd81c62f15e1aa9d5f637ec935fa#3702af90)
   Compiling trouble-nrf-sdc-examples v0.1.0 (/Users/haobogu/Projects/rust/trouble/examples/nrf-sdc)
    Finished `release` profile [optimized + debuginfo] target(s) in 3.63s
     Running `probe-rs run --chip nRF52840_xxAA target/thumbv7em-none-eabihf/release/ble_bas_peripheral`
      Erasing ✔ [00:00:03] [##########################################################################################################################################]      0 B/     0 B @      0 B/s (eta 0s )
  Programming ✔ [00:00:05] [#####################################################################################################################################] 152.00 KiB/152.00 KiB @ 28.90 KiB/s (eta 0s )    Finished in 5.2652664s
0.000061 WARN  Memory buffer too big. 2168 bytes needed
└─ nrf_sdc::sdc::{impl#3}::build @ /Users/haobogu/.cargo/git/checkouts/nrf-sdc-52477ea9d1e36c44/3702af9/nrf-sdc/src/fmt.rs:151 
0.000762 INFO  Our address = Address { kind: AddrKind(1), addr: BdAddr([65, 90, 227, 30, 131, 231]) }
└─ trouble_example_apps::ble_bas_peripheral::run::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
0.000915 INFO  Starting advertising and GATT service
└─ trouble_example_apps::ble_bas_peripheral::run::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
0.001007 INFO  [host] filter accept list size: 8
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#0} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:143 
0.001037 INFO  [host] setting txq to 3
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#0} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:143 
0.001098 INFO  [host] configuring host buffers (8 packets of size 251)
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#0} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:143 
0.001129 INFO  [host] initialized
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#0} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:143 
0.001220 INFO  [adv] advertising
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
0.001312 TRACE [host] enabling advertising
└─ trouble_host::host::{impl#2}::advertise::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:117 
21.151184 TRACE [host] connection with handle ConnHandle(0) established to BdAddr([15, c9, bd, 67, 78, 69])
└─ trouble_host::host::{impl#2}::handle_connection @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:117 
21.151306 TRACE [link][poll_accept] connection handle ConnHandle(0) in role Peripheral accepted
└─ trouble_host::connection_manager::{impl#1}::poll_accept @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:117 
21.151367 INFO  [adv] connection established
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
21.272308 WARN  [host] unsupported l2cap channel id 58
└─ trouble_host::host::{impl#2}::handle_acl @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:156 
21.272338 WARN  [host] encountered error processing ACL data for ConnHandle(0): NotSupported
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#2} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:156 
21.302276 TRACE [host] agreed att MTU of 185
└─ trouble_host::host::{impl#2}::handle_acl @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:117 
21.392547 INFO  [gatt] Read event on Characteristic { cccd_handle: Some(35), handle: 34 }
└─ trouble_example_apps::ble_bas_peripheral::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
21.452545 ERROR [gatt] Error processing GATT events: NotFound
└─ trouble_example_apps::ble_bas_peripheral::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:169 
23.151428 INFO  [adv] notifying connection of tick 1
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
25.151519 INFO  [adv] notifying connection of tick 2
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
27.151611 INFO  [adv] notifying connection of tick 3
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
29.151702 INFO  [adv] notifying connection of tick 4
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
31.151794 INFO  [adv] notifying connection of tick 5
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
33.151885 INFO  [adv] notifying connection of tick 6
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
35.151977 INFO  [adv] notifying connection of tick 7
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
37.152069 INFO  [adv] notifying connection of tick 8
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
39.152160 INFO  [adv] notifying connection of tick 9
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
41.152252 INFO  [adv] notifying connection of tick 10
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
43.152343 INFO  [adv] notifying connection of tick 11
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
45.152435 INFO  [adv] notifying connection of tick 12
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
47.152526 INFO  [adv] notifying connection of tick 13
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
49.152618 INFO  [adv] notifying connection of tick 14
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
51.152709 INFO  [adv] notifying connection of tick 15
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
51.483886 INFO  [host] disconnection event on handle 0, reason: Remote User Terminated Connection
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#2} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:143 
53.152801 INFO  [adv] notifying connection of tick 16
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
53.152862 INFO  [adv] advertising
└─ trouble_example_apps::ble_bas_peripheral::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/examples/apps/src/fmt.rs:143 
53.152923 TRACE [host] disabling advertising
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#0} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:117 
53.153045 TRACE [host] enabling advertising
└─ trouble_host::host::{impl#2}::advertise::{async_fn#0} @ /Users/haobogu/Projects/rust/trouble/host/src/fmt.rs:117 

[lulf]

May I ask, which client are you using to connect? I'm not able to reproduce with the nrf connect app on iOS

[HaoboGu]

May I ask, which client are you using to connect? I'm not able to reproduce with the nrf connect app on iOS

I'm using nrf connect as well. Here is the client log:

[HaoboGu]

After the last callback, the device is disconnected.

[lulf]

Hmm, maybe the discovery process is different in some cases. Which app version are you using?

[HaoboGu]

My nrf connect's application version is 2.7.11, build number is 26

[lulf]

Looks like my old ios didn't get newer nrf connect. But luckily I was able to reproduce your issue on a mac.

[lulf]

@HaoboGu The fix merged in #116 fixes the issue for me. Please reopen if you're still seeing the issue with that.

[HaoboGu]

@lulf Thanks for the quick fix! The latest version works for nrf connect, but both iOS/macOS cannot detect the ble_bas_peripheral example in the built-in bluetooth config panel:

Is that intentional?

And, when it comes to my own service, I got nrf-sdc panic:

INFO  Connected
└─ rmk::ble::trouble::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:270 
WARN  [host] unsupported l2cap channel id 58
└─ trouble_host::host::{impl#2}::handle_acl @ /Users/haobogu/.cargo/git/checkouts/trouble-148cf413cadab653/1776fbf/host/src/fmt.rs:156 
WARN  [host] encountered error processing ACL data for ConnHandle(0): NotSupported
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#2} @ /Users/haobogu/.cargo/git/checkouts/trouble-148cf413cadab653/1776fbf/host/src/fmt.rs:156 
TRACE [host] agreed att MTU of 185
└─ trouble_host::host::{impl#2}::handle_acl @ /Users/haobogu/.cargo/git/checkouts/trouble-148cf413cadab653/1776fbf/host/src/fmt.rs:117 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 50 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 52 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 54 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 56 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 58 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 60 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 62 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 82 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
ERROR panicked at 'SoftdeviceController: 20:201'
└─ nrf_sdc::sdc::fault_handler @ /Users/haobogu/.cargo/git/checkouts/nrf-sdc-52477ea9d1e36c44/3702af9/nrf-sdc/src/fmt.rs:101 
ERROR panicked at /Users/haobogu/.cargo/registry/src/rsproxy.cn-0dccff568467c15b/defmt-0.3.8/src/lib.rs:367:5:
explicit panic
└─ panic_probe::print_defmt::print @ /Users/haobogu/.cargo/registry/src/rsproxy.cn-0dccff568467c15b/panic-probe-0.3.2/src/lib.rs:104

Do you have any idea for this? Thanks again for your help!

[lulf]

@lulf Thanks for the quick fix! The latest version works for nrf connect, but both iOS/macOS cannot detect the ble_bas_peripheral example in the built-in bluetooth config panel:

Is that intentional?

I'm not sure what's required for a BLE device to be listed in the Mac OS list. Could be there are some special characteristics that you need to provide for it to get listed. From what I gather, it might only show devices that implement the officially supported bluetooth profiles (see https://support.apple.com/en-us/102842)

And, when it comes to my own service, I got nrf-sdc panic:

INFO  Connected
└─ rmk::ble::trouble::advertise_task::{async_fn#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:270 
WARN  [host] unsupported l2cap channel id 58
└─ trouble_host::host::{impl#2}::handle_acl @ /Users/haobogu/.cargo/git/checkouts/trouble-148cf413cadab653/1776fbf/host/src/fmt.rs:156 
WARN  [host] encountered error processing ACL data for ConnHandle(0): NotSupported
└─ trouble_host::host::{impl#2}::run_with_handler::{async_fn#0}::{async_block#2} @ /Users/haobogu/.cargo/git/checkouts/trouble-148cf413cadab653/1776fbf/host/src/fmt.rs:156 
TRACE [host] agreed att MTU of 185
└─ trouble_host::host::{impl#2}::handle_acl @ /Users/haobogu/.cargo/git/checkouts/trouble-148cf413cadab653/1776fbf/host/src/fmt.rs:117 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 50 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 52 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 54 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 56 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 58 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 60 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 62 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
INFO  [gatt] Read event on Characteristic { cccd_handle: None, handle: 82 }
└─ rmk::ble::trouble::gatt_task::{async_fn#0}::{closure#0} @ /Users/haobogu/Projects/keyboard/rmk/rmk/src/ble/trouble.rs:226 
ERROR panicked at 'SoftdeviceController: 20:201'
└─ nrf_sdc::sdc::fault_handler @ /Users/haobogu/.cargo/git/checkouts/nrf-sdc-52477ea9d1e36c44/3702af9/nrf-sdc/src/fmt.rs:101 
ERROR panicked at /Users/haobogu/.cargo/registry/src/rsproxy.cn-0dccff568467c15b/defmt-0.3.8/src/lib.rs:367:5:
explicit panic
└─ panic_probe::print_defmt::print @ /Users/haobogu/.cargo/registry/src/rsproxy.cn-0dccff568467c15b/panic-probe-0.3.2/src/lib.rs:104

Do you have any idea for this? Thanks again for your help!

About the SDC crash, that's an internal error in the Nordic SDC library, so I'm not sure what it could mean, I haven't seen it myself, but could be worth checking up with Nordic.

[martintv]

@HaoboGu : about the 'SoftdeviceController: 20:201' crash:

is it easy for you to reproduce it? you are connected to a mac as peripheral when it happens? any way you could get a sniffer-log of on air trafiic when it happens?

[HaoboGu]

@HaoboGu : about the 'SoftdeviceController: 20:201' crash:

is it easy for you to reproduce it? you are connected to a mac as peripheral when it happens? any way you could get a sniffer-log of on air trafiic when it happens?

Yes, I can repro it everytime after I click "connect" to the peripheral. I'll try to get a sniffer-log.

[igiona]

I'm not sure what's required for a BLE device to be listed in the Mac OS list. Could be there are some special characteristics that you need to provide for it to get listed. From what I gather, it might only show devices that implement the officially supported bluetooth profiles

That's correct, apple is quite picky& demanding (the same is also valid for iOS). If you scan your deceives in an app you'll get the device listed regardless what service you provide, but not from the OS menu. There you need to provide all they want you to provide.

[HaoboGu]

@martintv I tried to sniffer the BLE traffic using nRF sniffer. Here is the wireshark log file, it can be opened using wireshark after installing nRF sniffer:

nrf_sniffer.pcapng.zip

I hope it's useful :)

[lulf]

@HaoboGu Hey, the feedback I got from Martin is that the data that trouble attempts to send is too big. What is the BleHostResources configuration you are using, and what is the size of the GATT attributes? It's likely related to either misconfigured limits, or trouble not segmenting the gatt payloads appropriately.

[HaoboGu]

@lulf My full configuration is at https://github.com/HaoboGu/rmk/blob/feat/trouble/rmk/src/ble/trouble.rs, I set MAX_ATTRIBUTES to 50, which is a relatively large number. But the number of added attribute is actually less than I used in nrf-softdevice(see nrf-softdevice example)