From ec0505e7cc0767d2b887a925c6c4b24b0b21206f Mon Sep 17 00:00:00 2001 From: ivmarkov Date: Wed, 1 May 2024 13:14:49 +0000 Subject: [PATCH] Many small bugfixes; better logging --- .github/configs/sdkconfig.defaults | 2 +- examples/light.rs | 2 +- src/ble.rs | 127 ++++++++++++++++++++--------- src/wifi/comm.rs | 92 ++++++++++++++------- 4 files changed, 155 insertions(+), 68 deletions(-) diff --git a/.github/configs/sdkconfig.defaults b/.github/configs/sdkconfig.defaults index b2341e6..c26e85a 100644 --- a/.github/configs/sdkconfig.defaults +++ b/.github/configs/sdkconfig.defaults @@ -7,7 +7,7 @@ CONFIG_ESP_SYSTEM_EVENT_TASK_STACK_SIZE=8192 CONFIG_FREERTOS_IDLE_TASK_STACKSIZE=4096 # BT -CONFIG_BT_BTC_TASK_STACK_SIZE=8192 +CONFIG_BT_BTC_TASK_STACK_SIZE=15000 CONFIG_BT_ENABLED=y CONFIG_BT_BLUEDROID_ENABLED=y CONFIG_BT_CLASSIC_ENABLED=n diff --git a/examples/light.rs b/examples/light.rs index 0e469ea..06db701 100644 --- a/examples/light.rs +++ b/examples/light.rs @@ -43,7 +43,7 @@ fn main() -> Result<(), Error> { // confused by the low priority of the ESP IDF main task // Also allocate a large stack as `rs-matter` futures do occupy quite some space let thread = std::thread::Builder::new() - .stack_size(40 * 1024) + .stack_size(60 * 1024) .spawn(run) .unwrap(); diff --git a/src/ble.rs b/src/ble.rs index c91987f..4151216 100644 --- a/src/ble.rs +++ b/src/ble.rs @@ -33,6 +33,7 @@ use rs_matter::transport::network::btp::{ }; use rs_matter::transport::network::BtAddr; use rs_matter::utils::ifmutex::IfMutex; +use rs_matter::utils::signal::Signal; use crate::error::Error; @@ -66,6 +67,7 @@ struct IndBuffer { pub struct BtpGattContext { state: Mutex>, ind: IfMutex, + ind_in_flight: Signal, } impl BtpGattContext { @@ -84,6 +86,7 @@ impl BtpGattContext { addr: BtAddr([0; 6]), data: heapless::Vec::new(), }), + ind_in_flight: Signal::new(false), } } @@ -176,10 +179,27 @@ where info!("Gatts BTP app registered"); loop { + self.context + .ind_in_flight + .wait(|in_flight| (!*in_flight).then_some(())) + .await; + let mut ind = self.context.ind.lock_if(|ind| !ind.data.is_empty()).await; let ctx = GattExecContext::new(self.app_id, &gap, &gatts, self.context); + self.context.ind_in_flight.modify(|in_flight| { + if !*in_flight { + *in_flight = true; + } else { + // Should not happen as the only code that sets in flight to `true` + // is here + unreachable!(); + } + + (true, ()) + }); + // TODO: Is this asynchronous? ctx.indicate(&ind.data, ind.addr)?; @@ -284,8 +304,12 @@ where if let Some((gatts_if, conn_id, attr_handle)) = conn { self.gatts.indicate(gatts_if, conn_id, attr_handle, data)?; + info!("Indicated {} bytes to {address}", data.len()); + Ok(true) } else { + warn!("No connection for {address}, cannot indicate"); + Ok(false) } } @@ -390,6 +414,20 @@ where &mut callback, )?; } + GattsEvent::Confirm { status, .. } => { + self.check_gatt_status(status)?; + self.ctx.ind_in_flight.modify(|in_flight| { + if *in_flight { + *in_flight = false; + } else { + // Should not happen: means we have received a confirmation for + // an indication we did not send. + unreachable!(); + } + + (true, ()) + }); + } _ => (), } @@ -431,11 +469,8 @@ where }); self.gap.set_device_name(service_name)?; - self.gap.set_raw_adv_conf( - &service_adv_data - .service_payload_iter() - .collect::>(), - )?; + self.gap + .set_raw_adv_conf(&service_adv_data.iter().collect::>())?; self.gatts.create_service( gatt_if, &GattServiceId { @@ -649,7 +684,7 @@ where { let event = self.ctx.state.lock(|state| { let mut state = state.borrow_mut(); - let c2_handle = state.c2_handle; + let c1_handle = state.c1_handle; let c2_cccd_handle = state.c2_cccd_handle; let conn = state @@ -658,9 +693,7 @@ where .find(|conn| conn.conn_id == conn_id)?; if c2_cccd_handle == Some(handle) { - // TODO: What if this needs a response? - - if !is_prep && offset == 0 && value.len() == 2 { + if offset == 0 && value.len() == 2 { let value = u16::from_le_bytes([value[0], value[1]]); if value == 0x02 { if !conn.subscribed { @@ -674,8 +707,7 @@ where return Some(GattPeripheralEvent::NotifyUnsubscribed(BtAddr(addr.into()))); } } - } else if c2_handle == Some(handle) && offset == 0 { - // TODO: Is it safe to report the write before it was confirmed? + } else if c1_handle == Some(handle) && offset == 0 { return Some(GattPeripheralEvent::Write { address: BtAddr(addr.into()), data: value, @@ -686,36 +718,57 @@ where }); if let Some(event) = event { - if matches!(event, GattPeripheralEvent::Write { .. }) && need_rsp { - if is_prep { - self.ctx.state.lock(|state| { - let mut state = state.borrow_mut(); - - state - .response - .attr_handle(handle) - .auth_req(0) - .offset(offset) - .value(value) - .map_err(|_| EspError::from_infallible::())?; - - self.gatts.send_response( - gatt_if, - conn_id, - trans_id, - GattStatus::Ok, - Some(&state.response), - ) - })?; - } else { - self.gatts - .send_response(gatt_if, conn_id, trans_id, GattStatus::Ok, None)?; - } - } + self.send_write_response( + gatt_if, conn_id, trans_id, handle, offset, need_rsp, is_prep, value, + )?; callback(event); } Ok(()) } + + #[allow(clippy::too_many_arguments)] + fn send_write_response( + &self, + gatt_if: GattInterface, + conn_id: ConnectionId, + trans_id: TransferId, + handle: Handle, + offset: u16, + need_rsp: bool, + is_prep: bool, + value: &[u8], + ) -> Result<(), EspError> { + if !need_rsp { + return Ok(()); + } + + if is_prep { + self.ctx.state.lock(|state| { + let mut state = state.borrow_mut(); + + state + .response + .attr_handle(handle) + .auth_req(0) + .offset(offset) + .value(value) + .map_err(|_| EspError::from_infallible::())?; + + self.gatts.send_response( + gatt_if, + conn_id, + trans_id, + GattStatus::Ok, + Some(&state.response), + ) + })?; + } else { + self.gatts + .send_response(gatt_if, conn_id, trans_id, GattStatus::Ok, None)?; + } + + Ok(()) + } } diff --git a/src/wifi/comm.rs b/src/wifi/comm.rs index bbe8420..3ef5f20 100644 --- a/src/wifi/comm.rs +++ b/src/wifi/comm.rs @@ -1,6 +1,6 @@ use embassy_sync::blocking_mutex::raw::RawMutex; -use log::{error, info}; +use log::{error, info, warn}; use rs_matter::data_model::objects::{ AsyncHandler, AttrDataEncoder, AttrDataWriter, AttrDetails, AttrType, CmdDataEncoder, @@ -159,6 +159,8 @@ where ) -> Result<(), Error> { let mut tw = encoder.with_command(ResponseCommands::ScanNetworksResponse as _)?; + warn!("Scan network not supported"); + Status::new(IMStatusCode::Busy, 0).to_tlv(&mut tw, TagType::Anonymous)?; Ok(()) @@ -166,7 +168,7 @@ where fn add_network( &self, - exchange: &Exchange<'_>, + _exchange: &Exchange<'_>, req: &AddWifiNetworkRequest<'_>, encoder: CmdDataEncoder<'_, '_, '_>, ) -> Result<(), Error> { @@ -194,7 +196,8 @@ where .unwrap(); state.changed = true; - exchange.matter().notify_changed(); + + info!("Updated network with SSID {}", state.networks[index].ssid); NetworkConfigResponse { status: NetworkCommissioningStatus::Success, @@ -216,23 +219,32 @@ where .unwrap(), }; - if state.networks.push(network).is_ok() { - state.changed = true; - exchange.matter().notify_changed(); - - NetworkConfigResponse { - status: NetworkCommissioningStatus::Success, - debug_text: None, - network_index: Some(state.networks.len() as _), + match state.networks.push(network) { + Ok(_) => { + state.changed = true; + + info!( + "Added network with SSID {}", + state.networks.last().unwrap().ssid + ); + + NetworkConfigResponse { + status: NetworkCommissioningStatus::Success, + debug_text: None, + network_index: Some(state.networks.len() as _), + } + .to_tlv(&mut tw, TagType::Anonymous)?; } - .to_tlv(&mut tw, TagType::Anonymous)?; - } else { - NetworkConfigResponse { - status: NetworkCommissioningStatus::BoundsExceeded, - debug_text: None, - network_index: None, + Err(network) => { + warn!("Adding network with SSID {} failed: too many", network.ssid); + + NetworkConfigResponse { + status: NetworkCommissioningStatus::BoundsExceeded, + debug_text: None, + network_index: None, + } + .to_tlv(&mut tw, TagType::Anonymous)?; } - .to_tlv(&mut tw, TagType::Anonymous)?; } } @@ -242,7 +254,7 @@ where fn remove_network( &self, - exchange: &Exchange<'_>, + _exchange: &Exchange<'_>, req: &RemoveNetworkRequest<'_>, encoder: CmdDataEncoder<'_, '_, '_>, ) -> Result<(), Error> { @@ -260,9 +272,10 @@ where if let Some(index) = index { // Found - state.networks.remove(index); + let network = state.networks.remove(index); state.changed = true; - exchange.matter().notify_changed(); + + info!("Removed network with SSID {}", network.ssid); NetworkConfigResponse { status: NetworkCommissioningStatus::Success, @@ -271,6 +284,11 @@ where } .to_tlv(&mut tw, TagType::Anonymous)?; } else { + warn!( + "Network with SSID {} not found", + core::str::from_utf8(req.network_id.0).unwrap() + ); + // Not found NetworkConfigResponse { status: NetworkCommissioningStatus::NetworkIdNotFound, @@ -295,26 +313,26 @@ where // Non-concurrent commissioning scenario (i.e. only BLE is active, and the ESP IDF co-exist mode is not enabled) // Notify that we have received a connect command + let ssid = core::str::from_utf8(req.network_id.0).unwrap(); + self.networks.state.lock(|state| { let mut state = state.borrow_mut(); - state.connect_requested = Some( - core::str::from_utf8(req.network_id.0) - .unwrap() - .try_into() - .unwrap(), - ); + state.connect_requested = Some(ssid.try_into().unwrap()); }); self.networks.network_connect_requested.notify(); + warn!("Connecting to network with SSID {} not supported due to non-concurrent commissioning in place", ssid); + warn!("Response to ConnectNetwork will pend forever"); + // Block forever waiting for the firware to restart core::future::pending().await } fn reorder_network( &self, - exchange: &Exchange<'_>, + _exchange: &Exchange<'_>, req: &ReorderNetworkRequest<'_>, encoder: CmdDataEncoder<'_, '_, '_>, ) -> Result<(), Error> { @@ -342,7 +360,12 @@ where .unwrap(); state.changed = true; - exchange.matter().notify_changed(); + + info!( + "Network with SSID {} reordered to index {}", + core::str::from_utf8(req.network_id.0).unwrap(), + req.index + ); NetworkConfigResponse { status: NetworkCommissioningStatus::Success, @@ -351,6 +374,12 @@ where } .to_tlv(&mut tw, TagType::Anonymous)?; } else { + warn!( + "Reordering network with SSID {} to index {} failed: out of range", + core::str::from_utf8(req.network_id.0).unwrap(), + req.index + ); + NetworkConfigResponse { status: NetworkCommissioningStatus::OutOfRange, debug_text: None, @@ -359,6 +388,11 @@ where .to_tlv(&mut tw, TagType::Anonymous)?; } } else { + warn!( + "Network with SSID {} not found", + core::str::from_utf8(req.network_id.0).unwrap() + ); + // Not found NetworkConfigResponse { status: NetworkCommissioningStatus::NetworkIdNotFound,