From 5afc91ef2f857f392631e79c4e3bef29b3256acc Mon Sep 17 00:00:00 2001 From: Aleksander <170264518+t-aleksander@users.noreply.github.com> Date: Wed, 16 Oct 2024 12:52:33 +0200 Subject: [PATCH] Log improvements (#340) * some log improvements, also updates the documentation url * cleanup * cleanup 2 * sqlx prepare --- .github/pull_request_template.md | 6 +- README.md | 2 +- resources-linux/defguard-service.service | 2 +- ...bb5148296157f00ef39610c18fc290da384bf.json | 20 ++ ...e2cc7673709453d011e627930d6c184966d36.json | 20 ++ src-tauri/Cargo.lock | 5 +- src-tauri/Cargo.toml | 3 +- src-tauri/src/appstate.rs | 21 +- src-tauri/src/bin/defguard-client.rs | 94 ++++-- src-tauri/src/commands.rs | 299 ++++++++++-------- src-tauri/src/database/mod.rs | 56 ++-- src-tauri/src/database/models/instance.rs | 16 +- src-tauri/src/database/models/location.rs | 5 +- .../src/database/models/location_stats.rs | 15 +- src-tauri/src/database/models/settings.rs | 5 +- src-tauri/src/database/models/tunnel.rs | 13 +- src-tauri/src/enterprise/periodic/config.rs | 36 +-- src-tauri/src/error.rs | 6 +- .../src/log_watcher/global_log_watcher.rs | 42 +-- src-tauri/src/log_watcher/mod.rs | 7 + .../src/log_watcher/service_log_watcher.rs | 63 ++-- src-tauri/src/service/config.rs | 4 +- src-tauri/src/service/mod.rs | 54 ++-- src-tauri/src/service/utils.rs | 2 +- src-tauri/src/tray.rs | 25 +- src-tauri/src/utils.rs | 170 ++++++---- src/i18n/en/index.ts | 13 +- src/i18n/i18n-types.ts | 48 ++- src/pages/client/clientAPI/clientApi.ts | 4 +- src/pages/client/clientAPI/types.ts | 3 + .../components/GlobalLogs/GlobalLogs.tsx | 60 +++- .../GlobalLogs/GlobalLogsSelect.tsx | 10 +- .../GlobalLogs/GlobalLogsSourceSelect.tsx | 71 +++++ .../components/GlobalLogs/style.scss | 13 + 34 files changed, 829 insertions(+), 384 deletions(-) create mode 100644 src-tauri/.sqlx/query-2e752bd9e60b5ddd0c9eeeabb6cbb5148296157f00ef39610c18fc290da384bf.json create mode 100644 src-tauri/.sqlx/query-979d26af5b82c1a991402203707e2cc7673709453d011e627930d6c184966d36.json create mode 100644 src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSourceSelect.tsx diff --git a/.github/pull_request_template.md b/.github/pull_request_template.md index 63767beb..e7b25f34 100644 --- a/.github/pull_request_template.md +++ b/.github/pull_request_template.md @@ -7,17 +7,17 @@ #### Documentation ### -- [ ] If testing requires changes in the environment or deployment, please **update the documentation** (https://defguard.gitbook.io) first and **attach the link to the documentation** section in this pull request +- [ ] If testing requires changes in the environment or deployment, please **update the documentation** (https://docs.defguard.net) first and **attach the link to the documentation** section in this pull request - [ ] I have commented on my code, particularly in hard-to-understand areas -#### Testing ### +#### Testing ### - [ ] I have performed manual tests manually and all changes work - [ ] New and existing unit tests pass locally with my changes ### 🏚️ Main Branch Merge Checklist: -#### Testing ### +#### Testing ### - [ ] I have merged my changes before to dev and the dev checklist is done - [ ] I have tested all functionalities on the dev instance and they work diff --git a/README.md b/README.md index 733ab85f..55c77ec4 100644 --- a/README.md +++ b/README.md @@ -17,7 +17,7 @@ Desktop client for managing WireGuard VPN connections (any WireGuard server and - Multiple instances & locations - When combining with [defguard](https://github.com/DefGuard/defguard) VPN & SSO you can have multiple defguard instances (sites/installations) and multiple Locations (VPN tunnels in that location/site) in one client! If you are an admin/devops - all your customers (instances) and all their tunnels (locations) can be in one place! - Fast! - Built with Rust, [tauri](https://tauri.app/) and [React.js](https://react.dev/). -To learn more about the system see our [documentation](https://defguard.gitbook.io). +To learn more about the system see our [documentation](https://docs.defguard.net). ## Development diff --git a/resources-linux/defguard-service.service b/resources-linux/defguard-service.service index 6cc2cd3d..bce9f07b 100644 --- a/resources-linux/defguard-service.service +++ b/resources-linux/defguard-service.service @@ -1,6 +1,6 @@ [Unit] Description=Defguard interface daemon service -Documentation=https://defguard.gitbook.io/defguard/ +Documentation=https://docs.defguard.net Wants=network-online.target After=network-online.target diff --git a/src-tauri/.sqlx/query-2e752bd9e60b5ddd0c9eeeabb6cbb5148296157f00ef39610c18fc290da384bf.json b/src-tauri/.sqlx/query-2e752bd9e60b5ddd0c9eeeabb6cbb5148296157f00ef39610c18fc290da384bf.json new file mode 100644 index 00000000..acfde086 --- /dev/null +++ b/src-tauri/.sqlx/query-2e752bd9e60b5ddd0c9eeeabb6cbb5148296157f00ef39610c18fc290da384bf.json @@ -0,0 +1,20 @@ +{ + "db_name": "SQLite", + "query": "SELECT name FROM location WHERE id = $1", + "describe": { + "columns": [ + { + "name": "name", + "ordinal": 0, + "type_info": "Text" + } + ], + "parameters": { + "Right": 1 + }, + "nullable": [ + false + ] + }, + "hash": "2e752bd9e60b5ddd0c9eeeabb6cbb5148296157f00ef39610c18fc290da384bf" +} diff --git a/src-tauri/.sqlx/query-979d26af5b82c1a991402203707e2cc7673709453d011e627930d6c184966d36.json b/src-tauri/.sqlx/query-979d26af5b82c1a991402203707e2cc7673709453d011e627930d6c184966d36.json new file mode 100644 index 00000000..cd8dbd20 --- /dev/null +++ b/src-tauri/.sqlx/query-979d26af5b82c1a991402203707e2cc7673709453d011e627930d6c184966d36.json @@ -0,0 +1,20 @@ +{ + "db_name": "SQLite", + "query": "SELECT name FROM tunnel WHERE id = $1;", + "describe": { + "columns": [ + { + "name": "name", + "ordinal": 0, + "type_info": "Text" + } + ], + "parameters": { + "Right": 1 + }, + "nullable": [ + false + ] + }, + "hash": "979d26af5b82c1a991402203707e2cc7673709453d011e627930d6c184966d36" +} diff --git a/src-tauri/Cargo.lock b/src-tauri/Cargo.lock index a9847410..7c8424a3 100644 --- a/src-tauri/Cargo.lock +++ b/src-tauri/Cargo.lock @@ -1287,6 +1287,7 @@ dependencies = [ "tauri-plugin-single-instance", "tauri-plugin-window-state", "thiserror", + "time", "tokio", "tokio-util", "tonic", @@ -1302,8 +1303,8 @@ dependencies = [ [[package]] name = "defguard_wireguard_rs" -version = "0.5.2" -source = "git+https://github.com/DefGuard/wireguard-rs.git?rev=v0.5.2#a7840aa584b4af134e8327fdb03f0793b696554a" +version = "0.5.3" +source = "git+https://github.com/DefGuard/wireguard-rs.git?rev=v0.5.3#e3b1026ad561d151178e6cc39b5cd2d94acc97ca" dependencies = [ "base64 0.22.1", "libc", diff --git a/src-tauri/Cargo.toml b/src-tauri/Cargo.toml index 57c191d0..ebc7c647 100644 --- a/src-tauri/Cargo.toml +++ b/src-tauri/Cargo.toml @@ -22,7 +22,7 @@ base64 = "0.22" clap = { version = "4.5", features = ["derive", "env"] } chrono = { version = "0.4", features = ["serde"] } dark-light = "1.1" -defguard_wireguard_rs = { git = "https://github.com/DefGuard/wireguard-rs.git", rev = "v0.5.2" } +defguard_wireguard_rs = { git = "https://github.com/DefGuard/wireguard-rs.git", rev = "v0.5.3" } dirs = "5.0" lazy_static = "1.5" local-ip-address = "0.6" @@ -58,6 +58,7 @@ tauri-plugin-single-instance = { git = "https://github.com/tauri-apps/plugins-wo tauri-plugin-log = { git = "https://github.com/tauri-apps/plugins-workspace", branch = "v1" } tauri-plugin-window-state = { git = "https://github.com/tauri-apps/plugins-workspace", branch = "v1" } thiserror = "1.0" +time = { version = "0.3", features = ["formatting"] } tokio = { version = "1", features = ["macros", "rt-multi-thread", "signal"] } tokio-util = "0.7" tonic = "0.12" diff --git a/src-tauri/src/appstate.rs b/src-tauri/src/appstate.rs index b2c91ebf..ba164631 100644 --- a/src-tauri/src/appstate.rs +++ b/src-tauri/src/appstate.rs @@ -57,7 +57,7 @@ impl AppState { location_id: Id, connection_type: &ConnectionType, ) -> Option { - debug!("Removing active connection for location with id: {location_id}"); + trace!("Removing active connection for location with id: {location_id}"); let mut connections = self.active_connections.lock().await; if let Some(index) = connections.iter().position(|conn| { @@ -65,7 +65,7 @@ impl AppState { }) { // Found a connection with the specified location_id let removed_connection = connections.remove(index); - info!("Active connection has been removed from the active connections list."); + trace!("Active connection has been removed from the active connections list."); Some(removed_connection) } else { debug!("No active connection found with location_id: {location_id}"); @@ -91,9 +91,10 @@ impl AppState { } pub async fn close_all_connections(&self) -> Result<(), crate::error::Error> { - info!("Closing all active connections..."); + debug!("Closing all active connections..."); let active_connections = self.active_connections.lock().await; - info!("Found {} active connections", active_connections.len()); + let active_connections_count = active_connections.len(); + debug!("Found {} active connections", active_connections_count); for connection in active_connections.iter() { debug!( "Found active connection with location {}", @@ -103,7 +104,11 @@ impl AppState { debug!("Removing interface {}", connection.interface_name); disconnect_interface(connection, self).await?; } - info!("All active connections closed"); + if active_connections_count > 0 { + info!("All active connections ({active_connections_count}) have been closed."); + } else { + debug!("There were no active connections to close, nothing to do."); + } Ok(()) } @@ -113,8 +118,8 @@ impl AppState { connection_type: ConnectionType, ) -> Option { let connections = self.active_connections.lock().await; - debug!( - "Checking for active connection with id: {id}, connection_type: {connection_type:?} in active connections: {connections:?}" + trace!( + "Checking for active connection with id: {id}, connection_type: {connection_type:?} in active connections." ); if let Some(connection) = connections @@ -122,7 +127,7 @@ impl AppState { .find(|conn| conn.location_id == id && conn.connection_type == connection_type) { // 'connection' now contains the first element with the specified id and connection_type - debug!("Found connection: {connection:?}"); + trace!("Found connection: {connection:?}"); Some(connection.to_owned()) } else { debug!("Couldn't find connection with id: {id}, connection_type: {connection_type:?} in active connections."); diff --git a/src-tauri/src/bin/defguard-client.rs b/src-tauri/src/bin/defguard-client.rs index 0b615ef8..6e3bd012 100644 --- a/src-tauri/src/bin/defguard-client.rs +++ b/src-tauri/src/bin/defguard-client.rs @@ -27,6 +27,7 @@ use defguard_client::{ enterprise::periodic::config::poll_config, events::SINGLE_INSTANCE, periodic::version::poll_version, + service, tray::{configure_tray_icon, handle_tray_event, reload_tray_menu}, utils::load_log_targets, VERSION, @@ -37,6 +38,7 @@ use log::{Level, LevelFilter}; use tauri::{api::process, Env}; use tauri::{Builder, Manager, RunEvent, State, SystemTray, WindowEvent}; use tauri_plugin_log::LogTarget; +use time; #[derive(Clone, serde::Serialize)] struct Payload { @@ -49,6 +51,7 @@ extern crate log; // for tauri log plugin const LOG_TARGETS: [LogTarget; 2] = [LogTarget::Stdout, LogTarget::LogDir]; +const LOG_FILTER: [&str; 5] = ["tauri", "sqlx", "hyper", "h2", "tower"]; lazy_static! { static ref LOG_INCLUDES: Vec = load_log_targets(); @@ -76,9 +79,16 @@ async fn main() { } let log_level = - LevelFilter::from_str(&env::var("DEFGUARD_CLIENT_LOG_LEVEL").unwrap_or("info".into())) + LevelFilter::from_str(&env::var("DEFGUARD_CLIENT_LOG_LEVEL").unwrap_or("debug".into())) .unwrap_or(LevelFilter::Info); + // Sets the time format. Service's logs have a subsecond part, so we also need to include it here, + // otherwise the logs couldn't be sorted correctly when displayed together in the UI. + let format = time::format_description::parse( + "[[[year]-[month]-[day]][[[hour]:[minute]:[second].[subsecond]]", + ) + .unwrap(); + let app = Builder::default() .invoke_handler(tauri::generate_handler![ all_locations, @@ -126,6 +136,18 @@ async fn main() { })) .plugin( tauri_plugin_log::Builder::default() + .format(move |out, message, record| { + out.finish(format_args!( + "{}[{}][{}] {}", + tauri_plugin_log::TimezoneStrategy::UseUtc + .get_now() + .format(&format) + .unwrap(), + record.level(), + record.target(), + message + )) + }) .targets(LOG_TARGETS) .level(log_level) .filter(|metadata| { @@ -142,6 +164,22 @@ async fn main() { } true }) + .filter(|metadata| { + // Log all errors, warnings and infos + if metadata.level() == LevelFilter::Error + || metadata.level() == LevelFilter::Warn + || metadata.level() == LevelFilter::Info + { + return true; + } + // Otherwise do not log the following targets + for target in LOG_FILTER.iter() { + if metadata.target().contains(target) { + return false; + } + } + true + }) .build(), ) .plugin(tauri_plugin_window_state::Builder::default().build()) @@ -149,28 +187,38 @@ async fn main() { .build(tauri::generate_context!()) .expect("error while building tauri application"); - info!("Starting version v{}...", VERSION); + info!("Starting Defguard client version {}", VERSION); // initialize database let app_handle = app.handle(); - debug!("Initializing database connection..."); - let app_state: State = app_handle.state(); - let db = database::init_db(&app_handle) - .await - .expect("Database initialization failed"); - *app_state.db.lock().unwrap() = Some(db); - info!("Database initialization completed"); - debug!("Getting database info to check if the connection is working..."); - let result = database::info(&app_state.get_pool()).await; - if let Err(e) = result { - error!( - "There was an error while getting the database info: {:?}. The database connection might not be working.", - e - ); - } + info!( - "Database info has been fetched successfully. The connection with the database is working." + "The application data (database file) will be stored in: {:?} \ + and the application logs in: {:?}. Logs of the background defguard service responsible for \ + managing the VPN connections at the network level will be stored in: {:?}.", + // display the path to the app data direcory, convert option to option<&str> + app_handle + .path_resolver() + .app_data_dir() + .unwrap_or("UNDEFINED DATA DIRECTORY".into()), + app_handle + .path_resolver() + .app_log_dir() + .unwrap_or("UNDEFINED LOG DIRECTORY".into()), + service::config::DEFAULT_LOG_DIR ); + debug!("Performing database setup..."); + let app_state: State = app_handle.state(); + let db = match database::init_db(&app_handle).await { + Ok(db) => db, + Err(e) => { + error!("Failed to initialize database: {}", e); + return; + } + }; + *app_state.db.lock().unwrap() = Some(db); + debug!("Database setup has been completed successfully."); + // configure tray debug!("Configuring tray icon..."); if let Ok(settings) = Settings::get(&app_state.get_pool()).await { @@ -179,15 +227,15 @@ async fn main() { debug!("Tray icon has been configured successfully"); // run periodic tasks - debug!("Starting periodic tasks..."); + debug!("Starting periodic tasks (config and version polling)..."); tauri::async_runtime::spawn(poll_version(app_handle.clone())); tauri::async_runtime::spawn(poll_config(app_handle.clone())); debug!("Periodic tasks have been started"); // load tray menu after database initialization to show all instance and locations - debug!("Reloading tray menu to show all instances and locations..."); + debug!("Re-generating tray menu to show all available instances and locations as we have connected to the database..."); reload_tray_menu(&app_handle).await; - debug!("Tray menu has been reloaded successfully"); + debug!("Tray menu has been re-generated successfully"); // Handle Ctrl-C debug!("Setting up Ctrl-C handler..."); @@ -202,7 +250,7 @@ async fn main() { debug!("Ctrl-C handler has been set up successfully"); // run app - info!("Running the application..."); + debug!("Starting the main application event loop..."); app.run(|app_handle, event| match event { // prevent shutdown on window close RunEvent::ExitRequested { api, .. } => { @@ -211,7 +259,7 @@ async fn main() { } // handle shutdown RunEvent::Exit => { - info!("Exiting event loop..."); + debug!("Exiting the application's main event loop..."); let app_state: State = app_handle.state(); app_state.quit(app_handle); } diff --git a/src-tauri/src/commands.rs b/src-tauri/src/commands.rs index 7e535f4b..e3a484b5 100644 --- a/src-tauri/src/commands.rs +++ b/src-tauri/src/commands.rs @@ -1,3 +1,4 @@ +use core::fmt; use std::{ collections::{HashMap, HashSet}, env, @@ -62,7 +63,7 @@ pub async fn connect( ); handle_connection_for_location(&location, preshared_key, handle.clone()).await?; reload_tray_menu(&handle).await; - info!("Connected to location {} successfully", location.name); + info!("Connected to location {location}"); } else { error!("Location with ID {location_id} not found in the database, aborting connection attempt"); return Err(Error::NotFound); @@ -73,7 +74,7 @@ pub async fn connect( tunnel.name ); handle_connection_for_tunnel(&tunnel, handle).await?; - info!("Connected to tunnel {} successfully", tunnel.name); + info!("Successfully connected to tunnel {tunnel}"); } else { error!("Tunnel {location_id} not found"); return Err(Error::NotFound); @@ -101,22 +102,13 @@ pub async fn disconnect( connection_type: ConnectionType, handle: AppHandle, ) -> Result<(), Error> { - debug!("Received a command to disconnect from a {connection_type} with ID {location_id}"); let state = handle.state::(); + let name = get_tunnel_or_location_name(location_id, connection_type, &state).await; + debug!("Received a command to disconnect from the {connection_type} {name}({location_id})"); - let name = match get_tunnel_or_location_name(location_id, connection_type, &state).await { - Some(name) => { - debug!("Identified {connection_type} with ID {location_id} as \"{name}\", handling disconnection..."); - name - } - None => { - debug!("Could not identify {connection_type} with ID {location_id}, this {connection_type} will be referred to as UNKNOWN, trying to disconnect anyway..."); - "UNKNOWN".to_string() - } - }; - + debug!("Removing active connection for {connection_type} {name}({location_id}) from the application's state, if it exists..."); if let Some(connection) = state.remove_connection(location_id, &connection_type).await { - debug!("Found active connection for {connection_type} {name}({location_id})"); + debug!("Found and removed active connection from the application's state for {connection_type} {name}({location_id})"); trace!("Connection: {connection:?}"); disconnect_interface(&connection, &state).await?; debug!("Emitting the event informing the frontend about the disconnection from {connection_type} {name}({location_id})"); @@ -130,15 +122,30 @@ pub async fn disconnect( stop_log_watcher_task(&handle, &connection.interface_name)?; reload_tray_menu(&handle).await; if connection_type == ConnectionType::Location { + let name = get_tunnel_or_location_name(location_id, connection_type, &state).await; if let Err(err) = maybe_update_instance_config(location_id, &handle).await { - warn!("Failed to update instance for location {location_id}: {err}"); + match err { + Error::CoreNotEnterprise => { + debug!( + "Tried to fetch instance config from core after disconnecting from {name}(ID: {location_id}), but the core is not enterprise, so we can't fetch the config." + ); + } + Error::NoToken => { + debug!( + "Tried to fetch instance config from core after disconnecting from {name}(ID: {location_id}), but this location's instance has no polling token, so we can't fetch the config." + ); + } + _ => { + warn!("Error while trying to fetch instance config after disconnecting from {name}(ID: {location_id}): {err}"); + } + } }; } - info!("Finished disconnecting from {connection_type} {name}({location_id})"); + info!("Disconnected from {connection_type} {name}(ID: {location_id})"); Ok(()) } else { - error!("Error while disconnecting from {connection_type} {name}({location_id}): connection not found"); + warn!("Couldn't disconnect from {connection_type} {name}(ID: {location_id}), as no active connection was found."); Err(Error::NotFound) } } @@ -222,7 +229,7 @@ pub async fn save_device_config( .expect("Missing instance info in device config response"); let mut instance: Instance = instance_info.into(); if response.token.is_some() { - info!("Received polling token for instance {}", instance.name); + debug!("The newly saved device config has a polling token, automatic configuration polling will be possible if the core has an enterprise license.") } else { warn!( "Missing polling token for instance {}, core and/or proxy services may need an update, configuration polling won't work", @@ -233,7 +240,7 @@ pub async fn save_device_config( debug!("Saving instance {}", instance.name); let instance = instance.save(&mut *transaction).await?; - info!("Saved instance {}", instance.name); + debug!("Saved instance {}", instance.name); let device = response .device @@ -244,7 +251,7 @@ pub async fn save_device_config( keys.pubkey, instance.name, instance.id ); let keys = keys.save(&mut *transaction).await?; - info!( + debug!( "Saved wireguard key {} for instance {}({})", keys.pubkey, instance.name, instance.id ); @@ -255,21 +262,17 @@ pub async fn save_device_config( new_location.name, instance.name, instance.id ); let new_location = new_location.save(&mut *transaction).await?; - info!( + debug!( "Saved location {} for instance {}({})", new_location.name, instance.name, instance.id ); } transaction.commit().await?; - info!("Instance {}({:?}) created.", instance.name, instance.id); + info!("New instance {} created.", instance); trace!("Created following instance: {instance:#?}"); let locations = Location::find_by_instance_id(&app_state.get_pool(), instance.id).await?; trace!("Created following locations: {locations:#?}"); handle.emit_all(INSTANCE_UPDATE, ())?; - info!( - "Device configuration saved for instance {}({})", - instance.name, instance.id, - ); let res: SaveDeviceConfigResponse = SaveDeviceConfigResponse { locations, instance, @@ -280,10 +283,12 @@ pub async fn save_device_config( #[tauri::command(async)] pub async fn all_instances(app_state: State<'_, AppState>) -> Result>, Error> { - debug!("Retrieving all instances."); - + debug!("Getting information about all instances."); let instances = Instance::all(&app_state.get_pool()).await?; - debug!("Found ({}) instances", instances.len()); + trace!( + "Found {} instances to return information about.", + instances.len() + ); trace!("Instances found: {instances:#?}"); let mut instance_info = Vec::new(); let connection_ids = app_state @@ -310,8 +315,11 @@ pub async fn all_instances(app_state: State<'_, AppState>) -> Result) -> fmt::Result { + write!(f, "{}", self.name) + } +} + #[tauri::command(async)] pub async fn all_locations( instance_id: Id, app_state: State<'_, AppState>, ) -> Result, Error> { - debug!("Retrieving all locations."); + let instance = match Instance::find_by_id(&app_state.get_pool(), instance_id).await? { + Some(instance) => instance, + None => { + error!("Tried to get all locations for the instance with ID {instance_id}, but the instance was not found."); + return Err(Error::NotFound); + } + }; + trace!( + "Getting information about all locations for instance {}.", + instance.name + ); let locations = Location::find_by_instance_id(&app_state.get_pool(), instance_id).await?; + trace!( + "Found {} locations for instance {instance} to return information about.", + locations.len() + ); let active_locations_ids: Vec = app_state .get_connection_id_by_type(&ConnectionType::Location) .await; @@ -357,10 +385,9 @@ pub async fn all_locations( }; location_info.push(info); } - debug!("Locations retrieved({})", location_info.len()); - debug!( - "Returning {} locations for instance {instance_id}", - location_info.len(), + trace!( + "Returning information about {} locations for instance {instance}", + location_info.len() ); trace!("Locations returned:\n{location_info:#?}"); @@ -404,11 +431,12 @@ pub async fn update_instance( app_state: State<'_, AppState>, app_handle: AppHandle, ) -> Result<(), Error> { - debug!("Received update_instance command"); + debug!("Received command to update instance with id {instance_id}"); trace!("Processing following response:\n {response:#?}"); let pool = app_state.get_pool(); if let Some(mut instance) = Instance::find_by_id(&pool, instance_id).await? { + debug!("The instance with id {instance_id} to update was found: {instance}"); let mut transaction = pool.begin().await?; do_update_instance(&mut transaction, &mut instance, response).await?; transaction.commit().await?; @@ -417,7 +445,7 @@ pub async fn update_instance( reload_tray_menu(&app_handle).await; Ok(()) } else { - error!("Instance with id {instance_id} not found"); + error!("Instance to update with id {instance_id} was not found, aborting update"); Err(Error::NotFound) } } @@ -462,7 +490,7 @@ pub async fn do_update_instance( response: DeviceConfigResponse, ) -> Result<(), Error> { // update instance - debug!("Updating instance {}({}).", instance.name, instance.id); + debug!("Updating instance {}", instance); let locations_changed = locations_changed(transaction, instance, &response).await?; let instance_info = response .instance @@ -476,13 +504,13 @@ pub async fn do_update_instance( && instance_info.disable_all_traffic { debug!( - "Disabling all traffic for all locations of instance {}({}).", - instance.name, instance.id + "Disabling all traffic for all locations of instance {}.", + instance ); Location::disable_all_traffic_for_all(transaction.as_mut(), instance.id).await?; debug!( - "Disabled all traffic for all locations of instance {}({}).", - instance.name, instance.id + "Disabled all traffic for all locations of instance {}.", + instance ); } instance.disable_all_traffic = instance_info.disable_all_traffic; @@ -491,7 +519,7 @@ pub async fn do_update_instance( // This happens during polling, as core doesn't issue a new token for polling request if response.token.is_some() { instance.token = response.token; - info!("Set polling token for instance {}", instance.name); + debug!("Set polling token for instance {}", instance.name); } else { debug!( "No polling token received for instance {}, not updating", @@ -500,8 +528,8 @@ pub async fn do_update_instance( } instance.save(transaction.as_mut()).await?; debug!( - "Instance {}({}) main config applied from core's response.", - instance.name, instance.id + "A new base configuration has been applied to instance {}, even if nothing changed", + instance ); // check if locations have changed @@ -540,50 +568,40 @@ pub async fn do_update_instance( current_location.dns = new_location.dns; current_location.save(transaction.as_mut()).await?; info!( - "Location {}({}) updated for instance {}({}).", - current_location.name, current_location.id, instance.name, instance.id, + "Location {} configuration updated for instance {}", + current_location, instance, ); } else { // create new location debug!( - "Creating new location for instance {}({}).", - instance.name, instance.id + "Creating new location {new_location} for instance {}", + instance ); let new_location = new_location.save(transaction.as_mut()).await?; info!( - "New location {}({}) created for instance {}({})", - new_location.name, new_location.id, instance.name, instance.id + "New location {} created for instance {}", + new_location, instance ); } } - info!( - "Locations updated for instance {}({}).", - instance.name, instance.id - ); // remove locations which were present in current locations // but no longer found in core response - debug!( - "Removing locations for instance {}({}).", - instance.name, instance.id - ); + debug!("Removing locations for instance {}.", instance); for removed_location in current_locations { removed_location.delete(transaction.as_mut()).await?; + info!( + "Removed location {} for instance {} during instance update", + removed_location, instance + ); } - info!( - "Locations removed for instance {}({}).", - instance.name, instance.id - ); + debug!("Finished updating locations for instance {}", instance); } else { info!( - "Locations for instance {}({}) didn't change. Not updating them.", - instance.name, instance.id + "Locations for instance {} didn't change. Not updating them.", + instance ); } - info!( - "Instance {}({}) update is done.", - instance.name, instance.id - ); Ok(()) } @@ -705,14 +723,23 @@ pub async fn active_connection( handle: AppHandle, ) -> Result, Error> { let state = handle.state::(); - debug!("Retrieving active connection for location with id: {location_id}"); - debug!("Location found"); + let name = get_tunnel_or_location_name(location_id, connection_type, &state).await; + debug!( + "Checking if there is an active connection for location {}(ID: {})", + name, location_id + ); let connection = state.find_connection(location_id, connection_type).await; if connection.is_some() { - debug!("Active connection found"); + debug!( + "Found active connection for location {}(ID: {})", + name, location_id + ) } trace!("Connection retrieved:\n{connection:#?}"); - debug!("Active connection information for location has been retrieved"); + debug!( + "Active connection information for location {}(ID: {}) has been found, returning connection information", + name, location_id + ); Ok(connection) } @@ -722,23 +749,34 @@ pub async fn last_connection( connection_type: ConnectionType, app_state: State<'_, AppState>, ) -> Result>, Error> { - debug!("Retrieving last connection for location {location_id} with type {connection_type:?}"); + let name = get_tunnel_or_location_name(location_id, connection_type, &app_state).await; + + debug!( + "Retrieving last connection information for {connection_type} {name}(ID: {location_id})" + ); if connection_type == ConnectionType::Location { if let Some(connection) = Connection::latest_by_location_id(&app_state.get_pool(), location_id).await? { - info!("Found last connection at {}", connection.end); + debug!( + "Last connection to {connection_type} {name} has been made at {}", + connection.end + ); Ok(Some(connection.into())) } else { + debug!("No previous connections to {connection_type} {name} have been found."); Ok(None) } } else if let Some(connection) = TunnelConnection::latest_by_tunnel_id(&app_state.get_pool(), location_id).await? { - info!("Found last connection at {}", connection.end); + debug!( + "Last connection to {connection_type} {name} has been made at {}", + connection.end + ); Ok(Some(connection.into())) } else { - info!("No last connection found"); + debug!("No previous connections to {connection_type} {name} have been found."); Ok(None) } } @@ -752,6 +790,7 @@ pub async fn update_location_routing( ) -> Result<(), Error> { let app_state = handle.state::(); debug!("Updating location routing {location_id} with {connection_type:?}"); + let name = get_tunnel_or_location_name(location_id, connection_type, &app_state).await; match connection_type { ConnectionType::Location => { @@ -773,7 +812,7 @@ pub async fn update_location_routing( location.route_all_traffic = route_all_traffic; location.save(&app_state.get_pool()).await?; - info!("Location routing updated for location {location_id}"); + debug!("Location routing updated for location {name}(ID: {location_id})"); handle.emit_all( LOCATION_UPDATE, Payload { @@ -811,15 +850,14 @@ pub async fn update_location_routing( #[tauri::command(async)] pub async fn get_settings(handle: AppHandle) -> Result { - debug!("Retrieving settings"); let app_state = handle.state::(); let settings = Settings::get(&app_state.get_pool()).await?; - debug!("Settings retrieved"); Ok(settings) } #[tauri::command(async)] pub async fn update_settings(data: SettingsPatch, handle: AppHandle) -> Result { + debug!("Updating settings"); let app_state = handle.state::(); let pool = &app_state.get_pool(); trace!("Pool received"); @@ -828,7 +866,7 @@ pub async fn update_settings(data: SettingsPatch, handle: AppHandle) -> Result {} Err(e) => { @@ -838,52 +876,52 @@ pub async fn update_settings(data: SettingsPatch, handle: AppHandle) -> Result Result<(), Error> { - debug!("Deleting instance {instance_id}"); + debug!("Deleting instance with ID {instance_id}"); let app_state = handle.state::(); let mut client = app_state.client.clone(); let pool = &app_state.get_pool(); let Some(instance) = Instance::find_by_id(pool, instance_id).await? else { - error!("Instance {instance_id} not found"); + error!("Couldn't delete instance: instance with ID {instance_id} could not be found."); return Err(Error::NotFound); }; + debug!("The instance that is being deleted has been identified as {instance}"); let instance_locations = Location::find_by_instance_id(pool, instance_id).await?; + if !instance_locations.is_empty() { + debug!( + "Found locations associated with the instance {instance}, closing their connections..." + ) + } for location in instance_locations { if let Some(connection) = app_state .remove_connection(location.id, &ConnectionType::Location) .await { - debug!( - "Found active connection for location {} ({}), closing...", - location.name, location.id - ); + debug!("Found active connection for location {location}, closing..."); let request = RemoveInterfaceRequest { interface_name: connection.interface_name.clone(), - endpoint: location.endpoint, + endpoint: location.endpoint.clone(), }; client.remove_interface(request).await.map_err(|status| { - let msg = - format!("Error occured while removing interface {} for location {} ({}), status: {status}", - connection.interface_name, location.name, location.id - ); - error!("{msg}"); - Error::InternalError(msg) + error!("Error occured while removing interface {} for location {location}, status: {status}", connection.interface_name); + Error::InternalError(format!( + "There was an error while removing interface for location {location}, error message: {}. Check logs for more details.", status.message() + )) })?; - info!("Connection closed and interface removed"); + info!("The connection to location {location} has been closed, as it was associated with the instance {instance} that is being deleted."); } } instance.delete(pool).await?; reload_tray_menu(&handle).await; handle.emit_all(INSTANCE_UPDATE, ())?; - info!("Instance {instance_id}, deleted"); + info!("Successfully deleted instance {instance}."); Ok(()) } @@ -901,9 +939,9 @@ pub fn parse_tunnel_config(config: &str) -> Result { #[tauri::command(async)] pub async fn update_tunnel(mut tunnel: Tunnel, handle: AppHandle) -> Result<(), Error> { let app_state = handle.state::(); - debug!("Received tunnel configuration: {tunnel:#?}"); + debug!("Received tunnel configuration to update: {tunnel:?}"); tunnel.save(&app_state.get_pool()).await?; - info!("Saved tunnel {tunnel:#?}"); + info!("The tunnel {tunnel} configuration has been updated."); handle.emit_all( LOCATION_UPDATE, Payload { @@ -916,9 +954,9 @@ pub async fn update_tunnel(mut tunnel: Tunnel, handle: AppHandle) -> Result< #[tauri::command(async)] pub async fn save_tunnel(tunnel: Tunnel, handle: AppHandle) -> Result<(), Error> { let app_state = handle.state::(); - debug!("Received tunnel configuration: {tunnel:#?}"); + debug!("Received tunnel configuration to save: {tunnel:?}"); let tunnel = tunnel.save(&app_state.get_pool()).await?; - info!("Saved tunnel {tunnel:#?}"); + info!("The tunnel {tunnel} configuration has been saved."); handle.emit_all( LOCATION_UPDATE, Payload { @@ -941,10 +979,10 @@ pub struct TunnelInfo { #[tauri::command(async)] pub async fn all_tunnels(app_state: State<'_, AppState>) -> Result>, Error> { - debug!("Retrieving all tunnels."); + trace!("Getting information about all tunnels"); let tunnels = Tunnel::all(&app_state.get_pool()).await?; - debug!("Found ({}) tunnels", tunnels.len()); + trace!("Found ({}) tunnels to get information about", tunnels.len()); trace!("Tunnels found: {tunnels:#?}"); let mut tunnel_info = Vec::new(); let active_tunnel_ids = app_state @@ -963,7 +1001,10 @@ pub async fn all_tunnels(app_state: State<'_, AppState>) -> Result, ) -> Result, Error> { - debug!("Retrieving Tunnel with ID {tunnel_id}."); + debug!("Retrieving details about tunnel with ID {tunnel_id}."); if let Some(tunnel) = Tunnel::find_by_id(&app_state.get_pool(), tunnel_id).await? { - info!("Found tunnel {tunnel_id}"); + debug!("The tunnel {tunnel} has been found, returning its details."); Ok(tunnel) } else { - error!("Tunnel with ID: {tunnel_id}, not found"); + error!("Tunnel with ID {tunnel_id} not found, cannot retrieve its details."); Err(Error::NotFound) } } #[tauri::command(async)] pub async fn delete_tunnel(tunnel_id: Id, handle: AppHandle) -> Result<(), Error> { - debug!("Deleting tunnel {tunnel_id}"); + debug!("Deleting tunnel with ID {tunnel_id}"); let app_state = handle.state::(); let mut client = app_state.client.clone(); let pool = &app_state.get_pool(); let Some(tunnel) = Tunnel::find_by_id(pool, tunnel_id).await? else { - error!("Tunnel {tunnel_id} not found"); + error!("The tunnel to delete with ID {tunnel_id} could not be found, cannot delete."); return Err(Error::NotFound); }; + debug!("The tunnel to delete with ID {tunnel_id} has been identified as {tunnel}, proceeding with deletion."); if let Some(connection) = app_state .remove_connection(tunnel_id, &ConnectionType::Tunnel) .await { - debug!("Found active connection for tunnel({tunnel_id}), closing...",); + debug!("Found active connection for tunnel {tunnel} which is being deleted, closing the connection."); if let Some(pre_down) = &tunnel.pre_down { - debug!("Executing specified PreDown command: {pre_down}"); + debug!("Executing defined PreDown command before removing the interface {} for the tunnel {tunnel}: {pre_down}", connection.interface_name); let _ = execute_command(pre_down); - info!("Executed specified PreDown command: {pre_down}"); + info!("Executed defined PreDown command before removing the interface {} for the tunnel {tunnel}: {pre_down}", connection.interface_name); } let request = RemoveInterfaceRequest { interface_name: connection.interface_name.clone(), @@ -1012,23 +1054,24 @@ pub async fn delete_tunnel(tunnel_id: Id, handle: AppHandle) -> Result<(), Error .remove_interface(request) .await .map_err(|status| { - let msg = - format!("Error occured while removing interface {} for tunnel {tunnel_id}, status: {status}", - connection.interface_name - ); - error!("{msg}"); - Error::InternalError(msg) + error!("An error occured while removing interface {} for tunnel {tunnel}, status: {status}", + connection.interface_name); + Error::InternalError( + format!( + "An error occured while removing interface {} for tunnel {tunnel}, error message: {}. Check logs for more details.", connection.interface_name, status.message() + ) + ) })?; + info!("Network interface {} has been removed and the connection to tunnel {tunnel} has been closed.", connection.interface_name); if let Some(post_down) = &tunnel.post_down { - debug!("Executing specified PostDown command: {post_down}"); + debug!("Executing defined PostDown command after removing the interface {} for the tunnel {tunnel}: {post_down}", connection.interface_name); let _ = execute_command(post_down); - info!("Executed specified PostDown command: {post_down}"); + info!("Executed defined PostDown command after removing the interface {} for the tunnel {tunnel}: {post_down}", connection.interface_name); } - info!("Connection closed and interface removed"); } tunnel.delete(pool).await?; - info!("Tunnel {tunnel_id}, deleted"); + info!("Successfully deleted tunnel {tunnel}"); Ok(()) } @@ -1061,7 +1104,7 @@ pub async fn get_latest_app_version(handle: AppHandle) -> Result Result Result { let db_url = prepare_db_url(app_handle)?; debug!("Connecting to database: {}", db_url); let pool = DbPool::connect(&db_url).await?; - debug!("Running migrations."); + debug!("Running database migrations, if there are any."); sqlx::migrate!().run(&pool).await?; + debug!("Applied all database migrations that were pending. If any."); Settings::init_defaults(&pool).await?; - info!("Applied migrations."); Ok(pool) } @@ -35,51 +35,57 @@ pub async fn init_db(app_handle: &AppHandle) -> Result { /// Handles creating appropriate directories if they don't exist. fn prepare_db_url(app_handle: &AppHandle) -> Result { if let Ok(url) = env::var("DATABASE_URL") { - debug!("Using custom database url: {url}"); + info!("The default database location has been just overridden by the DATABASE_URL environment variable. The application will use the database located at: {url}"); Ok(url) } else { - debug!("Using production database"); + debug!("A production database will be used as no custom DATABASE_URL was provided."); // Check if database directory and file exists, create if they don't. let app_dir = app_handle .path_resolver() .app_data_dir() - .ok_or(Error::Config)?; - debug!("Creating app data dir at: {}", app_dir.to_string_lossy()); - fs::create_dir_all(&app_dir)?; - info!("Created app data dir at: {}", app_dir.to_string_lossy()); + .ok_or(Error::Config( + "Application data directory is not defined. Cannot proceed. Is the application running on a supported platform?".to_string() + ))?; + if app_dir.exists() { + debug!( + "Application data directory already exists at: {}, skipping its creation.", + app_dir.to_string_lossy() + ); + } else { + debug!( + "Creating application data directory at: {}", + app_dir.to_string_lossy() + ); + fs::create_dir_all(&app_dir)?; + debug!( + "Created application data directory at: {}", + app_dir.to_string_lossy() + ); + } let db_path = app_dir.join(DB_NAME); if db_path.exists() { - info!( - "Database exists, skipping database creation. Database path: {}", + debug!( + "Database file already exists at: {}. Skipping its creation.", db_path.to_string_lossy() ); } else { debug!( - "Database not found. Creating database file at: {}", + "Database file not found at {}. Creating a new one.", db_path.to_string_lossy() ); fs::File::create(&db_path)?; info!( - "Database file successfully created at: {}", + "A new, empty database file has been created at: {} as no previous database file was found. This file will be used to store application data.", db_path.to_string_lossy() ); } + debug!( + "Application's database file is located at: {}", + db_path.to_string_lossy() + ); Ok(format!( "sqlite://{}", db_path.to_str().expect("Failed to format DB path") )) } } - -pub async fn info(pool: &DbPool) -> Result<(), Error> { - let instances = Instance::all(pool).await?; - let locations = Location::all(pool).await?; - debug!( - "Found {} locations in {} instances", - locations.len(), - instances.len() - ); - trace!("Instances Found:\n {instances:#?}"); - trace!("Locations Found:\n {locations:#?}"); - Ok(()) -} diff --git a/src-tauri/src/database/models/instance.rs b/src-tauri/src/database/models/instance.rs index f1ba53ea..850e3b87 100644 --- a/src-tauri/src/database/models/instance.rs +++ b/src-tauri/src/database/models/instance.rs @@ -1,3 +1,5 @@ +use core::fmt; + use serde::{Deserialize, Serialize}; use sqlx::{query, query_as, SqliteExecutor}; @@ -17,6 +19,12 @@ pub struct Instance { pub enterprise_enabled: bool, } +impl fmt::Display for Instance { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "{}(ID: {})", self.name, self.id) + } +} + impl From for Instance { fn from(instance_info: proto::InstanceInfo) -> Self { Self { @@ -110,7 +118,7 @@ impl Instance { Ok(()) } - pub async fn delete<'e, E>(self, executor: E) -> Result<(), Error> + pub async fn delete<'e, E>(&self, executor: E) -> Result<(), Error> where E: SqliteExecutor<'e>, { @@ -230,3 +238,9 @@ pub struct InstanceInfo { pub disable_all_traffic: bool, pub enterprise_enabled: bool, } + +impl fmt::Display for InstanceInfo { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "{}(ID: {})", self.name, self.id) + } +} diff --git a/src-tauri/src/database/models/location.rs b/src-tauri/src/database/models/location.rs index 595d07e2..572fd522 100644 --- a/src-tauri/src/database/models/location.rs +++ b/src-tauri/src/database/models/location.rs @@ -25,7 +25,7 @@ pub struct Location { impl fmt::Display for Location { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - write!(f, "{}(ID: {})", self.id, self.name) + write!(f, "{}(ID: {})", self.name, self.id) } } @@ -122,11 +122,10 @@ impl Location { .await } - pub async fn delete<'e, E>(self, executor: E) -> Result<(), SqlxError> + pub async fn delete<'e, E>(&self, executor: E) -> Result<(), SqlxError> where E: SqliteExecutor<'e>, { - info!("Removing location {self:?}"); query!("DELETE FROM location WHERE id = $1;", self.id) .execute(executor) .await?; diff --git a/src-tauri/src/database/models/location_stats.rs b/src-tauri/src/database/models/location_stats.rs index 61621de5..462865af 100644 --- a/src-tauri/src/database/models/location_stats.rs +++ b/src-tauri/src/database/models/location_stats.rs @@ -3,7 +3,7 @@ use std::time::SystemTime; use chrono::{NaiveDateTime, Utc}; use defguard_wireguard_rs::host::Peer; use serde::{Deserialize, Serialize}; -use sqlx::{query_as, query_scalar, SqliteExecutor}; +use sqlx::{query_as, query_scalar, Error as SqlxError, SqliteExecutor}; use super::{Id, NoId}; use crate::{ @@ -63,6 +63,19 @@ where }) } +impl LocationStats { + pub async fn get_name<'e, E>(&self, executor: E) -> Result + where + E: SqliteExecutor<'e>, + { + Ok( + query_scalar!("SELECT name FROM location WHERE id = $1", self.location_id) + .fetch_one(executor) + .await?, + ) + } +} + impl LocationStats { #[must_use] pub fn new( diff --git a/src-tauri/src/database/models/settings.rs b/src-tauri/src/database/models/settings.rs index 829f9a5b..51a7fa60 100644 --- a/src-tauri/src/database/models/settings.rs +++ b/src-tauri/src/database/models/settings.rs @@ -131,7 +131,7 @@ impl Settings { .fetch_optional(pool) .await?; if current_config.is_none() { - debug!("No settings found on app init, inserting defaults."); + debug!("No previous application settings found, inserting defaults."); // check what system theme is currently in use and default to it. let theme = match dark_light::detect() { dark_light::Mode::Default | dark_light::Mode::Light => SettingsTheme::Light, @@ -154,6 +154,9 @@ impl Settings { ) .execute(pool) .await?; + } else { + debug!("Found previous app settings, using them."); + debug!("Found settings: {:?}", current_config); } Ok(()) } diff --git a/src-tauri/src/database/models/tunnel.rs b/src-tauri/src/database/models/tunnel.rs index 355bf84b..b4664a1f 100644 --- a/src-tauri/src/database/models/tunnel.rs +++ b/src-tauri/src/database/models/tunnel.rs @@ -84,7 +84,7 @@ impl Tunnel { Ok(()) } - pub async fn delete<'e, E>(self, executor: E) -> Result<(), Error> + pub async fn delete<'e, E>(&self, executor: E) -> Result<(), Error> where E: SqliteExecutor<'e>, { @@ -251,6 +251,17 @@ pub struct TunnelStats { persistent_keepalive_interval: Option, } +impl TunnelStats { + pub async fn get_name<'e, E>(&self, executor: E) -> Result + where + E: SqliteExecutor<'e>, + { + query_scalar!("SELECT name FROM tunnel WHERE id = $1;", self.tunnel_id) + .fetch_one(executor) + .await + } +} + impl TunnelStats { #[must_use] pub fn new( diff --git a/src-tauri/src/enterprise/periodic/config.rs b/src-tauri/src/enterprise/periodic/config.rs index 1789355f..b34ef364 100644 --- a/src-tauri/src/enterprise/periodic/config.rs +++ b/src-tauri/src/enterprise/periodic/config.rs @@ -50,22 +50,28 @@ pub async fn poll_config(handle: AppHandle) { match err { Error::CoreNotEnterprise => { debug!( - "Tried to contact core for instance {}({}) config but it's not enterprise, can't retrieve config", - instance.name, instance.id, + "Tried to contact core for instance {} config but it's not enterprise, can't retrieve config", + instance, + ); + } + Error::NoToken => { + debug!( + "Instance {} has no token, can't retrieve its config from the core", + instance, ); } _ => { error!( - "Failed to retrieve instance {}({}) config from core: {err}", - instance.name, instance.id, + "Failed to retrieve instance {} config from core: {err}", + instance ); } } } else { config_retrieved += 1; debug!( - "Retrieved config for instance {}({}) from core", - instance.name, instance.id, + "Finished processing configuration polling request for instance {}", + instance ); } } @@ -78,10 +84,11 @@ pub async fn poll_config(handle: AppHandle) { } if config_retrieved > 0 { info!( - "Retrieved configuration from core for {} instances, sleeping {}s", + "Automatically retrieved the newest instance configuration from core for {} instances, sleeping for {}s", config_retrieved, INTERVAL_SECONDS.as_secs(), ); + debug!("Instances for which configuration was retrieved from core: {instances:?}"); } else { debug!( "No configuration updates retrieved, sleeping {}s", @@ -165,10 +172,8 @@ pub async fn poll_instance( .device_config .as_ref() .ok_or_else(|| Error::InternalError("Device config not present in response".to_string()))?; - debug!( - "Parsed the following config for instance {}: {device_config:?}", - instance.name - ); + debug!("Parsed the config for instance {}", instance.name); + trace!("Parsed config: {device_config:?}"); // Early return if config didn't change if !config_changed(transaction, instance, device_config).await? { @@ -218,7 +223,7 @@ async fn config_changed( device_config: &DeviceConfigResponse, ) -> Result { debug!( - "Checking if config changed for instance {}({})", + "Checking if config and any of the locations changed for instance {}({})", instance.name, instance.id ); let locations_changed = locations_changed(transaction, instance, device_config).await?; @@ -235,12 +240,7 @@ async fn config_changed( /// Retrieves pubkey & token to build InstanceInfoRequest fn build_request(instance: &Instance) -> Result { - let token = &instance.token.as_ref().ok_or_else(|| { - Error::InternalError(format!( - "Instance {}({}) is missing token, can't build request for config polling", - instance.name, instance.id - )) - })?; + let token = &instance.token.as_ref().ok_or_else(|| Error::NoToken)?; Ok(InstanceInfoRequest { token: (*token).to_string(), diff --git a/src-tauri/src/error.rs b/src-tauri/src/error.rs index e6b984de..bdd2ac57 100644 --- a/src-tauri/src/error.rs +++ b/src-tauri/src/error.rs @@ -7,8 +7,8 @@ use thiserror::Error; pub enum Error { #[error(transparent)] Io(#[from] std::io::Error), - #[error("Config directory error")] - Config, + #[error("Application config directory error: {0}")] + Config(String), #[error("Database error: {0}")] Database(#[from] sqlx::Error), #[error("Migrate error: {0}")] @@ -41,6 +41,8 @@ pub enum Error { CommandError(String), #[error("Core is not enterprise")] CoreNotEnterprise, + #[error("Instance has no config polling token")] + NoToken, } // we must manually implement serde::Serialize diff --git a/src-tauri/src/log_watcher/global_log_watcher.rs b/src-tauri/src/log_watcher/global_log_watcher.rs index ede0140f..26ad2cc3 100644 --- a/src-tauri/src/log_watcher/global_log_watcher.rs +++ b/src-tauri/src/log_watcher/global_log_watcher.rs @@ -20,7 +20,7 @@ use tracing::Level; use crate::{ appstate::AppState, error::Error, - log_watcher::{extract_timestamp, LogLine, LogLineFields, LogWatcherError}, + log_watcher::{extract_timestamp, LogLine, LogLineFields, LogSource, LogWatcherError}, utils::get_service_log_dir, }; @@ -39,7 +39,7 @@ const DELAY: Duration = Duration::from_secs(2); impl LogDirs { #[must_use] pub fn new(handle: &AppHandle) -> Result { - debug!("Getting log directories."); + debug!("Getting log directories for service and client to watch."); let service_log_dir = get_service_log_dir().to_path_buf(); let client_log_dir = handle @@ -49,7 +49,7 @@ impl LogDirs { "Path to client logs directory is empty.".to_string(), ))?; debug!( - "Log directories of service and client are: {:?} and {:?}", + "Log directories of service and client have been identified by the global log watcher: {:?} and {:?}", service_log_dir, client_log_dir ); @@ -90,14 +90,14 @@ impl LogDirs { } fn get_current_service_file(&self) -> Result { - debug!( + trace!( "Opening service log file: {:?}", self.current_service_log_file ); match &self.current_service_log_file { Some(path) => { let file = File::open(path)?; - debug!( + trace!( "Successfully opened service log file at {:?}", self.current_service_log_file ); @@ -111,7 +111,7 @@ impl LogDirs { } fn get_client_file(&self) -> Result { - debug!( + trace!( "Opening the log file for the client, using directory: {:?}", self.client_log_dir ); @@ -123,9 +123,9 @@ impl LogDirs { self.client_log_dir )))?; let path = format!("{}/defguard-client.log", dir_str); - debug!("Constructed client log file path: {path}"); + trace!("Constructed client log file path: {path}"); let file = File::open(&path)?; - debug!("Client log file at {:?} opened successfully", path); + trace!("Client log file at {:?} opened successfully", path); Ok(file) } } @@ -170,28 +170,25 @@ impl GlobalLogWatcher { /// into a [`LogLine`] struct and emitting it to the frontend. It can be stopped by cancelling /// the token by calling [`stop_global_log_watcher_task()`] fn parse_log_dirs(&mut self) -> Result<(), LogWatcherError> { - debug!("Parsing log directories"); + trace!("Processing log directories for service and client."); self.log_dirs.current_service_log_file = self.log_dirs.get_latest_log_file()?; - debug!( + trace!( "Latest service log file found: {:?}", self.log_dirs.current_service_log_file ); - debug!("Opening log files"); let mut service_reader = if let Ok(file) = self.log_dirs.get_current_service_file() { - debug!("Service log file opened successfully"); Some(BufReader::new(file)) } else { None }; let mut client_reader = if let Ok(file) = self.log_dirs.get_client_file() { - debug!("Client log file opened successfully"); Some(BufReader::new(file)) } else { None }; - debug!("Checking if log files are available"); + trace!("Checking if log files are available"); if service_reader.is_none() && client_reader.is_none() { warn!( "Couldn't read files at {:?} and {:?}, there will be no logs reported in the client.", @@ -201,7 +198,7 @@ impl GlobalLogWatcher { sleep(DELAY); return Ok(()); } - debug!("Log files are available, starting to read lines."); + trace!("Log files are available, starting to read lines."); let mut service_line = String::new(); let mut client_line = String::new(); @@ -211,7 +208,7 @@ impl GlobalLogWatcher { let mut service_line_read; let mut client_line_read; - debug!("Starting the log reading loop"); + debug!("Global log watcher is starting the loop for reading client and service log files"); loop { if self.cancellation_token.is_cancelled() { debug!("Received cancellation request. Stopping global log watcher"); @@ -251,6 +248,8 @@ impl GlobalLogWatcher { break; } } + } else { + debug!("Service log reader is not present, not reading service log lines."); } // Client @@ -280,6 +279,8 @@ impl GlobalLogWatcher { break; } } + } else { + debug!("Client log file reader is not present, not reading client logs."); } trace!("Read 0 bytes from both log files, we've reached EOF in both cases."); @@ -303,7 +304,7 @@ impl GlobalLogWatcher { /// Also performs filtering by log level and optional timestamp. fn parse_service_log_line(&self, line: &str) -> Result, LogWatcherError> { trace!("Parsing service log line: {line}"); - let log_line = if let Ok(line) = serde_json::from_str::(line) { + let mut log_line = if let Ok(line) = serde_json::from_str::(line) { line } else { warn!("Failed to parse service log line: {line}"); @@ -332,6 +333,8 @@ impl GlobalLogWatcher { } } + log_line.source = Some(LogSource::Service); + trace!("Successfully parsed service log line."); Ok(Some(log_line)) @@ -358,7 +361,7 @@ impl GlobalLogWatcher { let timestamp = format!("{} {}", timestamp_date, timestamp_time); let timestamp = Utc.from_utc_datetime( - &NaiveDateTime::parse_from_str(×tamp, "%Y-%m-%d %H:%M:%S").map_err(|e| { + &NaiveDateTime::parse_from_str(×tamp, "%Y-%m-%d %H:%M:%S%.f").map_err(|e| { LogWatcherError::LogParseError(format!( "Failed to parse timestamp {} with error: {}", timestamp, e @@ -397,6 +400,7 @@ impl GlobalLogWatcher { target, fields, span: None, + source: Some(LogSource::Client), }; if log_line.level > self.log_level { @@ -482,7 +486,7 @@ pub fn stop_global_log_watcher_task(handle: &AppHandle) -> Result<(), Error> { Ok(()) } else { // Silently ignore if global log watcher is not found, as there is nothing to cancel - debug!("Global log watcher not found, cannot cancel"); + debug!("Global log watcher not found, nothing to cancel"); Ok(()) } } diff --git a/src-tauri/src/log_watcher/mod.rs b/src-tauri/src/log_watcher/mod.rs index 8f142a36..c7e34c67 100644 --- a/src-tauri/src/log_watcher/mod.rs +++ b/src-tauri/src/log_watcher/mod.rs @@ -23,6 +23,12 @@ pub enum LogWatcherError { LogParseError(String), } +#[derive(Debug, Deserialize, Serialize, Clone)] +pub enum LogSource { + Service, + Client, +} + /// Represents a single line in log file #[serde_as] #[derive(Clone, Debug, Deserialize, Serialize)] @@ -33,6 +39,7 @@ struct LogLine { target: String, fields: LogLineFields, span: Option, + source: Option, } #[derive(Clone, Debug, Deserialize, Serialize)] diff --git a/src-tauri/src/log_watcher/service_log_watcher.rs b/src-tauri/src/log_watcher/service_log_watcher.rs index 6774e327..fbc297ba 100644 --- a/src-tauri/src/log_watcher/service_log_watcher.rs +++ b/src-tauri/src/log_watcher/service_log_watcher.rs @@ -19,8 +19,12 @@ use tokio_util::sync::CancellationToken; use tracing::Level; use crate::{ - appstate::AppState, database::models::Id, error::Error, log_watcher::extract_timestamp, - utils::get_service_log_dir, ConnectionType, + appstate::AppState, + database::models::Id, + error::Error, + log_watcher::extract_timestamp, + utils::{get_service_log_dir, get_tunnel_or_location_name}, + ConnectionType, }; use super::{LogLine, LogWatcherError}; @@ -48,10 +52,8 @@ impl<'a> ServiceLogWatcher<'a> { interface_name: String, log_level: Level, from: Option>, + log_dir: &'a Path, ) -> Self { - // get log file directory - let log_dir = get_service_log_dir(); - info!("Log dir: {log_dir:?}"); Self { interface_name, log_level, @@ -126,8 +128,7 @@ impl<'a> ServiceLogWatcher<'a> { } if self.cancellation_token.is_cancelled() { info!( - "Received cancellation request. Stopping log watcher for interface {}", - self.interface_name + "The background task responsible for watching the defguard service log file for interface {} is being stopped.", self.interface_name ); break; } @@ -223,13 +224,13 @@ pub async fn spawn_log_watcher_task( // parse `from` timestamp let from = from.and_then(|from| DateTime::::from_str(&from).ok()); - let connection_type = if connection_type.eq(&ConnectionType::Tunnel) { + let connection_type_str = if connection_type.eq(&ConnectionType::Tunnel) { "Tunnel" } else { "Location" }; - let event_topic = format!("log-update-{connection_type}-{location_id}"); - debug!("Using the following event topic for the service log watcher: {event_topic}"); + let event_topic = format!("log-update-{connection_type_str}-{location_id}"); + debug!("Using the following event topic for the service log watcher for communicating with the frontend: {event_topic}"); // explicitly clone before topic is moved into the closure let topic_clone = event_topic.clone(); @@ -240,32 +241,40 @@ pub async fn spawn_log_watcher_task( let token = CancellationToken::new(); let token_clone = token.clone(); + let log_dir = get_service_log_dir(); // get log file directory + let mut log_watcher = ServiceLogWatcher::new( + handle_clone, + token_clone, + topic_clone, + interface_name_clone, + log_level, + from, + log_dir, + ); + // spawn task let _join_handle: TokioJoinHandle> = tokio::spawn(async move { - let mut log_watcher = ServiceLogWatcher::new( - handle_clone, - token_clone, - topic_clone, - interface_name_clone, - log_level, - from, - ); log_watcher.run()?; Ok(()) }); // store `CancellationToken` to manually stop watcher thread - let mut log_watchers = app_state - .log_watchers - .lock() - .expect("Failed to lock log watchers mutex"); - if let Some(old_token) = log_watchers.insert(interface_name.clone(), token) { - // cancel previous log watcher for this interface - debug!("Existing log watcher for interface {interface_name} found. Cancelling..."); - old_token.cancel(); + // keep this in a block as we .await later, which should not be done while holding a lock like this + { + let mut log_watchers = app_state + .log_watchers + .lock() + .expect("Failed to lock log watchers mutex"); + if let Some(old_token) = log_watchers.insert(interface_name.clone(), token) { + // cancel previous log watcher for this interface + debug!("Existing log watcher for interface {interface_name} found. Cancelling..."); + old_token.cancel(); + } } - info!("Service log watcher task for interface {interface_name} started"); + let name = get_tunnel_or_location_name(location_id, connection_type, &app_state).await; + info!("A background task has been spawned to watch the defguard service log file for {connection_type} {name} (interface {interface_name}), \ + location's specific collected logs will be displayed in the {connection_type}'s detailed view."); Ok(event_topic) } diff --git a/src-tauri/src/service/config.rs b/src-tauri/src/service/config.rs index d718465f..6277d19f 100644 --- a/src-tauri/src/service/config.rs +++ b/src-tauri/src/service/config.rs @@ -1,9 +1,9 @@ use clap::Parser; #[cfg(target_os = "windows")] -const DEFAULT_LOG_DIR: &str = "/Logs/defguard-service"; +pub const DEFAULT_LOG_DIR: &str = "/Logs/defguard-service"; #[cfg(not(target_os = "windows"))] -const DEFAULT_LOG_DIR: &str = "/var/log/defguard-service"; +pub const DEFAULT_LOG_DIR: &str = "/var/log/defguard-service"; #[derive(Debug, Parser, Clone)] #[clap(about = "Defguard VPN client interface management service")] diff --git a/src-tauri/src/service/mod.rs b/src-tauri/src/service/mod.rs index c1fb6b98..6123af26 100644 --- a/src-tauri/src/service/mod.rs +++ b/src-tauri/src/service/mod.rs @@ -12,6 +12,7 @@ use std::{ time::{Duration, UNIX_EPOCH}, }; +use super::VERSION; #[cfg(not(target_os = "macos"))] use defguard_wireguard_rs::Kernel; #[cfg(target_os = "macos")] @@ -137,9 +138,6 @@ impl DesktopDaemonService for DaemonService { } debug!("DNS configuration for interface {ifname}: DNS: {dns:?}, Search domains: {search_domains:?}"); - // configure interface - debug!("Configuring new interface {ifname} with the following configuration: {config:?}"); - #[cfg(not(windows))] let configure_interface_result = wgapi.configure_interface(&config); #[cfg(windows)] @@ -162,7 +160,7 @@ impl DesktopDaemonService for DaemonService { })?; if !dns.is_empty() { - debug!("Configuring DNS for interface {ifname} with config: {dns:?}"); + debug!("The following DNS servers will be set: {dns:?}, search domains: {search_domains:?}"); wgapi.configure_dns(&dns, &search_domains).map_err(|err| { let msg = format!("Failed to configure DNS for WireGuard interface {ifname}: {err}"); @@ -174,7 +172,7 @@ impl DesktopDaemonService for DaemonService { } } - info!("Finished creating a new interface {ifname}"); + debug!("Finished creating a new interface {ifname}"); Ok(Response::new(())) } @@ -211,7 +209,7 @@ impl DesktopDaemonService for DaemonService { Status::new(Code::Internal, msg) })?; - info!("Finished removing interface {ifname}"); + debug!("Finished removing interface {ifname}"); Ok(Response::new(())) } @@ -221,46 +219,59 @@ impl DesktopDaemonService for DaemonService { &self, request: tonic::Request, ) -> Result, Status> { - debug!("Received a request to read interface data"); let request = request.into_inner(); + debug!( + "Received a request to start a new network usage stats data stream for interface {}", + request.interface_name + ); let ifname = request.interface_name; let span = info_span!("read_interface_data", interface_name = &ifname); span.in_scope(|| { - info!("Starting interface data stream for {ifname}"); + debug!("Starting network usage stats stream for interface {ifname}"); }); let stats_period = self.stats_period; let (tx, rx) = mpsc::channel(64); tokio::spawn(async move { - info!("Spawning stats thread for interface {ifname}"); + debug!("Spawning network usage stats collection task for interface {ifname}"); // setup WireGuard API - let error_msg = format!("Failed to initialize WireGuard API for interface {ifname}"); + let error_msg = format!("Failed to initialize WireGuard API for interface {ifname} during the creation of the network usage stats collection task."); let wgapi = setup_wgapi(&ifname).expect(&error_msg); let period = Duration::from_secs(stats_period); let mut interval = interval(period); loop { // wait till next iteration - debug!("Waiting for next stats update for interface {ifname}"); + debug!("Waiting for next network usage stats update for interface {ifname}"); interval.tick().await; - debug!("Sending stats update for interface {ifname}"); + debug!("Gathering network usage stats to send to the client about network activity for interface {ifname}"); match wgapi.read_interface_data() { Ok(host) => { if let Err(err) = tx.send(Ok(host.into())).await { error!( - "Failed to send stats update for interface {ifname}. Error: {err}" + "Couldn't send network usage stats update for interface {ifname}. Error: {err}" ); break; } } Err(err) => { - error!("Failed to retrieve stats for WireGuard interface {ifname}. Error: {err}"); - break; + match err { + WireguardInterfaceError::SocketClosed(err) => { + warn!( + "Failed to retrieve network usage stats for WireGuard interface {ifname}. Error: {err}" + ); + break; + } + _ => { + error!("Failed to retrieve network usage stats for WireGuard interface {ifname}. Error: {err}"); + break; + } + } } } - debug!("Finished sending stats update for interface {ifname}"); + debug!("Network activity statistics for interface {ifname} have been sent to the client"); } - warn!("Client disconnected from stats update stream for interface {ifname}"); + debug!("The client has disconnected from the network usage statistics data stream for interface {ifname}, stopping the statistics data collection task."); }.instrument(span)); let output_stream = ReceiverStream::new(rx); @@ -271,13 +282,16 @@ impl DesktopDaemonService for DaemonService { } pub async fn run_server(config: Config) -> anyhow::Result<()> { - info!("Starting defguard interface management daemon"); + debug!("Starting defguard interface management daemon"); let addr = SocketAddr::new(IpAddr::V4(Ipv4Addr::LOCALHOST), DAEMON_HTTP_PORT); let daemon_service = DaemonService::new(&config); - info!("defguard daemon listening on {addr}"); - debug!("Daemon configuration: {config:?}"); + info!( + "Defguard daemon version {} started, listening on {addr}", + VERSION + ); + debug!("Defguard daemon configuration: {config:?}"); Server::builder() .trace_fn(|_| tracing::info_span!("defguard_service")) diff --git a/src-tauri/src/service/utils.rs b/src-tauri/src/service/utils.rs index 737dcc93..f934fe59 100644 --- a/src-tauri/src/service/utils.rs +++ b/src-tauri/src/service/utils.rs @@ -31,7 +31,7 @@ pub fn logging_setup(config: &Config) -> WorkerGuard { .unwrap_or_else(|_| format!("{},hyper=info,h2=info", config.log_level).into()); // prepare log level filter for json file - let json_filter = EnvFilter::new(format!("{},hyper=info", Level::DEBUG)); + let json_filter = EnvFilter::new(format!("{},hyper=info,h2=info", Level::DEBUG)); // prepare tracing layers let stdout_layer = fmt::layer() diff --git a/src-tauri/src/tray.rs b/src-tauri/src/tray.rs index 2ee7d8a7..8d972c79 100644 --- a/src-tauri/src/tray.rs +++ b/src-tauri/src/tray.rs @@ -26,16 +26,21 @@ pub async fn generate_tray_menu(app_state: State<'_, AppState>) -> Result) -> Result) -> Result()) .await .unwrap(); if let Err(err) = app_handle.tray_handle().set_menu(system_menu) { warn!("Unable to update tray menu {err:?}"); - } else { - debug!("Successfully reloaded tray menu"); } } @@ -139,11 +140,11 @@ pub fn handle_tray_event(app: &AppHandle, event: SystemTrayEvent) { pub fn configure_tray_icon(app: &AppHandle, theme: &TrayIconTheme) -> Result<(), Error> { let resource_str = format!("resources/icons/tray-32x32-{}.png", theme.as_ref()); - debug!("Tray icon loading from {resource_str}"); + debug!("Trying to load the tray icon from {resource_str}"); if let Some(icon_path) = app.path_resolver().resolve_resource(&resource_str) { let icon = Icon::File(icon_path); app.tray_handle().set_icon(icon)?; - debug!("Tray icon changed"); + debug!("Tray icon set to {resource_str} successfully."); Ok(()) } else { error!("Loading tray icon resource {resource_str} failed! Resource not resolved.",); diff --git a/src-tauri/src/utils.rs b/src-tauri/src/utils.rs index 45005230..fc4e203d 100644 --- a/src-tauri/src/utils.rs +++ b/src-tauri/src/utils.rs @@ -147,7 +147,7 @@ pub async fn setup_interface( } } } else { - info!("Interface creation request for location {location} has been sent to the defguard background service, created the {} interface.", interface_config.name); + info!("The interface for location {location} has been created successfully, interface name: {}.", interface_config.name); Ok(()) } } else { @@ -222,17 +222,20 @@ pub fn spawn_stats_thread( tokio::spawn(async move { let state = handle.state::(); let mut client = state.client.clone(); - let request = ReadInterfaceDataRequest { interface_name }; + let request = ReadInterfaceDataRequest { + interface_name: interface_name.clone(), + }; let mut stream = client .read_interface_data(request) .await - .expect("Failed to connect to interface stats stream") + .expect("Failed to connect to interface stats stream for interface {interface_name}") .into_inner(); loop { match stream.message().await { Ok(Some(interface_data)) => { - debug!("Received interface data update: {interface_data:?}"); + debug!("Received new network usage statistics for interface {interface_name}."); + trace!("Received interface data: {interface_data:?}"); let peers: Vec = interface_data.peers.into_iter().map(Into::into).collect(); for peer in peers { @@ -244,9 +247,25 @@ pub fn spawn_stats_thread( ) .await .unwrap(); - debug!("Saving location stats: {location_stats:#?}"); - let result = location_stats.save(&state.get_pool()).await; - debug!("Saved location stats: {result:#?}"); + let location_name = location_stats + .get_name(&state.get_pool()) + .await + .unwrap_or("UNKNOWN".to_string()); + + debug!("Saving network usage stats related to location {location_name} (interface {interface_name})."); + trace!("Stats: {location_stats:?}"); + match location_stats.save(&state.get_pool()).await { + Ok(_) => { + debug!( + "Saved network usage stats for location {location_name}" + ); + } + Err(err) => { + error!( + "Failed to save network usage stats for location {location_name}: {err}" + ); + } + } } else { let tunnel_stats = peer_to_tunnel_stats( &peer, @@ -255,14 +274,24 @@ pub fn spawn_stats_thread( ) .await .unwrap(); - debug!("Saving tunnel stats: {tunnel_stats:#?}"); - let result = tunnel_stats.save(&state.get_pool()).await; - debug!("Saved location stats: {result:#?}"); + let tunnel_name = tunnel_stats + .get_name(&state.get_pool()) + .await + .unwrap_or("UNKNOWN".to_string()); + debug!("Saving network usage stats related to tunnel {tunnel_name} (interface {interface_name}): {tunnel_stats:?}"); + match tunnel_stats.save(&state.get_pool()).await { + Ok(_) => { + debug!("Saved stats for tunnel {tunnel_name}"); + } + Err(err) => { + error!("Failed to save stats for tunnel {tunnel_name}: {err}"); + } + } } } } Ok(None) => { - info!( + debug!( "gRPC stream to the defguard-service managing connections has been closed" ); break; @@ -273,7 +302,7 @@ pub fn spawn_stats_thread( } } } - warn!("Interface data stream disconnected"); + debug!("Network usage stats thread for interface {interface_name} has been terminated"); }); } @@ -377,7 +406,7 @@ pub async fn setup_interface_tunnel( // request interface configuration debug!("Looking for a free port for interface {interface_name}..."); if let Some(port) = find_random_free_port() { - info!("Found free port: {port} for interface {interface_name}."); + debug!("Found free port: {port} for interface {interface_name}."); let interface_config = InterfaceConfiguration { name: interface_name, prvkey: tunnel.prvkey.clone(), @@ -393,27 +422,40 @@ pub async fn setup_interface_tunnel( dns: tunnel.dns.clone(), }; if let Some(pre_up) = &tunnel.pre_up { - debug!("Executing specified PreUp command: {pre_up}"); + debug!("Executing defined PreUp command before setting up the interface {} for the tunnel {tunnel}: {pre_up}", interface_config.name); let _ = execute_command(pre_up); - info!("Executed specified PreUp command: {pre_up}"); + info!( + "Executed defined PreUp command before setting up the interface {} for the tunnel {tunnel}: {pre_up}", interface_config.name + ); } if let Err(error) = client.create_interface(request).await { - let msg = format!("Failed to create interface: {error}"); - error!("{msg}"); - Err(Error::InternalError(msg)) + error!( + "Failed to create a network interface ({}) for tunnel {tunnel}: {error}", + interface_config.name + ); + Err(Error::InternalError(format!( + "Failed to create a network interface ({}) for tunnel {tunnel}, error message: {}. Check logs for more details.", + interface_config.name, error.message() + ))) } else { + info!( + "Network interface {} for tunnel {tunnel} created successfully.", + interface_config.name + ); if let Some(post_up) = &tunnel.post_up { - debug!("Executing specified PreUp command: {post_up}"); + debug!("Executing defined PostUp command after setting up the interface {} for the tunnel {tunnel}: {post_up}", interface_config.name); let _ = execute_command(post_up); - info!("Executed specified PreUp command: {post_up}"); + info!("Executed defined PostUp command after setting up the interface {} for the tunnel {tunnel}: {post_up}", interface_config.name); } - info!("Interface {} created successfully.", interface_config.name); - debug!("Created interface with config: {interface_config:?}"); + debug!( + "Created interface {} with config: {interface_config:?}", + interface_config.name + ); Ok(()) } } else { let msg = format!( - "Error finding free port during tunnel {tunnel} setup for interface {interface_name}" + "Couldn't find free port for interface {interface_name} while setting up tunnel {tunnel}" ); error!("{msg}"); Err(Error::InternalError(msg)) @@ -426,7 +468,8 @@ pub async fn get_tunnel_interface_details( ) -> Result { debug!("Fetching tunnel details for tunnel ID {tunnel_id}"); if let Some(tunnel) = Tunnel::find_by_id(pool, tunnel_id).await? { - let peer_pubkey = tunnel.pubkey; + debug!("The tunnel with ID {tunnel_id} has been found and identified as {tunnel}."); + let peer_pubkey = &tunnel.pubkey; // generate interface name #[cfg(target_os = "macos")] @@ -443,7 +486,7 @@ pub async fn get_tunnel_interface_details( ) .fetch_optional(pool) .await?; - info!("Fetched tunnel stats for tunnel ID {tunnel_id}"); + debug!("Fetched tunnel connection statistics for tunnel {tunnel}"); let (listen_port, persistent_keepalive_interval, last_handshake) = match result { Some(record) => ( @@ -454,7 +497,7 @@ pub async fn get_tunnel_interface_details( None => (None, None, None), }; - info!("Fetched tunnel details for tunnel ID {tunnel_id}"); + debug!("Fetched tunnel configuration details for tunnel {tunnel}."); Ok(LocationInterfaceDetails { location_id: tunnel_id, @@ -463,7 +506,7 @@ pub async fn get_tunnel_interface_details( address: tunnel.address, dns: tunnel.dns, listen_port, - peer_pubkey, + peer_pubkey: peer_pubkey.to_string(), peer_endpoint: tunnel.endpoint, allowed_ips: tunnel.allowed_ips.unwrap_or_default(), persistent_keepalive_interval, @@ -567,8 +610,7 @@ pub async fn handle_connection_for_location( ConnectionType::Location, ); state.active_connections.lock().await.push(connection); - debug!("Created a new interface for location {}", location.name); - debug!( + trace!( "Active connections: {:?}", state.active_connections.lock().await ); @@ -579,19 +621,25 @@ pub async fn handle_connection_for_location( message: "Created new connection".into(), }, )?; - debug!("Event sent for location {}", location.name); + debug!("Event informing the frontend that a new connection has been created sent."); // Spawn stats threads - debug!("Spawning stats thread for location {}...", location.name); + debug!( + "Spawning network usage stats thread for location {}...", + location + ); spawn_stats_thread( handle.clone(), interface_name.clone(), ConnectionType::Location, ); - debug!("Stats thread for location {} spawned.", location.name); + debug!( + "Network usage stats thread for location {} spawned.", + location + ); // spawn log watcher - debug!("Spawning log watcher for location {}...", location.name); + debug!("Spawning service log watcher for location {}...", location); spawn_log_watcher_task( handle, location.id, @@ -601,7 +649,7 @@ pub async fn handle_connection_for_location( None, ) .await?; - debug!("Log watcher for location {} spawned.", location.name); + debug!("Service log watcher for location {} spawned.", location); Ok(()) } @@ -625,7 +673,6 @@ pub async fn handle_connection_for_tunnel( ConnectionType::Tunnel, ); state.active_connections.lock().await.push(connection); - debug!("Created a new interface for tunnel {}", tunnel.name); debug!( "Active connections: {:?}", state.active_connections.lock().await @@ -637,7 +684,7 @@ pub async fn handle_connection_for_tunnel( message: "Created new connection".into(), }, )?; - debug!("Event sent for tunnel {}", tunnel.name); + debug!("Event informing the frontend that a new connection has been created sent."); // Spawn stats threads debug!("Spawning stats thread for tunnel {}", tunnel.name); @@ -675,7 +722,7 @@ pub fn execute_command(command: &str) -> Result<(), Error> { let stdout = String::from_utf8_lossy(&output.stdout); let stderr = String::from_utf8_lossy(&output.stderr); - info!( + debug!( "Command {command} executed successfully. Stdout: {}", stdout ); @@ -711,7 +758,7 @@ pub async fn disconnect_interface( }; let request = RemoveInterfaceRequest { interface_name, - endpoint: location.endpoint, + endpoint: location.endpoint.clone(), }; debug!("Sending request to the background service to remove interface {} for location {}...", active_connection.interface_name, location.name); if let Err(error) = client.remove_interface(request).await { @@ -737,25 +784,25 @@ pub async fn disconnect_interface( location.name ); trace!("Saved connection: {connection:?}"); - debug!( - "Interface {} removed successfully", + info!( + "Network interface {} for location {location} has been removed", active_connection.interface_name ); - info!("Disconnected from location {}", location.name); + debug!("Finished disconnecting from location {}", location.name); } ConnectionType::Tunnel => { let Some(tunnel) = Tunnel::find_by_id(&state.get_pool(), location_id).await? else { error!("Error while disconnecting interface {interface_name}, tunnel with ID {location_id} not found"); return Err(Error::NotFound); }; - if let Some(pre_down) = tunnel.pre_down { - debug!("Executing specified PreDown command: {pre_down}"); - let _ = execute_command(&pre_down); - info!("Executed specified PreDown command: {pre_down}"); + if let Some(pre_down) = &tunnel.pre_down { + debug!("Executing defined PreDown command before setting up the interface {} for the tunnel {tunnel}: {pre_down}", active_connection.interface_name); + let _ = execute_command(pre_down); + info!("Executed defined PreDown command before setting up the interface {} for the tunnel {tunnel}: {pre_down}", active_connection.interface_name); } let request = RemoveInterfaceRequest { interface_name, - endpoint: tunnel.endpoint, + endpoint: tunnel.endpoint.clone(), }; if let Err(error) = client.remove_interface(request).await { error!( @@ -767,10 +814,10 @@ pub async fn disconnect_interface( error.message() ))); } - if let Some(post_down) = tunnel.post_down { - debug!("Executing specified PostDown command: {post_down}"); - let _ = execute_command(&post_down); - info!("Executed specified PostDown command: {post_down}"); + if let Some(post_down) = &tunnel.post_down { + debug!("Executing defined PostDown command after removing the interface {} for the tunnel {tunnel}: {post_down}", active_connection.interface_name); + let _ = execute_command(post_down); + info!("Executed defined PostDown command after removing the interface {} for the tunnel {tunnel}: {post_down}", active_connection.interface_name); } let connection: TunnelConnection = active_connection.into(); let connection = connection.save(&state.get_pool()).await?; @@ -779,11 +826,11 @@ pub async fn disconnect_interface( tunnel.name ); trace!("Saved connection: {connection:#?}"); - debug!( - "Interface {} removed successfully", + info!( + "Network interface {} for tunnel {tunnel} has been removed", active_connection.interface_name ); - info!("Disconnected from tunnel {}", tunnel.name); + debug!("Finished disconnecting from tunnel {}", tunnel.name); } } @@ -791,13 +838,14 @@ pub async fn disconnect_interface( } /// Helper function to get the name of a tunnel or location by its ID -/// Returns the name of the tunnel or location if it exists, otherwise None +/// Returns the name of the tunnel or location if it exists, otherwise "UNKNOWN" +/// This is for logging purposes. pub async fn get_tunnel_or_location_name( id: Id, connection_type: ConnectionType, appstate: &AppState, -) -> Option { - match connection_type { +) -> String { + let name = match connection_type { ConnectionType::Location => Location::find_by_id(&appstate.get_pool(), id) .await .ok() @@ -806,5 +854,15 @@ pub async fn get_tunnel_or_location_name( .await .ok() .and_then(|t| t.map(|t| t.name)), + }; + + match name { + Some(name) => name, + None => { + debug!( + "Couldn't identify {connection_type}'s name for logging purposes, it will be referred to as UNKNOWN", + ); + "UNKNOWN".to_string() + } } } diff --git a/src/i18n/en/index.ts b/src/i18n/en/index.ts index b5f305e0..e5437bca 100644 --- a/src/i18n/en/index.ts +++ b/src/i18n/en/index.ts @@ -141,6 +141,15 @@ If you are an admin/devops - all your customers (instances) and all their tunnel trace: 'Trace', }, }, + globalLogs: { + logSources: { + cliet: 'Client', + service: 'Service', + all: 'All', + }, + logSourceHelper: + 'The source of the logs. Logs can come from the Defguard client or the background Defguard service that manages VPN conncetions at the network level.', + }, theme: { title: 'Theme', options: { @@ -361,7 +370,7 @@ If you are an admin/devops - all your customers (instances) and all their tunnel

- For more help, please visit defguard help (https://defguard.gitbook.io/) + For more help, please visit defguard help (https://docs.defguard.net)

`, }, @@ -409,7 +418,7 @@ If you are an admin/devops - all your customers (instances) and all their tunnel

- For more help, please visit defguard help (https://defguard.gitbook.io/) + For more help, please visit defguard help (https://docs.defguard.net)

`, }, diff --git a/src/i18n/i18n-types.ts b/src/i18n/i18n-types.ts index 67248acd..365262c7 100644 --- a/src/i18n/i18n-types.ts +++ b/src/i18n/i18n-types.ts @@ -324,6 +324,26 @@ type RootTranslation = { trace: string } } + globalLogs: { + logSources: { + /** + * C​l​i​e​n​t + */ + cliet: string + /** + * S​e​r​v​i​c​e + */ + service: string + /** + * A​l​l + */ + all: string + } + /** + * T​h​e​ ​s​o​u​r​c​e​ ​o​f​ ​t​h​e​ ​l​o​g​s​.​ ​L​o​g​s​ ​c​a​n​ ​c​o​m​e​ ​f​r​o​m​ ​t​h​e​ ​D​e​f​g​u​a​r​d​ ​c​l​i​e​n​t​ ​o​r​ ​t​h​e​ ​b​a​c​k​g​r​o​u​n​d​ ​D​e​f​g​u​a​r​d​ ​s​e​r​v​i​c​e​ ​t​h​a​t​ ​m​a​n​a​g​e​s​ ​V​P​N​ ​c​o​n​n​c​e​t​i​o​n​s​ ​a​t​ ​t​h​e​ ​n​e​t​w​o​r​k​ ​l​e​v​e​l​. + */ + logSourceHelper: string + } theme: { /** * T​h​e​m​e @@ -831,7 +851,7 @@ type RootTranslation = { ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​/​u​l​>​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​/​d​i​v​>​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​p​>​ - ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​F​o​r​ ​m​o​r​e​ ​h​e​l​p​,​ ​p​l​e​a​s​e​ ​v​i​s​i​t​ ​d​e​f​g​u​a​r​d​ ​h​e​l​p​ ​(​h​t​t​p​s​:​/​/​d​e​f​g​u​a​r​d​.​g​i​t​b​o​o​k​.​i​o​/​)​ + ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​F​o​r​ ​m​o​r​e​ ​h​e​l​p​,​ ​p​l​e​a​s​e​ ​v​i​s​i​t​ ​d​e​f​g​u​a​r​d​ ​h​e​l​p​ ​(​h​t​t​p​s​:​/​/​d​o​c​s​.​d​e​f​g​u​a​r​d​.​n​e​t​)​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​/​p​>​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ */ @@ -917,7 +937,7 @@ type RootTranslation = { ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​/​p​>​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​/​d​i​v​>​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​p​>​ - ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​F​o​r​ ​m​o​r​e​ ​h​e​l​p​,​ ​p​l​e​a​s​e​ ​v​i​s​i​t​ ​d​e​f​g​u​a​r​d​ ​h​e​l​p​ ​(​h​t​t​p​s​:​/​/​d​e​f​g​u​a​r​d​.​g​i​t​b​o​o​k​.​i​o​/​)​ + ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​F​o​r​ ​m​o​r​e​ ​h​e​l​p​,​ ​p​l​e​a​s​e​ ​v​i​s​i​t​ ​d​e​f​g​u​a​r​d​ ​h​e​l​p​ ​(​h​t​t​p​s​:​/​/​d​o​c​s​.​d​e​f​g​u​a​r​d​.​n​e​t​)​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​<​/​p​>​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ ​ */ @@ -1830,6 +1850,26 @@ export type TranslationFunctions = { trace: () => LocalizedString } } + globalLogs: { + logSources: { + /** + * Client + */ + cliet: () => LocalizedString + /** + * Service + */ + service: () => LocalizedString + /** + * All + */ + all: () => LocalizedString + } + /** + * The source of the logs. Logs can come from the Defguard client or the background Defguard service that manages VPN conncetions at the network level. + */ + logSourceHelper: () => LocalizedString + } theme: { /** * Theme @@ -2336,7 +2376,7 @@ export type TranslationFunctions = {

- For more help, please visit defguard help (https://defguard.gitbook.io/) + For more help, please visit defguard help (https://docs.defguard.net)

*/ @@ -2422,7 +2462,7 @@ export type TranslationFunctions = {

- For more help, please visit defguard help (https://defguard.gitbook.io/) + For more help, please visit defguard help (https://docs.defguard.net)

*/ diff --git a/src/pages/client/clientAPI/clientApi.ts b/src/pages/client/clientAPI/clientApi.ts index 4944ed4c..bc39f5de 100644 --- a/src/pages/client/clientAPI/clientApi.ts +++ b/src/pages/client/clientAPI/clientApi.ts @@ -32,12 +32,12 @@ async function invokeWrapper( args?: InvokeArgs, timeout: number = 5000, ): Promise { - debug(`Invoking command '${command}'`); + debug(`Invoking command '${command}' on the frontend`); try { const res = await pTimeout(invoke(command, args), { milliseconds: timeout, }); - debug(`Invoke ${command} completed`); + debug(`Invoke ${command} completed on the frontend`); trace(`${command} completed with data: ${JSON.stringify(res)}`); return res; } catch (e) { diff --git a/src/pages/client/clientAPI/types.ts b/src/pages/client/clientAPI/types.ts index 489e5736..85fd600a 100644 --- a/src/pages/client/clientAPI/types.ts +++ b/src/pages/client/clientAPI/types.ts @@ -46,6 +46,8 @@ export type SaveTunnelRequest = { export type TrayIconTheme = 'color' | 'white' | 'black' | 'gray'; export type LogLevel = 'error' | 'info' | 'debug' | 'trace'; +export type GlobalLogLevel = 'error' | 'info' | 'debug'; +export type LogSource = 'Client' | 'Service' | 'All'; export type ClientView = 'grid' | 'detail' | null; @@ -60,6 +62,7 @@ export type LogItem = { level: LogLevel; target: string; fields: LogItemField; + source: LogSource; }; export type InterfaceLogsRequest = { diff --git a/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogs.tsx b/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogs.tsx index 846e33ec..82d76d96 100644 --- a/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogs.tsx +++ b/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogs.tsx @@ -10,15 +10,21 @@ import { useI18nContext } from '../../../../../../i18n/i18n-react'; import { ActionButton } from '../../../../../../shared/defguard-ui/components/Layout/ActionButton/ActionButton'; import { ActionButtonVariant } from '../../../../../../shared/defguard-ui/components/Layout/ActionButton/types'; import { Card } from '../../../../../../shared/defguard-ui/components/Layout/Card/Card'; +import { Helper } from '../../../../../../shared/defguard-ui/components/Layout/Helper/Helper'; import { clientApi } from '../../../../clientAPI/clientApi'; -import { LogItem, LogLevel } from '../../../../clientAPI/types'; -import { useClientStore } from '../../../../hooks/useClientStore'; +import { + GlobalLogLevel, + LogItem, + LogLevel, + LogSource, +} from '../../../../clientAPI/types'; import { GlobalLogsSelect } from './GlobalLogsSelect'; +import { GlobalLogsSourceSelect } from './GlobalLogsSourceSelect'; export const GlobalLogs = () => { const logsContainerElement = useRef(null); - const appLogLevel = useClientStore((state) => state.settings.log_level); - const locationLogLevelRef = useRef(appLogLevel); + const globalLogLevelRef = useRef('info'); + const logSourceRef = useRef('All'); const { LL } = useI18nContext(); const localLL = LL.pages.client.pages.instancePage.detailView.details.logs; const { startGlobalLogWatcher, stopGlobalLogWatcher } = clientApi; @@ -53,9 +59,11 @@ export const GlobalLogs = () => { logItems.forEach((item) => { if ( logsContainerElement.current && - filterLogByLevel(locationLogLevelRef.current, item.level) + filterLogByLevel(globalLogLevelRef.current, item.level) && + filterLogBySource(logSourceRef.current, item.source) ) { - const messageString = `${item.timestamp} ${item.level} ${item.fields.message}`; + const dateTime = new Date(item.timestamp).toLocaleString(); + const messageString = `[${dateTime}][${item.level}][${item.source}] ${item.fields.message}`; const element = createLogLineElement(messageString); const scrollAfterAppend = logsContainerElement.current.scrollHeight - @@ -101,15 +109,33 @@ export const GlobalLogs = () => {

{localLL.title()}

- { - locationLogLevelRef.current = level; - clearLogs(); - stopGlobalLogWatcher(); - startGlobalLogWatcher(); - }} - /> +
+ { + globalLogLevelRef.current = level; + clearLogs(); + stopGlobalLogWatcher(); + startGlobalLogWatcher(); + }} + /> +
+ { + logSourceRef.current = source; + clearLogs(); + stopGlobalLogWatcher(); + startGlobalLogWatcher(); + }} + /> + +

+ {LL.pages.client.pages.settingsPage.tabs.global.globalLogs.logSourceHelper()} +

+ +
+
{ @@ -150,3 +176,7 @@ const filterLogByLevel = (target: LogLevel, log: LogLevel): boolean => { return true; } }; + +const filterLogBySource = (target: LogSource, log: LogSource): boolean => { + return target === 'All' || target === log; +}; diff --git a/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSelect.tsx b/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSelect.tsx index 18050438..88c7028f 100644 --- a/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSelect.tsx +++ b/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSelect.tsx @@ -7,11 +7,11 @@ import { SelectSelectedValue, SelectSizeVariant, } from '../../../../../../shared/defguard-ui/components/Layout/Select/types'; -import { LogLevel } from '../../../../clientAPI/types'; +import { GlobalLogLevel } from '../../../../clientAPI/types'; type Props = { - initSelected: LogLevel; - onChange: (selected: LogLevel) => void; + initSelected: GlobalLogLevel; + onChange: (selected: GlobalLogLevel) => void; }; export const GlobalLogsSelect = ({ initSelected, onChange }: Props) => { @@ -19,7 +19,7 @@ export const GlobalLogsSelect = ({ initSelected, onChange }: Props) => { const localLL = LL.pages.client.pages.settingsPage.tabs.global.logging.options; const [selected, setSelected] = useState(initSelected); - const options = useMemo((): SelectOption[] => { + const options = useMemo((): SelectOption[] => { return [ { key: 0, @@ -40,7 +40,7 @@ export const GlobalLogsSelect = ({ initSelected, onChange }: Props) => { }, [localLL]); const renderSelected = useCallback( - (value: LogLevel): SelectSelectedValue => { + (value: GlobalLogLevel): SelectSelectedValue => { const option = options.find((o) => o.value === value); if (option) { return { diff --git a/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSourceSelect.tsx b/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSourceSelect.tsx new file mode 100644 index 00000000..8bbe204c --- /dev/null +++ b/src/pages/client/pages/ClientSettingsPage/components/GlobalLogs/GlobalLogsSourceSelect.tsx @@ -0,0 +1,71 @@ +import { useCallback, useMemo, useState } from 'react'; + +import { useI18nContext } from '../../../../../../i18n/i18n-react'; +import { Select } from '../../../../../../shared/defguard-ui/components/Layout/Select/Select'; +import { + SelectOption, + SelectSelectedValue, + SelectSizeVariant, +} from '../../../../../../shared/defguard-ui/components/Layout/Select/types'; +import { LogSource } from '../../../../clientAPI/types'; + +type Props = { + initSelected: LogSource; + onChange: (selected: LogSource) => void; +}; + +export const GlobalLogsSourceSelect = ({ initSelected, onChange }: Props) => { + const { LL } = useI18nContext(); + const localLL = LL.pages.client.pages.settingsPage.tabs.global.globalLogs.logSources; + const [selected, setSelected] = useState(initSelected); + + const options = useMemo((): SelectOption[] => { + return [ + { + key: 0, + label: localLL.all(), + value: 'All', + }, + { + key: 1, + label: localLL.cliet(), + value: 'Client', + }, + { + key: 2, + label: localLL.service(), + value: 'Service', + }, + ]; + }, [localLL]); + + const renderSelected = useCallback( + (value: LogSource): SelectSelectedValue => { + const option = options.find((o) => o.value === value); + if (option) { + return { + key: option.key, + displayValue: option.label, + }; + } + return { + key: 0, + displayValue: '', + }; + }, + [options], + ); + + return ( +