Log improvements (#340)

* some log improvements, also updates the documentation url

* cleanup

* cleanup 2

* sqlx prepare

.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

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 <strong>one client</strong>! 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
 

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
 

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"

src-tauri/src/appstate.rs

@@ -57,15 +57,15 @@ impl AppState {
         location_id: Id,
         connection_type: &ConnectionType,
     ) -> Option<ActiveConnection> {
-        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| {
             conn.location_id == location_id && conn.connection_type.eq(connection_type)
         }) {
             // 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,16 +118,16 @@ impl AppState {
         connection_type: ConnectionType,
     ) -> Option<ActiveConnection> {
         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
             .iter()
             .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.");

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<String> = 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,35 +164,61 @@ 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())
         .manage(AppState::default())
         .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<AppState> = 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<pathbuf> 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<AppState> = 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<AppState> = app_handle.state();
             app_state.quit(app_handle);
         }