Merge pull request #87 from tankyleo/26-01-logging

Add logger for VSS

Author: tnull

.github/workflows/build-and-deploy-rust.yml

@@ -38,17 +38,17 @@ jobs:
       - name: Build and Deploy VSS Server
         run: |
           cd rust
-          cargo build
-          cargo run server/vss-server-config.toml&
+          RUSTFLAGS="--cfg noop_authorizer" cargo build --no-default-features
+          ./target/debug/vss-server server/vss-server-config.toml&
 
       - name: Hit endpoint to verify service is up
         run: |
           sleep 5
 
           # Put request with store='storeId' and key=k1
           hex=0A0773746F726549641A150A026B3110FFFFFFFFFFFFFFFFFF011A046B317631
-          curl --data-binary "$(echo "$hex" | xxd -r -p)" http://localhost:8080/vss/putObjects
+          curl -f --data-binary "$(echo "$hex" | xxd -r -p)" http://localhost:8080/vss/putObjects
 
           # Get request with store='storeId' and key=k1
           hex=0A0773746F7265496412026B31
-          curl --data-binary "$(echo "$hex" | xxd -r -p)" http://localhost:8080/vss/getObject
+          curl -f --data-binary "$(echo "$hex" | xxd -r -p)" http://localhost:8080/vss/getObject

.github/workflows/ldk-node-integration.yml

@@ -44,8 +44,8 @@ jobs:
       - name: Build and Deploy VSS Server
         run: |
           cd vss-server/rust
-          cargo build
-          cargo run --no-default-features server/vss-server-config.toml&
+          RUSTFLAGS="--cfg noop_authorizer" cargo build --no-default-features
+          ./target/debug/vss-server server/vss-server-config.toml&
       - name: Run LDK Node Integration tests
         run: |
           cd ldk-node

rust/Cargo.toml

@@ -13,3 +13,7 @@ lto = true
 
 [profile.dev]
 panic = "abort"
+
+[workspace.lints.rust.unexpected_cfgs]
+level = "forbid"
+check-cfg = ['cfg(noop_authorizer)']

rust/api/src/auth.rs

@@ -1,7 +1,6 @@
 use crate::error::VssError;
 use async_trait::async_trait;
 use std::collections::HashMap;
-use std::string::ToString;
 
 /// Response returned for [`Authorizer`] request if user is authenticated and authorized.
 #[derive(Debug, Clone)]
@@ -21,10 +20,13 @@ pub trait Authorizer: Send + Sync {
 }
 
 /// A no-operation authorizer, which lets any user-request go through.
+#[cfg(feature = "_test_utils")]
 pub struct NoopAuthorizer {}
 
+#[cfg(feature = "_test_utils")]
 const UNAUTHENTICATED_USER: &str = "unauth-user";
 
