From 462428f99a9b19e78f6bf38e7eca7c08cf6cb328 Mon Sep 17 00:00:00 2001 From: Kevin Yue Date: Tue, 23 May 2023 14:30:20 +0800 Subject: [PATCH] refactor: Add logger --- Cargo.lock | 246 +++++++++++++++++++++++++++++++++++- common/Cargo.toml | 1 + common/src/client.rs | 33 +++-- common/src/connection.rs | 38 +++--- common/src/server.rs | 16 +-- common/src/vpn/ffi.rs | 26 +++- common/src/vpn/mod.rs | 20 +-- common/src/vpn/vpn.c | 45 ++++--- common/src/vpn/vpn.h | 62 ++++++++- gpgui/package.json | 3 +- gpgui/pnpm-lock.yaml | 11 ++ gpgui/src-tauri/Cargo.toml | 9 +- gpgui/src-tauri/src/main.rs | 3 + gpservice/Cargo.toml | 2 + gpservice/src/main.rs | 6 +- 15 files changed, 430 insertions(+), 91 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index f4bac8f..b24a081 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -43,10 +43,13 @@ name = "app" version = "0.1.0" dependencies = [ "common", + "env_logger", + "log", "serde", "serde_json", "tauri", "tauri-build", + "tauri-plugin-log", ] [[package]] @@ -176,6 +179,16 @@ version = "3.12.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0d261e256854913907f67ed06efbc3338dfe6179796deefc1ff763fc1aee5535" +[[package]] +name = "byte-unit" +version = "4.0.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "da78b32057b8fdfc352504708feeba7216dcd65a2c9ab02978cbd288d1279b6c" +dependencies = [ + "serde", + "utf8-width", +] + [[package]] name = "bytemuck" version = "1.13.0" @@ -329,6 +342,7 @@ dependencies = [ "bytes", "cc", "data-encoding", + "log", "ring", "serde", "serde_json", @@ -601,6 +615,40 @@ dependencies = [ "cfg-if", ] +[[package]] +name = "env_logger" +version = "0.10.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "85cdab6a89accf66733ad5a1693a4dcced6aeff64602b634530dd73c1f3ee9f0" +dependencies = [ + "humantime", + "is-terminal", + "log", + "regex", + "termcolor", +] + +[[package]] +name = "errno" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4bcfec3a70f97c962c307b2d2c56e358cf1d00b558d74262b5f929ee8cc7e73a" +dependencies = [ + "errno-dragonfly", + "libc", + "windows-sys 0.48.0", +] + +[[package]] +name = "errno-dragonfly" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "aa68f1b12764fab894d2755d2518754e71b4fd80ecfb822714a1206c2aab39bf" +dependencies = [ + "cc", + "libc", +] + [[package]] name = "fastrand" version = "1.8.0" @@ -610,6 +658,15 @@ dependencies = [ "instant", ] +[[package]] +name = "fern" +version = "0.6.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d9f0c14694cbd524c8720dd69b0e3179344f04ebb5f90f2e4a440c6ea3b2f1ee" +dependencies = [ + "log", +] + [[package]] name = "field-offset" version = "0.3.4" @@ -995,6 +1052,8 @@ name = "gpservice" version = "0.1.0" dependencies = [ "common", + "env_logger", + "log", "tokio", ] @@ -1083,6 +1142,12 @@ dependencies = [ "libc", ] +[[package]] +name = "hermit-abi" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fed44880c466736ef9a5c5b5facefb5ed0785676d0c02d612db14e54f0d84286" + [[package]] name = "html5ever" version = "0.25.2" @@ -1114,6 +1179,12 @@ version = "0.1.5" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "21dec9db110f5f872ed9699c3ecf50cf16f423502706ba5c72462e28d3157573" +[[package]] +name = "humantime" +version = "2.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" + [[package]] name = "ico" version = "0.2.0" @@ -1199,6 +1270,29 @@ dependencies = [ "cfg-if", ] +[[package]] +name = "io-lifetimes" +version = "1.0.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9c66c74d2ae7e79a5a8f7ac924adbe38ee42a859c6539ad869eb51f0b52dc220" +dependencies = [ + "hermit-abi 0.3.1", + "libc", + "windows-sys 0.48.0", +] + +[[package]] +name = "is-terminal" +version = "0.4.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "adcf93614601c8129ddf72e2d5633df827ba6551541c6d8c59520a371475be1f" +dependencies = [ + "hermit-abi 0.3.1", + "io-lifetimes", + "rustix", + "windows-sys 0.48.0", +] + [[package]] name = "itoa" version = "0.4.8" @@ -1307,6 +1401,12 @@ dependencies = [ "safemem", ] +[[package]] +name = "linux-raw-sys" +version = "0.3.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ece97ea872ece730aed82664c424eb4c8291e1ff2480247ccf7409044bc6479f" + [[package]] name = "lock_api" version = "0.4.9" @@ -1324,6 +1424,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "abb12e687cfb44aa40f41fc3978ef76448f9b6038cad6aef4259d3c095a2382e" dependencies = [ "cfg-if", + "value-bag", ] [[package]] @@ -1525,7 +1626,7 @@ version = "1.15.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0fac9e2da13b5eb447a6ce3d392f23a29d8694bff781bf03a16cd9ac8697593b" dependencies = [ - "hermit-abi", + "hermit-abi 0.2.6", "libc", ] @@ -1550,6 +1651,15 @@ dependencies = [ "syn", ] +[[package]] +name = "num_threads" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2819ce041d2ee131036f4fc9d6ae7ae125a3a40e97ba64d04fe799ad9dabbb44" +dependencies = [ + "libc", +] + [[package]] name = "objc" version = "0.2.7" @@ -2104,6 +2214,20 @@ dependencies = [ "semver 1.0.16", ] +[[package]] +name = "rustix" +version = "0.37.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "62b24138615de35e32031d041a09032ef3487a616d901ca4db224e7d557efae2" +dependencies = [ + "bitflags", + "errno", + "io-lifetimes", + "libc", + "linux-raw-sys", + "windows-sys 0.45.0", +] + [[package]] name = "rustversion" version = "1.0.11" @@ -2666,6 +2790,21 @@ dependencies = [ "tauri-utils", ] +[[package]] +name = "tauri-plugin-log" +version = "0.0.0" +source = "git+https://github.com/tauri-apps/plugins-workspace?branch=v1#794f2d5cb8d53284f0abbeb8f584185b4dce3fc1" +dependencies = [ + "byte-unit", + "fern", + "log", + "serde", + "serde_json", + "serde_repr", + "tauri", + "time", +] + [[package]] name = "tauri-runtime" version = "0.12.1" @@ -2759,6 +2898,15 @@ dependencies = [ "utf-8", ] +[[package]] +name = "termcolor" +version = "1.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "be55cf8942feac5c765c2c993422806843c9a9a45d4d5c407ad6dd2ea95eb9b6" +dependencies = [ + "winapi-util", +] + [[package]] name = "thin-slice" version = "0.1.1" @@ -2802,6 +2950,8 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "cd0cbfecb4d19b5ea75bb31ad904eb5b9fa13f21079c3b92017ebdf4999a5890" dependencies = [ "itoa 1.0.5", + "libc", + "num_threads", "serde", "time-core", "time-macros", @@ -3041,6 +3191,12 @@ version = "0.7.6" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "09cc8ee72d2a9becf2f2febe0205bbed8fc6615b7cb429ad062dc7b7ddd036a9" +[[package]] +name = "utf8-width" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5190c9442dcdaf0ddd50f37420417d219ae5261bbf5db120d0f9bab996c9cba1" + [[package]] name = "uuid" version = "0.8.2" @@ -3062,6 +3218,16 @@ version = "0.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" +[[package]] +name = "value-bag" +version = "1.0.0-alpha.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2209b78d1249f7e6f3293657c9779fe31ced465df091bbd433a1cf88e916ec55" +dependencies = [ + "ctor", + "version_check", +] + [[package]] name = "vcpkg" version = "0.2.15" @@ -3309,7 +3475,7 @@ version = "0.44.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9e745dab35a0c4c77aa3ce42d595e13d2003d6902d6b08c9ef5fc326d08da12b" dependencies = [ - "windows-targets", + "windows-targets 0.42.1", ] [[package]] @@ -3344,12 +3510,12 @@ version = "0.42.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "5a3e1820f08b8513f676f7ab6c1f99ff312fb97b553d30ff4dd86f9f15728aa7" dependencies = [ - "windows_aarch64_gnullvm", + "windows_aarch64_gnullvm 0.42.1", "windows_aarch64_msvc 0.42.1", "windows_i686_gnu 0.42.1", "windows_i686_msvc 0.42.1", "windows_x86_64_gnu 0.42.1", - "windows_x86_64_gnullvm", + "windows_x86_64_gnullvm 0.42.1", "windows_x86_64_msvc 0.42.1", ] @@ -3359,7 +3525,16 @@ version = "0.45.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "75283be5efb2831d37ea142365f009c02ec203cd29a3ebecbc093d52315b66d0" dependencies = [ - "windows-targets", + "windows-targets 0.42.1", +] + +[[package]] +name = "windows-sys" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "677d2418bec65e3338edb076e806bc1ec15693c5d0104683f2efe857f61056a9" +dependencies = [ + "windows-targets 0.48.0", ] [[package]] @@ -3368,15 +3543,30 @@ version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8e2522491fbfcd58cc84d47aeb2958948c4b8982e9a2d8a2a35bbaed431390e7" dependencies = [ - "windows_aarch64_gnullvm", + "windows_aarch64_gnullvm 0.42.1", "windows_aarch64_msvc 0.42.1", "windows_i686_gnu 0.42.1", "windows_i686_msvc 0.42.1", "windows_x86_64_gnu 0.42.1", - "windows_x86_64_gnullvm", + "windows_x86_64_gnullvm 0.42.1", "windows_x86_64_msvc 0.42.1", ] +[[package]] +name = "windows-targets" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7b1eb6f0cd7c80c79759c929114ef071b87354ce476d9d94271031c0497adfd5" +dependencies = [ + "windows_aarch64_gnullvm 0.48.0", + "windows_aarch64_msvc 0.48.0", + "windows_i686_gnu 0.48.0", + "windows_i686_msvc 0.48.0", + "windows_x86_64_gnu 0.48.0", + "windows_x86_64_gnullvm 0.48.0", + "windows_x86_64_msvc 0.48.0", +] + [[package]] name = "windows-tokens" version = "0.39.0" @@ -3389,6 +3579,12 @@ version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8c9864e83243fdec7fc9c5444389dcbbfd258f745e7853198f365e3c4968a608" +[[package]] +name = "windows_aarch64_gnullvm" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "91ae572e1b79dba883e0d315474df7305d12f569b400fcf90581b06062f7e1bc" + [[package]] name = "windows_aarch64_msvc" version = "0.39.0" @@ -3401,6 +3597,12 @@ version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "4c8b1b673ffc16c47a9ff48570a9d85e25d265735c503681332589af6253c6c7" +[[package]] +name = "windows_aarch64_msvc" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b2ef27e0d7bdfcfc7b868b317c1d32c641a6fe4629c171b8928c7b08d98d7cf3" + [[package]] name = "windows_i686_gnu" version = "0.39.0" @@ -3413,6 +3615,12 @@ version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "de3887528ad530ba7bdbb1faa8275ec7a1155a45ffa57c37993960277145d640" +[[package]] +name = "windows_i686_gnu" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "622a1962a7db830d6fd0a69683c80a18fda201879f0f447f065a3b7467daa241" + [[package]] name = "windows_i686_msvc" version = "0.39.0" @@ -3425,6 +3633,12 @@ version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "bf4d1122317eddd6ff351aa852118a2418ad4214e6613a50e0191f7004372605" +[[package]] +name = "windows_i686_msvc" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4542c6e364ce21bf45d69fdd2a8e455fa38d316158cfd43b3ac1c5b1b19f8e00" + [[package]] name = "windows_x86_64_gnu" version = "0.39.0" @@ -3437,12 +3651,24 @@ version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c1040f221285e17ebccbc2591ffdc2d44ee1f9186324dd3e84e99ac68d699c45" +[[package]] +name = "windows_x86_64_gnu" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ca2b8a661f7628cbd23440e50b05d705db3686f894fc9580820623656af974b1" + [[package]] name = "windows_x86_64_gnullvm" version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "628bfdf232daa22b0d64fdb62b09fcc36bb01f05a3939e20ab73aaf9470d0463" +[[package]] +name = "windows_x86_64_gnullvm" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7896dbc1f41e08872e9d5e8f8baa8fdd2677f29468c4e156210174edc7f7b953" + [[package]] name = "windows_x86_64_msvc" version = "0.39.0" @@ -3455,6 +3681,12 @@ version = "0.42.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "447660ad36a13288b1db4d4248e857b510e8c3a225c822ba4fb748c0aafecffd" +[[package]] +name = "windows_x86_64_msvc" +version = "0.48.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1a515f5799fe4961cb532f983ce2b23082366b898e52ffbce459c86f67c8378a" + [[package]] name = "winnow" version = "0.3.3" diff --git a/common/Cargo.toml b/common/Cargo.toml index 510be70..6c406dc 100644 --- a/common/Cargo.toml +++ b/common/Cargo.toml @@ -15,6 +15,7 @@ serde_json = "1.0" async-trait = "0.1" ring = "0.16" data-encoding = "2.3" +log = "0.4" [build-dependencies] cc = "1.0" diff --git a/common/src/client.rs b/common/src/client.rs index 1b45a87..1adf6e4 100644 --- a/common/src/client.rs +++ b/common/src/client.rs @@ -7,6 +7,7 @@ use crate::RequestPool; use crate::Response; use crate::SOCKET_PATH; use crate::{Request, VpnStatus}; +use log::{info, warn, debug}; use serde::{Deserialize, Serialize}; use std::fmt::Display; use std::sync::Arc; @@ -107,16 +108,16 @@ impl Client { } pub async fn run(&self) { + info!("Connecting to the background service..."); + + // TODO exit the loop properly loop { match self.connect_to_server().await { Ok(_) => { - println!("Disconnected from server, reconnecting..."); + debug!("Disconnected from server, reconnecting..."); } Err(err) => { - println!( - "Disconnected from server with error: {:?}, reconnecting...", - err - ) + debug!("Error connecting to server, retrying, error: {:?}", err) } } @@ -144,10 +145,13 @@ impl Client { )); *self.is_healthy.write().await = true; - println!("Connected to server"); + info!("Connected to the background service"); + let _ = tokio::join!(read_handle, write_handle); *self.is_healthy.write().await = false; + // TODO connection was lost, cleanup the request pool and notify the UI + Ok(()) } @@ -208,22 +212,25 @@ async fn handle_read( Some(id) => request_pool.complete_request(id, response).await, None => { if let Err(err) = server_event_tx.send(response.into()).await { - println!("Error sending response to output channel: {}", err); + warn!("Error sending response to output channel: {}", err); } } } } } Err(err) if err.kind() == io::ErrorKind::ConnectionAborted => { - println!("Server disconnected"); + warn!("Disconnected from the background service"); if let Err(err) = server_event_tx.send(ServerEvent::ServerDisconnected).await { - println!("Error sending server disconnected event: {}", err); + warn!( + "Error sending server disconnected event to channel: {}", + err + ); } cancel_token.cancel(); break; } Err(err) => { - println!("Error reading from server: {}", err); + warn!("Error reading from server: {}", err); } } } @@ -240,15 +247,15 @@ async fn handle_write( tokio::select! { Some(request) = request_rx.recv() => { if let Err(err) = writer.write(&request).await { - println!("Error writing to server: {}", err); + warn!("Error writing to server: {}", err); } } _ = cancel_token.cancelled() => { - println!("The read loop has been cancelled, exiting the write loop"); + info!("The read loop has been cancelled, exiting the write loop"); break; } else => { - println!("Error reading command from channel"); + warn!("Error reading command from channel"); } } } diff --git a/common/src/connection.rs b/common/src/connection.rs index 0e918b0..b1a85bd 100644 --- a/common/src/connection.rs +++ b/common/src/connection.rs @@ -5,6 +5,7 @@ use crate::Response; use crate::ResponseData; use crate::VpnStatus; use crate::Writer; +use log::{debug, info, warn}; use std::sync::Arc; use tokio::io::{self, ReadHalf, WriteHalf}; use tokio::net::UnixStream; @@ -29,12 +30,13 @@ async fn handle_read( } if !authenticated.unwrap_or(false) { - println!("Client not authenticated"); + warn!("Client not authenticated, closing connection"); cancel_token.cancel(); break; } - println!("Received request: {:?}", request); + debug!("Received client request: {:?}", request); + let command = request.command(); let context = server_context.clone().into(); @@ -48,13 +50,13 @@ async fn handle_read( } Err(err) if err.kind() == io::ErrorKind::ConnectionAborted => { - println!("Client disconnected"); + info!("Client disconnected"); cancel_token.cancel(); break; } Err(err) => { - println!("Error receiving command: {:?}", err); + warn!("Error receiving request: {:?}", err); } } } @@ -70,19 +72,17 @@ async fn handle_write( loop { tokio::select! { Some(response) = response_rx.recv() => { - println!("Sending response: {:?}", response); + debug!("Sending response: {:?}", response); if let Err(err) = writer.write(&response).await { - println!("Error sending response: {:?}", err); - } else { - println!("Response sent"); + warn!("Error sending response: {:?}", err); } } _ = cancel_token.cancelled() => { - println!("Exiting write loop"); + info!("Exiting the write loop"); break; } else => { - println!("Error receiving response"); + warn!("Error receiving response from channel"); } } } @@ -95,21 +95,21 @@ async fn handle_status_change( ) { // Send the initial status send_status(&status_rx, &response_tx).await; - println!("Waiting for status change"); + debug!("Waiting for status change"); let start_time = std::time::Instant::now(); loop { tokio::select! { _ = status_rx.changed() => { - println!("Status changed: {:?}", start_time.elapsed()); + debug!("Status changed: {:?}", start_time.elapsed()); send_status(&status_rx, &response_tx).await; } _ = cancel_token.cancelled() => { - println!("Exiting status loop"); + info!("Exiting the status loop"); break; } else => { - println!("Error receiving status"); + warn!("Error receiving status from channel"); } } } @@ -121,7 +121,7 @@ async fn send_status(status_rx: &watch::Receiver, response_tx: &mpsc: .send(Response::from(ResponseData::Status(status))) .await { - println!("Error sending status: {:?}", err); + warn!("Error sending status: {:?}", err); } } @@ -132,6 +132,7 @@ pub(crate) async fn handle_connection(socket: UnixStream, context: Arc Option { @@ -164,9 +167,10 @@ fn peer_pid(socket: &UnixStream) -> Option { } } +// TODO - Implement authentication fn authenticate(peer_pid: Option) -> bool { if let Some(pid) = peer_pid { - println!("Peer PID: {}", pid); + info!("Peer PID: {}", pid); true } else { false diff --git a/common/src/server.rs b/common/src/server.rs index b881643..0c21db1 100644 --- a/common/src/server.rs +++ b/common/src/server.rs @@ -1,4 +1,5 @@ use crate::{connection::handle_connection, vpn::Vpn}; +use log::{warn, info}; use std::{future::Future, os::unix::prelude::PermissionsExt, path::Path, sync::Arc}; use tokio::fs; use tokio::net::{UnixListener, UnixStream}; @@ -39,7 +40,7 @@ impl Server { } let listener = UnixListener::bind(&self.socket_path)?; - println!("Listening on socket: {:?}", listener.local_addr()?); + info!("Listening on socket: {:?}", listener.local_addr()?); let metadata = fs::metadata(&self.socket_path).await?; let mut permissions = metadata.permissions(); @@ -49,11 +50,11 @@ impl Server { loop { match listener.accept().await { Ok((socket, _)) => { - println!("Accepted connection: {:?}", socket.peer_addr()?); + info!("Accepted connection: {:?}", socket.peer_addr()?); tokio::spawn(handle_connection(socket, self.context.clone())); } Err(err) => { - println!("Error accepting connection: {:?}", err); + warn!("Error accepting connection: {:?}", err); } } } @@ -73,18 +74,15 @@ pub async fn run( let server = Server::new(socket_path.to_string()); if server.is_running().await { - println!("Server is already running"); - return Ok(()); + return Err("Another instance of the server is already running".into()); } tokio::select! { res = server.start() => { - if let Err(err) = res { - println!("Error starting server: {:?}", err); - } + res? }, _ = shutdown => { - println!("Shutting down"); + info!("Shutting down the server..."); server.stop().await?; }, } diff --git a/common/src/vpn/ffi.rs b/common/src/vpn/ffi.rs index 833a0ca..af4539d 100644 --- a/common/src/vpn/ffi.rs +++ b/common/src/vpn/ffi.rs @@ -1,3 +1,4 @@ +use log::{debug, info, trace, warn}; use std::ffi::c_void; use tokio::sync::mpsc; @@ -28,9 +29,28 @@ extern "C" fn on_vpn_connected(value: i32, sender: *mut c_void) { } // Logger used in the C code. +// level: 0 = error, 1 = info, 2 = debug, 3 = trace +// map the error level log in openconnect to the warning level #[no_mangle] extern "C" fn vpn_log(level: i32, message: *const ::std::os::raw::c_char) { - println!("{}: {:?}", level, unsafe { - std::ffi::CStr::from_ptr(message) - }); + let message = unsafe { std::ffi::CStr::from_ptr(message) }; + let message = message.to_str().unwrap_or("Invalid log message"); + // Strip the trailing newline + let message = message.trim_end_matches('\n'); + + if level == 0 { + warn!("{}", message); + } else if level == 1 { + info!("{}", message); + } else if level == 2 { + debug!("{}", message); + } else if level == 3 { + trace!("{}", message); + } else { + warn!( + "Unknown log level: {}, enable DEBUG log level to see more details", + level + ); + debug!("{}", message); + } } diff --git a/common/src/vpn/mod.rs b/common/src/vpn/mod.rs index a4c7fa5..29e8c13 100644 --- a/common/src/vpn/mod.rs +++ b/common/src/vpn/mod.rs @@ -1,3 +1,4 @@ +use log::{warn, info, debug}; use serde::{Deserialize, Serialize}; use std::ffi::{c_void, CString}; use std::sync::Arc; @@ -43,7 +44,7 @@ impl StatusHolder { fn set(&mut self, status: VpnStatus) { self.status = status; if let Err(err) = self.status_tx.send(status) { - println!("Failed to send VPN status: {}", err); + warn!("Failed to send VPN status: {}", err); } } @@ -113,17 +114,17 @@ impl Vpn { status_holder.blocking_lock().set(VpnStatus::Connecting); let ret = unsafe { ffi::connect(&oc_options) }; - println!("VPN connection closed with code: {}", ret); + info!("VPN connection closed with code: {}", ret); status_holder.blocking_lock().set(VpnStatus::Disconnected); }); - println!("Waiting for the VPN connection..."); + info!("Waiting for the VPN connection..."); if let Some(cmd_pipe_fd) = vpn_rx.recv().await { - println!("VPN connection started, code: {}", cmd_pipe_fd); + info!("VPN connection started, cmd_pipe_fd: {}", cmd_pipe_fd); self.status_holder.lock().await.set(VpnStatus::Connected); } else { - println!("VPN connection failed to start"); + warn!("VPN connection failed to start"); } Ok(()) @@ -131,17 +132,20 @@ impl Vpn { pub async fn disconnect(&self) { if self.status().await == VpnStatus::Disconnected { - println!("VPN already disconnected"); + info!("VPN already disconnected, skipping disconnect"); return; } + info!("Disconnecting VPN..."); unsafe { ffi::disconnect() }; - // Wait for the VPN to disconnect - println!("VPN disconnect waiting for disconnect..."); + let mut status_rx = self.status_rx().await; + debug!("Waiting for the VPN to disconnect..."); + while status_rx.changed().await.is_ok() { if *status_rx.borrow() == VpnStatus::Disconnected { + info!("VPN disconnected"); break; } } diff --git a/common/src/vpn/vpn.c b/common/src/vpn/vpn.c index dae4464..2c677d8 100644 --- a/common/src/vpn/vpn.c +++ b/common/src/vpn/vpn.c @@ -1,10 +1,9 @@ #include -#include #include #include -#include -#include #include +#include +#include #include "vpn.h" @@ -16,27 +15,27 @@ const char *g_vpnc_script; /* Validate the peer certificate */ static int validate_peer_cert(__attribute__((unused)) void *_vpninfo, const char *reason) { - printf("Validating peer cert: %s\n", reason); + INFO("Validating peer cert: %s", reason); return 0; } /* Print progress messages */ -static void print_progress(__attribute__((unused)) void *_vpninfo, int level, const char *fmt, ...) +static void print_progress(__attribute__((unused)) void *_vpninfo, int level, const char *format, ...) { - FILE *outf = level ? stdout : stderr; va_list args; - - char ts[64]; - time_t t = time(NULL); - struct tm *tm = localtime(&t); - - strftime(ts, 64, "[%Y-%m-%d %H:%M:%S] ", tm); - fprintf(outf, "%s", ts); - - va_start(args, fmt); - vfprintf(outf, fmt, args); + va_start(args, format); + char *message = format_message(format, args); va_end(args); - fflush(outf); + + if (message == NULL) + { + ERROR("Failed to format log message"); + } + else + { + LOG(level, message); + free(message); + } } static void setup_tun_handler(void *_vpninfo) @@ -58,7 +57,7 @@ int vpn_connect(const Options *options) if (!vpninfo) { - printf("openconnect_vpninfo_new failed\n"); + ERROR("openconnect_vpninfo_new failed"); return 1; } @@ -71,7 +70,7 @@ int vpn_connect(const Options *options) g_cmd_pipe_fd = openconnect_setup_cmd_pipe(vpninfo); if (g_cmd_pipe_fd < 0) { - printf("openconnect_setup_cmd_pipe failed\n"); + ERROR("openconnect_setup_cmd_pipe failed"); return 1; } @@ -83,7 +82,7 @@ int vpn_connect(const Options *options) // Essential step if (openconnect_make_cstp_connection(vpninfo) != 0) { - printf("openconnect_make_cstp_connection failed\n"); + ERROR("openconnect_make_cstp_connection failed"); return 1; } @@ -98,15 +97,15 @@ int vpn_connect(const Options *options) while (1) { int ret = openconnect_mainloop(vpninfo, 300, 10); - printf("openconnect_mainloop returned %d\n", ret); if (ret) { + INFO("openconnect_mainloop returned %d, exiting", ret); openconnect_vpninfo_free(vpninfo); return ret; } - printf("openconnect_mainloop returned\n"); + INFO("openconnect_mainloop returned 0, reconnecting"); } } @@ -116,6 +115,6 @@ void vpn_disconnect() char cmd = OC_CMD_CANCEL; if (write(g_cmd_pipe_fd, &cmd, 1) < 0) { - printf("Stopping VPN failed\n"); + ERROR("Failed to write to command pipe, VPN connection may not be stopped"); } } diff --git a/common/src/vpn/vpn.h b/common/src/vpn/vpn.h index c2300c7..a853cb4 100644 --- a/common/src/vpn/vpn.h +++ b/common/src/vpn/vpn.h @@ -1,12 +1,62 @@ -typedef struct Options { - const char *server; - const char *cookie; - const char *script; - void *user_data; +#include +#include +#include +#include + +typedef struct Options +{ + const char *server; + const char *cookie; + const char *script; + void *user_data; } Options; int vpn_connect(const Options *options); void vpn_disconnect(); extern void on_vpn_connected(int cmd_pipe_fd, void *user_data); -extern void vpn_log(int level, const char *msg); \ No newline at end of file +extern void vpn_log(int level, const char *msg); + +static char *format_message(const char *format, va_list args) +{ + va_list args_copy; + va_copy(args_copy, args); + int len = vsnprintf(NULL, 0, format, args_copy); + va_end(args_copy); + + char *buffer = malloc(len + 1); + if (buffer == NULL) + { + return NULL; + } + + vsnprintf(buffer, len + 1, format, args); + return buffer; +} + +static void _log(int level, ...) +{ + va_list args; + va_start(args, level); + + char *format = va_arg(args, char *); + char *message = format_message(format, args); + + va_end(args); + + if (message == NULL) + { + vpn_log(PRG_ERR, "Failed to format log message"); + } + else + { + vpn_log(level, message); + free(message); + } +} + +#define LOG(level, ...) _log(level, __VA_ARGS__) +#define ERROR(...) LOG(PRG_ERR, __VA_ARGS__) +#define INFO(...) LOG(PRG_INFO, __VA_ARGS__) +#define DEBUG(...) LOG(PRG_DEBUG, __VA_ARGS__) +#define TRACE(...) LOG(PRG_TRACE, __VA_ARGS__) diff --git a/gpgui/package.json b/gpgui/package.json index f3dddde..abb47ee 100644 --- a/gpgui/package.json +++ b/gpgui/package.json @@ -17,7 +17,8 @@ "@tauri-apps/api": "^1.2.0", "react": "^18.2.0", "react-dom": "^18.2.0", - "react-spinners": "^0.13.8" + "react-spinners": "^0.13.8", + "tauri-plugin-log-api": "github:tauri-apps/tauri-plugin-log" }, "devDependencies": { "@tauri-apps/cli": "^1.2.3", diff --git a/gpgui/pnpm-lock.yaml b/gpgui/pnpm-lock.yaml index b3fd641..943e2e1 100644 --- a/gpgui/pnpm-lock.yaml +++ b/gpgui/pnpm-lock.yaml @@ -28,6 +28,9 @@ dependencies: react-spinners: specifier: ^0.13.8 version: 0.13.8(react-dom@18.2.0)(react@18.2.0) + tauri-plugin-log-api: + specifier: github:tauri-apps/tauri-plugin-log + version: github.com/tauri-apps/tauri-plugin-log/5e14c2cad7335a4284a6caad81d8cf37dd675a27 devDependencies: '@tauri-apps/cli': @@ -1389,3 +1392,11 @@ packages: resolution: {integrity: sha512-r3vXyErRCYJ7wg28yvBY5VSoAF8ZvlcW9/BwUzEtUsjvX/DKs24dIkuwjtuprwJJHsbyUbLApepYTR1BN4uHrg==} engines: {node: '>= 6'} dev: false + + github.com/tauri-apps/tauri-plugin-log/5e14c2cad7335a4284a6caad81d8cf37dd675a27: + resolution: {tarball: https://codeload.github.com/tauri-apps/tauri-plugin-log/tar.gz/5e14c2cad7335a4284a6caad81d8cf37dd675a27} + name: tauri-plugin-log-api + version: 0.0.0 + dependencies: + '@tauri-apps/api': 1.2.0 + dev: false diff --git a/gpgui/src-tauri/Cargo.toml b/gpgui/src-tauri/Cargo.toml index f391281..2469f56 100644 --- a/gpgui/src-tauri/Cargo.toml +++ b/gpgui/src-tauri/Cargo.toml @@ -15,15 +15,18 @@ rust-version = "1.59" tauri-build = { version = "1.2.1", features = [] } [dependencies] +tauri = { version = "1.2.4", features = ["http-all"] } +tauri-plugin-log = { git = "https://github.com/tauri-apps/plugins-workspace", branch = "v1" } serde_json = "1.0" serde = { version = "1.0", features = ["derive"] } -tauri = { version = "1.2.4", features = ["http-all"] } +log = "0.4" +env_logger = "0.10" common = { path = "../../common" } [features] # by default Tauri runs in production mode # when `tauri dev` runs it is executed with `cargo run --no-default-features` if `devPath` is an URL -default = [ "custom-protocol" ] +default = ["custom-protocol"] # this feature is used for production builds where `devPath` points to the filesystem # DO NOT remove this -custom-protocol = [ "tauri/custom-protocol" ] +custom-protocol = ["tauri/custom-protocol"] diff --git a/gpgui/src-tauri/src/main.rs b/gpgui/src-tauri/src/main.rs index 9fc565d..96a427f 100644 --- a/gpgui/src-tauri/src/main.rs +++ b/gpgui/src-tauri/src/main.rs @@ -4,6 +4,7 @@ )] use common::{Client, ServerApiError, VpnStatus}; +use env_logger::Env; use serde::Serialize; use std::sync::Arc; use tauri::{Manager, State}; @@ -53,6 +54,8 @@ fn setup(app: &mut tauri::App) -> Result<(), Box> { } fn main() { + env_logger::Builder::from_env(Env::default().default_filter_or("info")).init(); + tauri::Builder::default() .setup(setup) .invoke_handler(tauri::generate_handler![ diff --git a/gpservice/Cargo.toml b/gpservice/Cargo.toml index 2daef7a..48bc724 100644 --- a/gpservice/Cargo.toml +++ b/gpservice/Cargo.toml @@ -8,6 +8,8 @@ edition = "2021" [dependencies] common = { path = "../common" } tokio = { version = "1", features = ["full"] } +env_logger = "0.10" +log = "0.4" # warp = "0.3" # aes-gcm = "0.10" # procfs = "0.15" diff --git a/gpservice/src/main.rs b/gpservice/src/main.rs index 004946e..e62a2a1 100644 --- a/gpservice/src/main.rs +++ b/gpservice/src/main.rs @@ -2,6 +2,8 @@ include!(concat!(env!("OUT_DIR"), "/client_hash.rs")); // use aes_gcm::{aead::OsRng, Aes256Gcm, KeyInit}; use common::{server, SOCKET_PATH}; +use env_logger::Env; +use log::error; use tokio::signal; // static mut HTTP_PORT: u16 = 0; @@ -96,6 +98,8 @@ use tokio::signal; #[tokio::main] async fn main() -> Result<(), Box> { + env_logger::Builder::from_env(Env::default().default_filter_or("info")).init(); + // println!("{GPCLIENT_HASH}"); // unsafe { @@ -107,7 +111,7 @@ async fn main() -> Result<(), Box> { // server::start().await if let Err(err) = server::run(SOCKET_PATH, signal::ctrl_c()).await { - println!("Error starting the server: {err}"); + error!("Error running server: {}", err); } Ok(()) }