Service discovery request resolves to empty list #123
Comments
|
Several issues are fixed, so we should try to get main branch working on esp32 first. |
|
For the record, I tried to run the btleplug example using the nrf-sdc example, so I think this issue is fixed on main: I will re-run that once having esp32 working. |
|
@peteskubiak Now with #124 merged, could you retry your testing? |
|
Sure thing. First off, I can confirm the esp32 example is now working. Blteplug testTrace from the example shows something slightly different: So the error message has disappeared and the read event report is now reporting different values for BluestThe code I've put together to exercise the bluest adapter performs the following tasks:
The trace from my code is the following: The trace from the TrouBLE example is as follows: Again, the error is no longer reported, but no services are discovered. NRF ConnectNRF Connect is still able to successfully connect and report all expected services and subscribe to the notify characteristic. As before, there is no |
|
@peteskubiak Thanks for testing! I only tried btleplug with esp32, and for me it does discover all the services and characteristics as when I tested nrf-sdc. I wonder if this could be related to bluez version on the system, could you share Linux version, version of bluez etc? One thing to keep in mind, bluez does some caching of earlier discoveries, so you might want to try to change the device id to something else than 'Trouble' in case it's caching some old state. Regarding the Read Event present or not, this event is only returned when a 'read' is requested. In the nrf connect app, you have to press 'read characteristic' icon to trigger a read event. Subscribing to a value will not trigger a a read event, so this is expected. The other examples probably do explicit reads. Would you mind sharing your 'bluest' code so I can try to reproduce it? |
|
Interesting! Yes my OS version is Ubuntu 20.04.6 LTS and bluez version is 5.53. It could be related to OS/bluez version; the fact that it can discover services on a bleps-based device but not TrouBLE might help to track down the source of the issue... Testing btleplug and bluest with an updated device ID each time have the same results: no services. Here's my bluest code: use bluest::Adapter;
use futures::StreamExt;
use std::error::Error;
use tracing::info;
use tracing::metadata::LevelFilter;
#[tokio::main]
async fn main() -> Result<(), Box<dyn Error>> {
use tracing_subscriber::prelude::*;
use tracing_subscriber::{fmt, EnvFilter};
tracing_subscriber::registry()
.with(fmt::layer())
.with(
EnvFilter::builder()
.with_default_directive(LevelFilter::INFO.into())
.from_env_lossy(),
)
.init();
let adapter = Adapter::default()
.await
.ok_or("Bluetooth adapter not found")?;
adapter.wait_available().await?;
info!("starting scan");
let mut scan = adapter.scan(&[]).await?;
info!("scan started");
let mut trouble = None;
let mut services = Vec::new();
while trouble.is_none() {
if let Some(discovered_device) = scan.next().await {
info!(
"{}{}: {:?}; {:?}",
discovered_device
.device
.name()
.as_deref()
.unwrap_or("(unknown)"),
discovered_device
.rssi
.map(|x| format!(" ({}dBm)", x))
.unwrap_or_default(),
discovered_device.adv_data.services,
discovered_device.adv_data.service_data
);
// NOTE: Doing simple string comparison to identity device
if discovered_device.device.name().unwrap() == *"Trouble3" {
trouble = Some(discovered_device.device);
services.extend(discovered_device.adv_data.services);
info!("Found trouble!");
}
}
}
adapter.connect_device(trouble.as_ref().unwrap()).await?;
info!("Connected to trouble!");
info!("Discovering services...");
info!(
"Services discovered: {:?}",
trouble.as_ref().unwrap().services().await?
);
adapter.disconnect_device(&trouble.unwrap()).await?;
Ok(())
} |
|
@peteskubiak Thanks! What seems to happen is that bluez aborts the connection due to the supervision timeout (bluez sets this to 420ms). I've used the bluetoothctl tool manually to connect, and I'm getting a Sometimes it gets a bit further and starts making GATT requests, but ultimately it sends up disconnecting sometimes. I've tried the following as well:
So I think this might not be related to trouble, but some timing handling in the esp32 hci controller and/or the hci integration, since the bleps examples exhibit the same behavior. Do you have a bleps example that works for you? I've been running the examples from main in esp-hal, maybe you could try those as well. |
|
I tried on a different machine, debian based, and in that case all the esp examples worked, all services discovered etc. If you have a bleps-based example that works for you, I'd be interested to test it on these two systems to understand more what's different. You can also try to increase the supervision timeout to see if that helps, |
|
Ahh that would explain the long pause when attempting to connect to the TrouBLE example. Here is the hacked together bleps example I've been using - I've stuck it into one file for easy sharing, please excuse the scrappy code! //! Embassy BLE Example
//!
#![no_std]
#![no_main]
use bleps::ad_structure::{
create_advertising_data, AdStructure, BR_EDR_NOT_SUPPORTED, LE_GENERAL_DISCOVERABLE,
};
use bleps::async_attribute_server::AttributeServer;
use bleps::asynch::Ble;
use bleps::att::Uuid;
use bleps::attribute_server::{NotificationData, WorkResult};
use bleps::event::EventType;
use bleps::no_rng::NoRng;
use bleps::PollResult;
use embassy_executor::Spawner;
use embassy_time::{Duration, Timer};
use esp_backtrace as _;
use esp_hal::clock::{ClockControl, Clocks};
use esp_hal::peripherals::{Peripherals, BT, RADIO_CLK, SYSTIMER};
use esp_hal::rng::Rng;
use esp_hal::system::SystemControl;
use esp_hal::timer::timg::TimerGroup;
use esp_hal::timer::{systimer, ErasedTimer, PeriodicTimer};
use esp_hal_embassy::main;
use esp_wifi::ble::controller::asynch::BleConnector;
use esp_wifi::{initialize, EspWifiInitFor};
use log::info;
#[global_allocator]
static ALLOCATOR: esp_alloc::EspHeap = esp_alloc::EspHeap::empty();
#[main]
async fn main(_spawner: Spawner) -> ! {
// Initialize the logger
esp_println::logger::init_logger(log::LevelFilter::Info);
init_heap();
// Initialize the hardware
let b = Board::init();
// Initialize the BLE stack
let ble_init = initialize(
EspWifiInitFor::Ble,
b.timer,
b.rng,
b.radio_clocks,
&b.clocks,
)
.unwrap();
let connector = BleConnector::new(&ble_init, b.ble);
let mut ble = Ble::new(connector, esp_wifi::current_millis);
let service_uuids = &[bleps::att::Uuid::Uuid16(0x1809)];
let mut rf3 = |_offset: usize, data: &mut [u8]| {
data[..5].copy_from_slice(&b"Hola!"[..]);
5
};
let mut wf3 = |offset: usize, data: &[u8]| {
info!("RECEIVED: Offset {}, data {:?}", offset, data);
};
let mut my_descriptor_read_function = |_offset: usize, data: &mut [u8]| {
data[..5].copy_from_slice(&b"Desc!"[..]);
5
};
let mut notify = |enabled: bool| {
info!("enabled = {enabled}");
};
let mut rf = rf3;
let mut notify2 = notify;
bleps::gatt!([service {
uuid: "937312e0-2354-11eb-9f10-fbc30a62cf38",
characteristics: [
characteristic {
name: "my_characteristic",
description: "Sine wave notifier",
descriptors: [descriptor {
uuid: "dfe57a9f-4495-45ba-9e02-df1a010b618c",
read: my_descriptor_read_function,
},],
uuid: "987312e0-2354-11eb-9f10-fbc30a62cf38",
notify: true,
read: rf3,
write: wf3,
notify_cb: notify,
},
characteristic {
name: "triangle_wave",
description: "Triangle wave notifier",
uuid: "937312e0-2354-11eb-9f10-fbc30a62cf38",
notify: true,
read: rf,
notify_cb: notify2,
}
],
},]);
advertise(&mut ble, service_uuids, "BLEPS DEMO").await;
let mut rng = NoRng;
let mut srv = AttributeServer::new(&mut ble, &mut gatt_attributes, &mut rng);
let mut counter = 0.0;
let mut tri_counter: f32 = 1.0;
let mut tri_adder = 1.0;
loop {
let mut cccd = [0u8; 1];
srv.get_characteristic_value(my_characteristic_notify_enable_handle, 0, &mut cccd);
if cccd[0] == 1 {
match srv
.do_work_with_notification(Some(NotificationData::new(
my_characteristic_handle,
&libm::sinf(counter).to_le_bytes(),
)))
.await
{
Ok(res) => match res {
WorkResult::DidWork => {
info!("Notify {counter}");
}
WorkResult::GotDisconnected => {
info!("Disconnected!");
}
},
Err(_) => todo!(),
}
counter += 0.1;
Timer::after(Duration::from_millis(200)).await;
} else {
let _ = srv.do_work().await;
}
let mut cccd = [0u8; 1];
srv.get_characteristic_value(triangle_wave_notify_enable_handle, 0, &mut cccd);
if cccd[0] == 1 {
match srv
.do_work_with_notification(Some(NotificationData::new(triangle_wave_handle, {
if tri_counter as i32 % 25 == 0 {
tri_adder = -tri_adder;
}
&tri_counter.to_le_bytes()
})))
.await
{
Ok(res) => {
if let WorkResult::GotDisconnected = res {
info!("Disconnected (TW)")
}
}
Err(_) => todo!(),
}
tri_counter += tri_adder;
}
}
}
fn init_heap() {
const HEAP_SIZE: usize = 32 * 1024;
static mut HEAP: core::mem::MaybeUninit<[u8; HEAP_SIZE]> = core::mem::MaybeUninit::uninit();
unsafe {
ALLOCATOR.init(HEAP.as_mut_ptr() as *mut u8, HEAP_SIZE);
}
}
async fn advertise(
ble: &mut Ble<BleConnector<'static>>,
service_uuids: &[Uuid],
name: &str,
) -> bool {
info!("{:?}", ble.init().await);
info!("{:?}", ble.cmd_set_le_advertising_parameters().await);
info!(
"{:?}",
ble.cmd_set_le_advertising_data(
create_advertising_data(&[
AdStructure::Flags(LE_GENERAL_DISCOVERABLE | BR_EDR_NOT_SUPPORTED),
AdStructure::ServiceUuids16(service_uuids),
AdStructure::CompleteLocalName(name),
])
.unwrap()
)
.await
);
info!("{:?}", ble.cmd_set_le_advertise_enable(true).await);
info!("started advertising");
loop {
if let Some(PollResult::Event(event)) = ble.poll().await {
// info!("{:?}", event);
match event {
EventType::DisconnectComplete { reason, .. } => {
info!("Disconnected: {:?}", reason);
break false;
}
EventType::ConnectionComplete { .. } => {
info!("Connected BLE!");
break true;
}
EventType::LongTermKeyRequest { .. } => unimplemented!(),
other => info!("Unhandled event: {:?}", other),
}
};
}
}
struct Board {
pub timer: PeriodicTimer<'static, ErasedTimer>,
pub clocks: Clocks<'static>,
pub rng: Rng,
pub radio_clocks: RADIO_CLK,
pub ble: BT,
}
impl Board {
pub fn init() -> Self {
let p = Peripherals::take();
let system = SystemControl::new(p.SYSTEM);
let clocks = ClockControl::max(system.clock_control).freeze();
let timg0 = TimerGroup::new(p.TIMG0, &clocks);
let timer0: ErasedTimer = timg0.timer0.into();
let timer = PeriodicTimer::new(timer0);
Board::init_embassy(p.SYSTIMER, &clocks);
Self {
timer,
clocks,
rng: Rng::new(p.RNG),
radio_clocks: p.RADIO_CLK,
ble: p.BT,
}
}
/// Initialize the embassy runtime
fn init_embassy(systimer: SYSTIMER, clocks: &Clocks) {
info!("Initializing embassy runtime");
let systimer = systimer::SystemTimer::new(systimer);
let alarms = systimer.split::<esp_hal::timer::systimer::Target>();
esp_hal_embassy::init(clocks, alarms.alarm0);
}
}Please note - the device will not go back to advertising on disconnect. Discovery of services seems to work fine with both Btleplug and Bluest with default bluez supervision timeout using this demo. I notice the connection happens considerably more quickly in this case too. I'm about out of time today but I wonder if bleps is using a different version of esp-hal or one of the other crates, and the controller is being configured differently? I'll have at look at this tomorrow if still relevant. I haven't had a chance yet to try out changing the supervision timeout, but I'll try that tomorrow too. |
|
Which versions/revisions of esp crates are you using? |
This issue was identified running the esp32 example on an ESP32-C3-DevKit-RUST-1 board @ 29dabe7 (the esp32 example is currently broken beyond this point, see #122).
Attempts to discover services on the device take a long time to resolve, and when they do they resolve to an empty list.
I have tested this against examples in two different adapter crates running on Ubuntu 20.04:
The results from these tests are the same. When the Linux application discover services on the device, I see the following trace from the device:
Service UUIDs can be read from the advertising data, but no service data is associated with them.
Running a bleps-based application on the same dev board, I can successfully discover services with both blteplug and bluest.
Confusingly however, I can connect to the device with the NRFConnect app on my phone and this does seem to be able to resolve the services successfully. I don't know how NRFConnect goes about service discovery, but I don't see either the
Read event on Characteristic { cccd_handle: Some(35), handle: 34 }line or theError processing GATT events: NotFoundline. Instead when NRFConnect connects I just see:The text was updated successfully, but these errors were encountered: