From a77bfa5f79652c48ba1f5c2a9e9ae311e2370d4a Mon Sep 17 00:00:00 2001 From: Akrm Al-Hakimi Date: Mon, 12 Jan 2026 11:49:17 -0500 Subject: [PATCH 1/2] refactor: better error context and debugging Replace silent error swallowing with warning logs throughout VPN operations, connection cleanup and device property retrieval to improve debuggin and diagnostics. --- nmrs/src/core/connection.rs | 28 +++- nmrs/src/core/device.rs | 53 ++++++-- nmrs/src/core/vpn.rs | 248 +++++++++++++++++++++++++++--------- nmrs/src/monitoring/info.rs | 33 ++++- nmrs/src/util/utils.rs | 44 ++++++- 5 files changed, 323 insertions(+), 83 deletions(-) diff --git a/nmrs/src/core/connection.rs b/nmrs/src/core/connection.rs index d71b8773..f2af227d 100644 --- a/nmrs/src/core/connection.rs +++ b/nmrs/src/core/connection.rs @@ -322,7 +322,13 @@ pub(crate) async fn disconnect_wifi_and_wait( .await?; debug!("Sending disconnect request"); - let _ = raw.call_method("Disconnect", &()).await; + match raw.call_method("Disconnect", &()).await { + Ok(_) => debug!("Disconnect method called successfully"), + Err(e) => warn!( + "Disconnect method call failed (device may already be disconnected): {}", + e + ), + } // Wait for disconnect using signal-based monitoring wait_for_device_disconnect(&dev).await?; @@ -416,7 +422,10 @@ async fn ensure_disconnected( if let Ok(conns) = nm.active_connections().await { for conn_path in conns { - let _ = nm.deactivate_connection(conn_path).await; + match nm.deactivate_connection(conn_path.clone()).await { + Ok(_) => debug!("Connection deactivated during cleanup"), + Err(e) => warn!("Failed to deactivate connection during cleanup: {}", e), + } } } @@ -463,8 +472,14 @@ async fn connect_via_saved( warn!("Saved connection activation failed: {e}"); warn!("Deleting saved connection and retrying with fresh credentials"); - let _ = nm.deactivate_connection(active_conn).await; - let _ = delete_connection(conn, saved.clone()).await; + match nm.deactivate_connection(active_conn.clone()).await { + Ok(_) => debug!("Connection deactivated during cleanup"), + Err(e) => warn!("Failed to deactivate connection during cleanup: {}", e), + } + match delete_connection(conn, saved.clone()).await { + Ok(_) => debug!("Saved connection deleted"), + Err(e) => warn!("Failed to delete saved connection during recovery: {}", e), + } let opts = ConnectionOptions { autoconnect: true, @@ -493,7 +508,10 @@ async fn connect_via_saved( warn!("activate_connection() failed: {e}"); warn!("Saved connection may be corrupted, deleting and retrying with fresh connection"); - let _ = delete_connection(conn, saved.clone()).await; + match delete_connection(conn, saved.clone()).await { + Ok(_) => debug!("Saved connection deleted"), + Err(e) => warn!("Failed to delete saved connection during recovery: {}", e), + } let opts = ConnectionOptions { autoconnect: true, diff --git a/nmrs/src/core/device.rs b/nmrs/src/core/device.rs index cb3008aa..6de84f21 100644 --- a/nmrs/src/core/device.rs +++ b/nmrs/src/core/device.rs @@ -4,7 +4,7 @@ //! and enabling/disabling Wi-Fi. Uses D-Bus signals for efficient state //! monitoring instead of polling. -use log::debug; +use log::{debug, warn}; use zbus::Connection; use crate::api::models::{ConnectionError, Device, DeviceIdentity, DeviceState}; @@ -30,21 +30,48 @@ pub(crate) async fn list_devices(conn: &Connection) -> Result> { let interface = d_proxy.interface().await?; let raw_type = d_proxy.device_type().await?; - let current_mac = d_proxy - .hw_address() - .await - .unwrap_or_else(|_| String::from("00:00:00:00:00:00")); - // PermHwAddress may not be available on all systems/devices - // If not available, fall back to HwAddress - let perm_mac = d_proxy - .perm_hw_address() - .await - .unwrap_or_else(|_| current_mac.clone()); + let current_mac = match d_proxy.hw_address().await { + Ok(addr) => addr, + Err(e) => { + warn!( + "Failed to get hardware address for device {}: {}", + interface, e + ); + String::from("00:00:00:00:00:00") + } + }; + + let perm_mac = match d_proxy.perm_hw_address().await { + Ok(addr) => addr, + Err(e) => { + debug!( + "Permanent hardware address not available for device {}: {}", + interface, e + ); + current_mac.clone() + } + }; + let device_type = raw_type.into(); let raw_state = d_proxy.state().await?; let state = raw_state.into(); - let managed = d_proxy.managed().await.ok(); - let driver = d_proxy.driver().await.ok(); + let managed = match d_proxy.managed().await { + Ok(m) => Some(m), + Err(e) => { + debug!( + "Failed to get 'managed' property for device {}: {}", + interface, e + ); + None + } + }; + let driver = match d_proxy.driver().await { + Ok(d) => Some(d), + Err(e) => { + debug!("Failed to get driver for device {}: {}", interface, e); + None + } + }; devices.push(Device { path: p.to_string(), diff --git a/nmrs/src/core/vpn.rs b/nmrs/src/core/vpn.rs index 470f0928..03cf025c 100644 --- a/nmrs/src/core/vpn.rs +++ b/nmrs/src/core/vpn.rs @@ -21,7 +21,7 @@ use crate::api::models::{ use crate::builders::build_wireguard_connection; use crate::core::state_wait::wait_for_connection_activation; use crate::dbus::{NMActiveConnectionProxy, NMProxy}; -use crate::util::utils::nm_proxy; +use crate::util::utils::{extract_connection_state_reason, nm_proxy}; use crate::Result; /// Connects to a WireGuard connection. @@ -98,8 +98,9 @@ pub(crate) async fn connect_vpn(conn: &Connection, creds: VpnCredentials) -> Res } crate::api::models::ActiveConnectionState::Deactivated => { warn!("Connection deactivated immediately after activation"); + let reason = extract_connection_state_reason(conn, &active_conn).await; Err(crate::api::models::ConnectionError::ActivationFailed( - crate::api::models::ConnectionStateReason::Unknown, + reason, )) } _ => { @@ -113,8 +114,9 @@ pub(crate) async fn connect_vpn(conn: &Connection, creds: VpnCredentials) -> Res } Err(e) => { warn!("Failed to build active connection proxy after delay: {}", e); + let reason = extract_connection_state_reason(conn, &active_conn).await; Err(crate::api::models::ConnectionError::ActivationFailed( - crate::api::models::ConnectionStateReason::Unknown, + reason, )) } }, @@ -123,8 +125,9 @@ pub(crate) async fn connect_vpn(conn: &Connection, creds: VpnCredentials) -> Res "Failed to create active connection proxy builder after delay: {}", e ); + let reason = extract_connection_state_reason(conn, &active_conn).await; Err(crate::api::models::ConnectionError::ActivationFailed( - crate::api::models::ConnectionStateReason::Unknown, + reason, )) } } @@ -157,15 +160,30 @@ pub(crate) async fn disconnect_vpn(conn: &Connection, name: &str) -> Result<()> .await { Ok(p) => p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to create proxy for active connection {}: {}", + ac_path, e + ); + continue; + } }; let conn_path: OwnedObjectPath = match ac_proxy.call_method("Connection", &()).await { Ok(msg) => match msg.body().deserialize::() { Ok(path) => path, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to deserialize connection path for {}: {}", + ac_path, e + ); + continue; + } }, - Err(_) => continue, + Err(e) => { + warn!("Failed to get Connection property from {}: {}", ac_path, e); + continue; + } }; let cproxy = match nm_proxy( @@ -176,19 +194,31 @@ pub(crate) async fn disconnect_vpn(conn: &Connection, name: &str) -> Result<()> .await { Ok(p) => p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to create proxy for connection settings {}: {}", + conn_path, e + ); + continue; + } }; let msg = match cproxy.call_method("GetSettings", &()).await { Ok(msg) => msg, - Err(_) => continue, + Err(e) => { + warn!("Failed to get settings for connection {}: {}", conn_path, e); + continue; + } }; let body = msg.body(); let settings_map: HashMap> = match body.deserialize() { Ok(map) => map, - Err(_) => continue, + Err(e) => { + warn!("Failed to deserialize settings for {}: {}", conn_path, e); + continue; + } }; if let Some(conn_sec) = settings_map.get("connection") { @@ -210,8 +240,10 @@ pub(crate) async fn disconnect_vpn(conn: &Connection, name: &str) -> Result<()> if id_match && is_wireguard { debug!("Found active WireGuard connection, deactivating: {name}"); - let _ = nm.deactivate_connection(ac_path).await; - info!("Successfully disconnected VPN: {name}"); + match nm.deactivate_connection(ac_path.clone()).await { + Ok(_) => info!("Successfully disconnected VPN: {name}"), + Err(e) => warn!("Failed to deactivate connection {}: {}", ac_path, e), + } return Ok(()); } } @@ -251,38 +283,65 @@ pub(crate) async fn list_vpn_connections(conn: &Connection) -> Result p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to create proxy for active connection {}: {}", + ac_path, e + ); + continue; + } }; let conn_path: OwnedObjectPath = match ac_proxy.call_method("Connection", &()).await { Ok(msg) => match msg.body().deserialize::() { Ok(p) => p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to deserialize connection path for {}: {}", + ac_path, e + ); + continue; + } }, - Err(_) => continue, + Err(e) => { + warn!("Failed to get Connection property from {}: {}", ac_path, e); + continue; + } }; let cproxy = match nm_proxy( conn, - conn_path, + conn_path.clone(), "org.freedesktop.NetworkManager.Settings.Connection", ) .await { Ok(p) => p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to create proxy for connection settings {}: {}", + conn_path, e + ); + continue; + } }; let msg = match cproxy.call_method("GetSettings", &()).await { Ok(m) => m, - Err(_) => continue, + Err(e) => { + warn!("Failed to get settings for connection {}: {}", conn_path, e); + continue; + } }; let body = msg.body(); let settings_map: HashMap> = match body.deserialize() { Ok(m) => m, - Err(_) => continue, + Err(e) => { + warn!("Failed to deserialize settings for {}: {}", conn_path, e); + continue; + } }; let conn_sec = match settings_map.get("connection") { @@ -322,8 +381,20 @@ pub(crate) async fn list_vpn_connections(conn: &Connection) -> Result dev_proxy.get_property::("Interface").await.ok(), - Err(_) => None, + Ok(dev_proxy) => match dev_proxy.get_property::("Interface").await { + Ok(iface) => Some(iface), + Err(e) => { + debug!( + "Failed to get interface name for VPN device {}: {}", + dev_path, e + ); + None + } + }, + Err(e) => { + debug!("Failed to create device proxy for {}: {}", dev_path, e); + None + } } } else { None @@ -346,19 +417,37 @@ pub(crate) async fn list_vpn_connections(conn: &Connection) -> Result p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to create proxy for saved connection {}: {}", + cpath, e + ); + continue; + } }; let msg = match cproxy.call_method("GetSettings", &()).await { Ok(m) => m, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to get settings for saved connection {}: {}", + cpath, e + ); + continue; + } }; let body = msg.body(); let settings_map: HashMap> = match body.deserialize() { Ok(m) => m, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to deserialize settings for saved connection {}: {}", + cpath, e + ); + continue; + } }; let conn_sec = match settings_map.get("connection") { @@ -402,7 +491,13 @@ pub(crate) async fn list_vpn_connections(conn: &Connection) -> Result Result<()> { debug!("Starting forget operation for VPN: {name}"); - let _ = disconnect_vpn(conn, name).await; + match disconnect_vpn(conn, name).await { + Ok(_) => debug!("VPN disconnected before deletion"), + Err(e) => warn!( + "Failed to disconnect VPN before deletion (may already be disconnected): {}", + e + ), + } let settings = nm_proxy( conn, @@ -423,37 +518,45 @@ pub(crate) async fn forget_vpn(conn: &Connection, name: &str) -> Result<()> { .await { Ok(p) => p, - Err(_) => continue, + Err(e) => { + warn!("Failed to create proxy for connection {}: {}", cpath, e); + continue; + } }; - if let Ok(msg) = cproxy.call_method("GetSettings", &()).await { - let body = msg.body(); - let settings_map: HashMap> = - body.deserialize()?; + let msg = match cproxy.call_method("GetSettings", &()).await { + Ok(msg) => msg, + Err(e) => { + warn!("Failed to get settings for connection {}: {}", cpath, e); + continue; + } + }; - if let Some(conn_sec) = settings_map.get("connection") { - let id_ok = conn_sec - .get("id") - .and_then(|v| match v { - zvariant::Value::Str(s) => Some(s.as_str() == name), - _ => None, - }) - .unwrap_or(false); + let body = msg.body(); + let settings_map: HashMap> = body.deserialize()?; - let type_ok = conn_sec - .get("type") - .and_then(|v| match v { - zvariant::Value::Str(s) => Some(s.as_str() == "wireguard"), - _ => None, - }) - .unwrap_or(false); - - if id_ok && type_ok { - debug!("Found WireGuard connection, deleting: {name}"); - cproxy.call_method("Delete", &()).await?; - info!("Successfully deleted VPN connection: {name}"); - return Ok(()); - } + if let Some(conn_sec) = settings_map.get("connection") { + let id_ok = conn_sec + .get("id") + .and_then(|v| match v { + zvariant::Value::Str(s) => Some(s.as_str() == name), + _ => None, + }) + .unwrap_or(false); + + let type_ok = conn_sec + .get("type") + .and_then(|v| match v { + zvariant::Value::Str(s) => Some(s.as_str() == "wireguard"), + _ => None, + }) + .unwrap_or(false); + + if id_ok && type_ok { + debug!("Found WireGuard connection, deleting: {name}"); + cproxy.call_method("Delete", &()).await?; + info!("Successfully deleted VPN connection: {name}"); + return Ok(()); } } } @@ -478,38 +581,65 @@ pub(crate) async fn get_vpn_info(conn: &Connection, name: &str) -> Result p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to create proxy for active connection {}: {}", + ac_path, e + ); + continue; + } }; let conn_path: OwnedObjectPath = match ac_proxy.call_method("Connection", &()).await { Ok(msg) => match msg.body().deserialize::() { Ok(p) => p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to deserialize connection path for {}: {}", + ac_path, e + ); + continue; + } }, - Err(_) => continue, + Err(e) => { + warn!("Failed to get Connection property from {}: {}", ac_path, e); + continue; + } }; let cproxy = match nm_proxy( conn, - conn_path, + conn_path.clone(), "org.freedesktop.NetworkManager.Settings.Connection", ) .await { Ok(p) => p, - Err(_) => continue, + Err(e) => { + warn!( + "Failed to create proxy for connection settings {}: {}", + conn_path, e + ); + continue; + } }; let msg = match cproxy.call_method("GetSettings", &()).await { Ok(m) => m, - Err(_) => continue, + Err(e) => { + warn!("Failed to get settings for connection {}: {}", conn_path, e); + continue; + } }; let body = msg.body(); let settings_map: HashMap> = match body.deserialize() { Ok(m) => m, - Err(_) => continue, + Err(e) => { + warn!("Failed to deserialize settings for {}: {}", conn_path, e); + continue; + } }; let conn_sec = match settings_map.get("connection") { diff --git a/nmrs/src/monitoring/info.rs b/nmrs/src/monitoring/info.rs index 9bcce526..0ee92bd7 100644 --- a/nmrs/src/monitoring/info.rs +++ b/nmrs/src/monitoring/info.rs @@ -3,6 +3,7 @@ //! Provides functions to retrieve detailed information about networks //! and query the current connection state. +use log::debug; use zbus::Connection; use crate::api::models::{ConnectionError, Network, NetworkInfo}; @@ -46,9 +47,27 @@ pub(crate) async fn show_details(conn: &Connection, net: &Network) -> Result Some(f), + Err(e) => { + debug!("Failed to get frequency for AP: {}", e); + None + } + }; + let max_br = match ap.max_bitrate().await { + Ok(br) => Some(br), + Err(e) => { + debug!("Failed to get max bitrate for AP: {}", e); + None + } + }; + let mode_raw = match ap.mode().await { + Ok(m) => Some(m), + Err(e) => { + debug!("Failed to get mode for AP: {}", e); + None + } + }; let wep = (flags & security_flags::WEP) != 0 && wpa_flags == 0 && rsn_flags == 0; let wpa1 = wpa_flags != 0; @@ -198,7 +217,13 @@ pub(crate) async fn current_connection_info(conn: &Connection) -> Option<(String ); let ssid_bytes = try_log!(ap.ssid().await, "Failed to get SSID bytes"); let ssid = decode_ssid_or_empty(&ssid_bytes); - let frequency = ap.frequency().await.ok(); + let frequency = match ap.frequency().await { + Ok(f) => Some(f), + Err(e) => { + debug!("Failed to get frequency for current AP: {}", e); + None + } + }; return Some((ssid.to_string(), frequency)); } } diff --git a/nmrs/src/util/utils.rs b/nmrs/src/util/utils.rs index 858c4d8c..3dc09318 100644 --- a/nmrs/src/util/utils.rs +++ b/nmrs/src/util/utils.rs @@ -3,13 +3,16 @@ //! Provides helpers for converting between Wi-Fi data representations: //! frequency to channel, signal strength to visual bars, SSID bytes to strings. -use log::warn; +use log::{debug, warn}; use std::borrow::Cow; use std::str; use zbus::Connection; use zvariant::OwnedObjectPath; -use crate::dbus::{NMAccessPointProxy, NMDeviceProxy, NMProxy, NMWirelessProxy}; +use crate::api::models::ConnectionStateReason; +use crate::dbus::{ + NMAccessPointProxy, NMActiveConnectionProxy, NMDeviceProxy, NMProxy, NMWirelessProxy, +}; use crate::types::constants::{device_type, frequency, signal_strength, wifi_mode}; use crate::Result; @@ -165,6 +168,43 @@ where .await?) } +/// Attempts to extract the actual state reason from an active connection. +/// +/// NetworkManager only provides reason codes via StateChanged signals, not as +/// a queryable property. This helper attempts to query the connection state +/// to verify it exists, but cannot extract the reason for its current state. +/// Returns Unknown if extraction fails, with appropriate logging. +pub(crate) async fn extract_connection_state_reason( + conn: &Connection, + active_conn_path: &OwnedObjectPath, +) -> ConnectionStateReason { + match NMActiveConnectionProxy::builder(conn).path(active_conn_path.clone()) { + Ok(builder) => match builder.build().await { + Ok(ac) => match ac.state().await { + Ok(state) => { + debug!( + "Active connection state: {}, but reason not available as property", + state + ); + ConnectionStateReason::Unknown + } + Err(e) => { + warn!("Failed to query active connection state: {}", e); + ConnectionStateReason::Unknown + } + }, + Err(e) => { + warn!("Failed to build active connection proxy: {}", e); + ConnectionStateReason::Unknown + } + }, + Err(e) => { + warn!("Failed to create active connection proxy builder: {}", e); + ConnectionStateReason::Unknown + } + } +} + /// Macro to convert Result to Option with error logging. /// Usage: `try_log!(result, "context message")?` #[macro_export] From 4eeed0d978c4c8de8dc21dea8811fa1ec79ee690 Mon Sep 17 00:00:00 2001 From: Akrm Al-Hakimi Date: Mon, 12 Jan 2026 11:52:26 -0500 Subject: [PATCH 2/2] chore: update `CHANGELOG.md` --- nmrs/CHANGELOG.md | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/nmrs/CHANGELOG.md b/nmrs/CHANGELOG.md index 3279393c..330c3847 100644 --- a/nmrs/CHANGELOG.md +++ b/nmrs/CHANGELOG.md @@ -3,8 +3,16 @@ All notable changes to the `nmrs` crate will be documented in this file. ## [Unreleased] -### Changed +### Changed - Dedupe DBus proxy construction across connection logic ([#165](https://github.com/cachebag/nmrs/pull/165)) +- Added contextual logging throughout VPN, connection, and device operations to preserve error context and improve debugging capabilities ([#168](https://github.com/cachebag/nmrs/pull/168)) + +### Fixed +- VPN operations no longer silently swallow D-Bus errors - now log warnings when proxy creation or method calls fail ([#168](https://github.com/cachebag/nmrs/pull/168)) +- Connection cleanup operations (disconnect, deactivate, delete) now log failures instead of ignoring them ([#168](https://github.com/cachebag/nmrs/pull/168)) +- VPN error mapping now attempts to extract actual connection state reasons instead of defaulting to `Unknown` ([#168](http://github.com/cachebag/nmrs/pull/168)) +- MAC address retrieval errors are now logged with appropriate context ([#168](https://github.com/cachebag/nmrs/pull/168)) +- Access point property retrieval failures are now logged for better diagnostics ([#168](https://github.com/cachebag/nmrs/pull/168)) ## [1.2.0] - 2026-01-05 ### Added