From 6fb14eecdbc2fa9f2cbfa85ea4f64b61d20ab512 Mon Sep 17 00:00:00 2001 From: ivmarkov Date: Wed, 1 May 2024 16:53:15 +0000 Subject: [PATCH] Bugfixing, more logging --- src/ble.rs | 4 ++-- src/netif.rs | 18 ++++++++++++++--- src/stack.rs | 9 +++++++++ src/wifi.rs | 20 ++++++++++++++----- src/wifi/comm.rs | 50 ++++++++++++++++++++---------------------------- src/wifi/mgmt.rs | 47 +++++++++++++++++++++++++++++++++++---------- 6 files changed, 99 insertions(+), 49 deletions(-) diff --git a/src/ble.rs b/src/ble.rs index 4151216..2ea0725 100644 --- a/src/ble.rs +++ b/src/ble.rs @@ -24,7 +24,7 @@ use esp_idf_svc::bt::{BdAddr, BleEnabled, BtDriver, BtStatus, BtUuid}; use esp_idf_svc::hal::task::embassy_sync::EspRawMutex; use esp_idf_svc::sys::{EspError, ESP_FAIL}; -use log::{info, warn}; +use log::{debug, info, warn}; use rs_matter::error::ErrorCode; use rs_matter::transport::network::btp::{ @@ -304,7 +304,7 @@ 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()); + debug!("Indicated {} bytes to {address}", data.len()); Ok(true) } else { diff --git a/src/netif.rs b/src/netif.rs index f37c037..b4b10be 100644 --- a/src/netif.rs +++ b/src/netif.rs @@ -3,16 +3,21 @@ use core::net::{Ipv4Addr, Ipv6Addr}; use core::pin::pin; +use alloc::sync::Arc; + use embassy_futures::select::select; use embassy_time::{Duration, Timer}; use esp_idf_svc::eventloop::EspSystemEventLoop; +use esp_idf_svc::hal::task::embassy_sync::EspRawMutex; use esp_idf_svc::handle::RawHandle; use esp_idf_svc::netif::{EspNetif, IpEvent}; use esp_idf_svc::sys::{esp, esp_netif_get_ip6_linklocal, EspError, ESP_FAIL}; use log::info; +use rs_matter::utils::notification::Notification; + use crate::error::Error; pub trait NetifAccess { @@ -24,15 +29,22 @@ pub trait NetifAccess { where F: FnMut(&EspNetif) -> Result, Error>, { - // TODO: Maybe wait on Wifi and Eth events as well - let mut subscription = sysloop.subscribe_async::()?; + let notification = Arc::new(Notification::::new()); + + let _subscription = { + let notification = notification.clone(); + + sysloop.subscribe::(move |_| { + notification.notify(); + }) + }?; loop { if let Some(result) = self.with_netif(&mut f).await? { break Ok(result); } - let mut events = pin!(subscription.recv()); + let mut events = pin!(notification.wait()); let mut timer = pin!(Timer::after(Duration::from_secs(5))); select(&mut events, &mut timer).await; diff --git a/src/stack.rs b/src/stack.rs index b9e2058..957e89d 100644 --- a/src/stack.rs +++ b/src/stack.rs @@ -114,10 +114,14 @@ where N: NetifAccess, { loop { + info!("Waiting for the network to come up..."); + let (ipv4, ipv6) = netif .wait(sysloop.clone(), |netif| Ok(get_ips(netif).ok())) .await?; + info!("Got network with IPs: IPv4={ipv4}, IPv6={ipv6}"); + let socket = async_io::Async::::bind(MATTER_SOCKET_BIND_ADDR)?; let mut main = @@ -131,6 +135,8 @@ where })); select3(&mut main, &mut mdns, &mut down).coalesce().await?; + + info!("Network change detected"); } } @@ -485,6 +491,9 @@ mod wifible { .await?; } + // Reset the matter transport to free up sessions and exchanges + self.matter().reset(); + let mut wifi = EspWifi::new(&mut modem, sysloop.clone(), Some(nvs.clone()))?; info!("Wifi driver initialized"); diff --git a/src/wifi.rs b/src/wifi.rs index 4dcfc9d..1342409 100644 --- a/src/wifi.rs +++ b/src/wifi.rs @@ -2,6 +2,8 @@ use core::cell::RefCell; use embassy_sync::blocking_mutex::{self, raw::RawMutex}; +use log::info; + use rs_matter::data_model::sdm::nw_commissioning::NetworkCommissioningStatus; use rs_matter::error::{Error, ErrorCode}; use rs_matter::tlv::{self, FromTLV, TLVList, TLVWriter, TagType, ToTLV}; @@ -38,12 +40,16 @@ impl WifiState { if let Some(ssid) = self.connect_requested.take() { let creds = self.networks.iter().find(|creds| creds.ssid == ssid); - if creds.is_some() { - return creds.cloned(); + if let Some(creds) = creds { + info!("Trying with requested network first - SSID: {}", creds.ssid); + + return Some(creds.clone()); } } if let Some(last_ssid) = last_ssid { + info!("Looking for network after the one with SSID: {}", last_ssid); + // Return the network positioned after the last one used let mut networks = self.networks.iter(); @@ -54,13 +60,17 @@ impl WifiState { } } - let network = networks.next(); - if network.is_some() { - return network.cloned(); + let creds = networks.next(); + if let Some(creds) = creds { + info!("Trying with next network - SSID: {}", creds.ssid); + + return Some(creds.clone()); } } // Wrap over + info!("Wrapping over"); + self.networks.first().cloned() } diff --git a/src/wifi/comm.rs b/src/wifi/comm.rs index 3ef5f20..2e8f112 100644 --- a/src/wifi/comm.rs +++ b/src/wifi/comm.rs @@ -157,11 +157,11 @@ where _req: &ScanNetworksRequest<'_>, encoder: CmdDataEncoder<'_, '_, '_>, ) -> Result<(), Error> { - let mut tw = encoder.with_command(ResponseCommands::ScanNetworksResponse as _)?; + let writer = encoder.with_command(ResponseCommands::ScanNetworksResponse as _)?; warn!("Scan network not supported"); - Status::new(IMStatusCode::Busy, 0).to_tlv(&mut tw, TagType::Anonymous)?; + writer.set(Status::new(IMStatusCode::Busy, 0))?; Ok(()) } @@ -182,7 +182,7 @@ where .iter() .position(|conf| conf.ssid.as_str().as_bytes() == req.ssid.0); - let mut tw = encoder.with_command(ResponseCommands::NetworkConfigResponse as _)?; + let writer = encoder.with_command(ResponseCommands::NetworkConfigResponse as _)?; if let Some(index) = index { // Update @@ -199,12 +199,11 @@ where info!("Updated network with SSID {}", state.networks[index].ssid); - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::Success, debug_text: None, network_index: Some(index as _), - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } else { // Add let network = WifiCredentials { @@ -228,22 +227,20 @@ where state.networks.last().unwrap().ssid ); - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::Success, debug_text: None, network_index: Some(state.networks.len() as _), - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } Err(network) => { warn!("Adding network with SSID {} failed: too many", network.ssid); - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::BoundsExceeded, debug_text: None, network_index: None, - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } } } @@ -268,7 +265,7 @@ where .iter() .position(|conf| conf.ssid.as_str().as_bytes() == req.network_id.0); - let mut tw = encoder.with_command(ResponseCommands::NetworkConfigResponse as _)?; + let writer = encoder.with_command(ResponseCommands::NetworkConfigResponse as _)?; if let Some(index) = index { // Found @@ -277,12 +274,11 @@ where info!("Removed network with SSID {}", network.ssid); - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::Success, debug_text: None, network_index: Some(index as _), - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } else { warn!( "Network with SSID {} not found", @@ -290,12 +286,11 @@ where ); // Not found - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::NetworkIdNotFound, debug_text: None, network_index: None, - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } Ok(()) @@ -346,7 +341,7 @@ where .iter() .position(|conf| conf.ssid.as_str().as_bytes() == req.network_id.0); - let mut tw = encoder.with_command(ResponseCommands::NetworkConfigResponse as _)?; + let writer = encoder.with_command(ResponseCommands::NetworkConfigResponse as _)?; if let Some(index) = index { // Found @@ -367,12 +362,11 @@ where req.index ); - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::Success, debug_text: None, network_index: Some(req.index as _), - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } else { warn!( "Reordering network with SSID {} to index {} failed: out of range", @@ -380,12 +374,11 @@ where req.index ); - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::OutOfRange, debug_text: None, network_index: Some(req.index as _), - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } } else { warn!( @@ -394,12 +387,11 @@ where ); // Not found - NetworkConfigResponse { + writer.set(NetworkConfigResponse { status: NetworkCommissioningStatus::NetworkIdNotFound, debug_text: None, network_index: None, - } - .to_tlv(&mut tw, TagType::Anonymous)?; + })?; } Ok(()) diff --git a/src/wifi/mgmt.rs b/src/wifi/mgmt.rs index 2eb16a0..565a8f8 100644 --- a/src/wifi/mgmt.rs +++ b/src/wifi/mgmt.rs @@ -6,12 +6,15 @@ use core::pin::pin; +use alloc::sync::Arc; + use embassy_futures::select::select; use embassy_sync::blocking_mutex::raw::RawMutex; use embassy_sync::mutex::Mutex; use embassy_time::{Duration, Timer}; use esp_idf_svc::eventloop::EspSystemEventLoop; +use esp_idf_svc::hal::task::embassy_sync::EspRawMutex; use esp_idf_svc::netif::EspNetif; use esp_idf_svc::sys::{EspError, ESP_ERR_INVALID_STATE}; use esp_idf_svc::wifi::{self as wifi, AsyncWifi, AuthMethod, EspWifi, WifiEvent}; @@ -19,6 +22,7 @@ use esp_idf_svc::wifi::{self as wifi, AsyncWifi, AuthMethod, EspWifi, WifiEvent} use log::{error, info, warn}; use rs_matter::data_model::sdm::nw_commissioning::NetworkCommissioningStatus; +use rs_matter::utils::notification::Notification; use crate::netif::NetifAccess; @@ -73,6 +77,7 @@ where let Some(creds) = creds else { // No networks, bail out + warn!("No networks found"); return Err(EspError::from_infallible::().into()); }; @@ -128,8 +133,15 @@ where } async fn wait_disconnect(&self) -> Result<(), EspError> { - // TODO: Maybe wait on Wifi and Eth events as well - let mut subscription = self.sysloop.subscribe_async::()?; + let notification = Arc::new(Notification::::new()); + + let _subscription = { + let notification = notification.clone(); + + self.sysloop.subscribe::(move |_| { + notification.notify(); + }) + }?; loop { { @@ -139,7 +151,7 @@ where } } - let mut events = pin!(subscription.recv()); + let mut events = pin!(notification.wait()); let mut timer = pin!(Timer::after(Duration::from_secs(5))); select(&mut events, &mut timer).await; @@ -147,6 +159,8 @@ where } async fn connect(&self, creds: &WifiCredentials) -> Result<(), EspError> { + info!("Connecting to SSID {}", creds.ssid); + let auth_methods: &[AuthMethod] = if creds.password.is_empty() { &[AuthMethod::None] } else { @@ -160,7 +174,6 @@ where let mut result = Ok(()); for auth_method in auth_methods.iter().copied() { - let connect = !matches!(auth_method, wifi::AuthMethod::None); let conf = wifi::Configuration::Client(wifi::ClientConfiguration { ssid: creds.ssid.clone(), auth_method, @@ -168,7 +181,7 @@ where ..Default::default() }); - result = self.connect_with(&conf, connect).await; + result = self.connect_with(&conf).await; if result.is_ok() { break; @@ -178,22 +191,36 @@ where result } - async fn connect_with( - &self, - conf: &wifi::Configuration, - connect: bool, - ) -> Result<(), EspError> { + async fn connect_with(&self, conf: &wifi::Configuration) -> Result<(), EspError> { + info!("Connecting with {:?}", conf); + let mut wifi = self.wifi.lock().await; let _ = wifi.stop().await; wifi.set_configuration(conf)?; + info!("Configuration set"); + wifi.start().await?; + info!("Wifi driver started"); + + let connect = matches!(conf, wifi::Configuration::Client(_)) + && !matches!( + conf, + wifi::Configuration::Client(wifi::ClientConfiguration { + auth_method: wifi::AuthMethod::None, + .. + }) + ); + if connect { + info!("Connecting..."); wifi.connect().await?; } + info!("Successfully connected with {:?}", conf); + Ok(()) } }