cassidy/GlobalProtect-openconnect
1
0
Fork 0
mirror of https://github.com/yuezk/GlobalProtect-openconnect.git synced 2025-05-20 07:26:58 -04:00
Code Issues Projects Releases Wiki Activity

refactor: Add logger

Browse Source
This commit is contained in:
Kevin Yue
2023-05-23 14:30:20 +08:00
parent cbd8b0f144
commit 462428f99a
15 changed files with 430 additions and 91 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
common/Cargo.toml
View File

@@ -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"

33
common/src/client.rs
View File

@@ -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");
}
}
}

38
common/src/connection.rs
View File

@@ -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<VpnStatus>, 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<ServerCon
let cancel_token = CancellationToken::new();
let status_rx = context.vpn().status_rx().await;
// Read requests from the client
let read_handle = tokio::spawn(handle_read(
read_stream,
context.clone(),
@@ -140,12 +141,14 @@ pub(crate) async fn handle_connection(socket: UnixStream, context: Arc<ServerCon
cancel_token.clone(),
));
// Write responses to the client
let write_handle = tokio::spawn(handle_write(
write_stream,
response_rx,
cancel_token.clone(),
));
// Watch for status changes
let status_handle = tokio::spawn(handle_status_change(
status_rx,
response_tx.clone(),
@@ -154,7 +157,7 @@ pub(crate) async fn handle_connection(socket: UnixStream, context: Arc<ServerCon
let _ = tokio::join!(read_handle, write_handle, status_handle);
println!("Connection closed")
debug!("Client connection closed");
}
fn peer_pid(socket: &UnixStream) -> Option<i32> {
@@ -164,9 +167,10 @@ fn peer_pid(socket: &UnixStream) -> Option<i32> {
}
}
// TODO - Implement authentication
fn authenticate(peer_pid: Option<i32>) -> bool {
if let Some(pid) = peer_pid {
println!("Peer PID: {}", pid);
info!("Peer PID: {}", pid);
true
} else {
false

16
common/src/server.rs
View File

@@ -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?;
},
}

26
common/src/vpn/ffi.rs
View File

@@ -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);
}
}

20
common/src/vpn/mod.rs
View File

@@ -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;
}
}

45
common/src/vpn/vpn.c
View File

@@ -1,10 +1,9 @@
#include <stdio.h>
#include <openconnect.h>
#include <stdlib.h>
#include <stdarg.h>
#include <time.h>
#include <sys/utsname.h>
#include <unistd.h>
#include <sys/utsname.h>
#include <openconnect.h>
#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");
}
}

62
common/src/vpn/vpn.h
View File

@@ -1,12 +1,62 @@
typedef struct Options {
const char *server;
const char *cookie;
const char *script;
void *user_data;
#include <stdio.h>
#include <stdlib.h>
#include <stdarg.h>
#include <openconnect.h>
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);
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__)