+#[cfg(feature = "_test_utils")]
 #[async_trait]
 impl Authorizer for NoopAuthorizer {
 	async fn verify(

rust/impls/Cargo.toml

@@ -13,6 +13,7 @@ bytes = "1.4.0"
 tokio = { version = "1.38.0", default-features = false, features = ["rt", "macros"] }
 native-tls = { version = "0.2.14", default-features = false }
 postgres-native-tls = { version = "0.5.2", default-features = false, features = ["runtime"] }
+log = { version = "0.4.29", default-features = false }
 
 [dev-dependencies]
 tokio = { version = "1.38.0", default-features = false, features = ["rt-multi-thread", "macros"] }

rust/impls/src/postgres_store.rs

@@ -17,6 +17,8 @@ use tokio::sync::Mutex;
 use tokio_postgres::tls::{MakeTlsConnect, TlsConnect};
 use tokio_postgres::{error, Client, NoTls, Socket, Transaction};
 
+use log::{debug, info, warn};
+
 pub use native_tls::Certificate;
 
 pub(crate) struct VssDbRecord {
@@ -104,6 +106,7 @@ where
 
 	async fn ensure_connected(&self, client: &mut Client) -> Result<(), Error> {
 		if client.is_closed() || client.check_connection().await.is_err() {
+			debug!("Rotating connection to the postgres database");
 			let new_client =
 				make_db_connection(&self.endpoint, &self.db_name, self.tls.clone()).await?;
 			*client = new_client;
@@ -145,7 +148,7 @@ where
 	// Connection must be driven on a separate task, and will resolve when the client is dropped
 	tokio::spawn(async move {
 		if let Err(e) = connection.await {
-			eprintln!("Connection error: {}", e);
+			warn!("Connection error: {}", e);
 		}
 	});
 	Ok(client)
@@ -173,7 +176,7 @@ where
 		client.execute(&stmt, &[]).await.map_err(|e| {
 			Error::new(ErrorKind::Other, format!("Failed to create database {}: {}", db_name, e))
 		})?;
-		println!("Created database {}", db_name);
+		info!("Created database {}", db_name);
 	}
 
 	Ok(())
@@ -291,7 +294,7 @@ where
 			panic!("We do not allow downgrades");
 		}
 
-		println!("Applying migration(s) {} through {}", migration_start, migrations.len() - 1);
+		info!("Applying migration(s) {} through {}", migration_start, migrations.len() - 1);
 
 		for (idx, &stmt) in (&migrations[migration_start..]).iter().enumerate() {
 			let _num_rows = tx.execute(stmt, &[]).await.map_err(|e| {

rust/server/Cargo.toml

@@ -22,3 +22,12 @@ prost = { version = "0.11.6", default-features = false, features = ["std"] }
 bytes = "1.4.0"
 serde = { version = "1.0.203", default-features = false, features = ["derive"] }
 toml = { version = "0.8.9", default-features = false, features = ["parse"] }
+log = { version = "0.4.29", default-features = false, features = ["std"] }
+chrono = { version = "0.4", default-features = false, features = ["clock"] }
+rand = { version = "0.9.2", default-features = false }
+
+[target.'cfg(noop_authorizer)'.dependencies]
+api = { path = "../api", features = ["_test_utils"] }
+
+[lints]
+workspace = true

rust/server/src/main.rs

@@ -17,13 +17,18 @@ use tokio::signal::unix::SignalKind;
 use hyper::server::conn::http1;
 use hyper_util::rt::TokioIo;
 
-use api::auth::{Authorizer, NoopAuthorizer};
+use log::{error, info, warn};
+
+use api::auth::Authorizer;
+#[cfg(noop_authorizer)]
+use api::auth::NoopAuthorizer;
 use api::kv_store::KvStore;
 #[cfg(feature = "jwt")]
 use auth_impls::jwt::JWTAuthorizer;
 #[cfg(feature = "sigs")]
 use auth_impls::signature::SignatureValidatingAuthorizer;
 use impls::postgres_store::{PostgresPlaintextBackend, PostgresTlsBackend};
+use util::logger::ServerLogger;
 use vss_service::VssService;
 
 mod util;
@@ -38,19 +43,36 @@ fn main() {
 			std::process::exit(-1);
 		});
 
+	let logger = match ServerLogger::init(config.log_level, &config.log_file) {
+		Ok(logger) => logger,
+		Err(e) => {
+			eprintln!("Failed to initialize logger: {e}");
+			std::process::exit(-1);
+		},
+	};
+
 	let runtime = match tokio::runtime::Builder::new_multi_thread().enable_all().build() {
 		Ok(runtime) => Arc::new(runtime),
 		Err(e) => {
-			eprintln!("Failed to setup tokio runtime: {}", e);
+			error!("Failed to setup tokio runtime: {}", e);
 			std::process::exit(-1);
 		},
 	};
 
 	runtime.block_on(async {
+		// Register SIGHUP handler for log rotation
+		let mut sighup_stream = match tokio::signal::unix::signal(SignalKind::hangup()) {
+			Ok(stream) => stream,
+			Err(e) => {
+				error!("Failed to register SIGHUP handler: {e}");
+				std::process::exit(-1);
+			}
+		};
+
 		let mut sigterm_stream = match tokio::signal::unix::signal(SignalKind::terminate()) {
 			Ok(stream) => stream,
 			Err(e) => {
-				println!("Failed to register for SIGTERM stream: {}", e);
+				error!("Failed to register for SIGTERM stream: {}", e);
 				std::process::exit(-1);
 			},
 		};
@@ -61,11 +83,11 @@ fn main() {
 			if let Some(rsa_pem) = config.rsa_pem {
 				authorizer = match JWTAuthorizer::new(&rsa_pem).await {
 					Ok(auth) => {
-						println!("Configured JWT authorizer with RSA public key");
+						info!("Configured JWT authorizer with RSA public key");
 						Some(Arc::new(auth))
 					},
 					Err(e) => {
-						println!("Failed to configure JWT authorizer: {}", e);
+						error!("Failed to configure JWT authorizer: {}", e);
 						std::process::exit(-1);
 					},
 				};
@@ -74,17 +96,25 @@ fn main() {
 		#[cfg(feature = "sigs")]
 		{
 			if authorizer.is_none() {
-				println!("Configured signature-validating authorizer");
+				info!("Configured signature-validating authorizer");
 				authorizer = Some(Arc::new(SignatureValidatingAuthorizer));
 			}
 		}
+
+		#[cfg(noop_authorizer)]
 		let authorizer = if let Some(auth) = authorizer {
 			auth
 		} else {
-			println!("No authentication method configured, all storage with the same store id will be commingled.");
+			warn!("No authentication method configured, all storage with the same store id will be commingled.");
 			Arc::new(NoopAuthorizer {})
 		};
 
+		#[cfg(not(noop_authorizer))]
+		let authorizer = authorizer.unwrap_or_else(||  {
+			error!("No authentication method configured, please configure either `JWTAuthorizer` or `SignatureValidatingAuthorizer`");
+			std::process::exit(-1);
+		});
+
 		let store: Arc<dyn KvStore> = if let Some(crt_pem) = config.tls_config {
 			let postgres_tls_backend = PostgresTlsBackend::new(
 				&config.postgresql_prefix,
@@ -94,10 +124,10 @@ fn main() {
 			)
 			.await
 			.unwrap_or_else(|e| {
-				println!("Failed to start postgres TLS backend: {}", e);
+				error!("Failed to start postgres TLS backend: {}", e);
 				std::process::exit(-1);
 			});
-			println!(
+			info!(
 				"Connected to PostgreSQL TLS backend with DSN: {}/{}",
 				config.postgresql_prefix, config.vss_db
 			);
@@ -110,21 +140,21 @@ fn main() {
 			)
 			.await
 			.unwrap_or_else(|e| {
-				println!("Failed to start postgres plaintext backend: {}", e);
+				error!("Failed to start postgres plaintext backend: {}", e);
 				std::process::exit(-1);
 			});
-			println!(
+			info!(
 				"Connected to PostgreSQL plaintext backend with DSN: {}/{}",
 				config.postgresql_prefix, config.vss_db
 			);
 			Arc::new(postgres_plaintext_backend)
 		};
 
 		let rest_svc_listener = TcpListener::bind(&config.bind_address).await.unwrap_or_else(|e| {
-			println!("Failed to bind listening port: {}", e);
+			error!("Failed to bind listening port: {}", e);
 			std::process::exit(-1);
 		});
-		println!("Listening for incoming connections on {}{}", config.bind_address, crate::vss_service::BASE_PATH_PREFIX);
+		info!("Listening for incoming connections on {}{}", config.bind_address, crate::vss_service::BASE_PATH_PREFIX);
 
 		loop {
 			tokio::select! {
@@ -135,19 +165,24 @@ fn main() {
 							let vss_service = VssService::new(Arc::clone(&store), Arc::clone(&authorizer));
 							runtime.spawn(async move {
 								if let Err(err) = http1::Builder::new().serve_connection(io_stream, vss_service).await {
-									eprintln!("Failed to serve connection: {}", err);
+									warn!("Failed to serve connection: {}", err);
 								}
 							});
 						},
-						Err(e) => eprintln!("Failed to accept connection: {}", e),
+						Err(e) => warn!("Failed to accept connection: {}", e),
 					}
 				}
 				_ = tokio::signal::ctrl_c() => {
-					println!("Received CTRL-C, shutting down..");
+					info!("Received CTRL-C, shutting down..");
 					break;
 				}
+				_ = sighup_stream.recv() => {
+					if let Err(e) = logger.reopen() {
+						error!("Failed to reopen log file on SIGHUP: {e}");
+					}
+				}
 				_ = sigterm_stream.recv() => {
-					println!("Received SIGTERM, shutting down..");
+					info!("Received SIGTERM, shutting down..");
 					break;
 				}
 			}