Add configurable log level and log file

Before we were dropping all our logs on the floor besides a few printlns
in the code. This uses `simplelogger` to add a log file and have them
print to the console. We also add to the config options for setting the
log file and log level.

Author: benthecarman

Cargo.lock

@@ -18,6 +18,8 @@ rusqlite = { version = "0.31.0", features = ["bundled"] }
 rand = { version = "0.8.5", default-features = false }
 async-trait = { version = "0.1.85", default-features = false }
 toml = { version = "0.8.9", default-features = false, features = ["parse"] }
+simplelog = { version = "0.12.0", default-features = false }
+log = "0.4.28"
 
 # Required for RabittMQ based EventPublisher. Only enabled for `events-rabbitmq` feature.
 lapin = { version = "2.4.0", features = ["rustls"], default-features = false, optional = true }

ldk-server/Cargo.toml

@@ -8,6 +8,9 @@ rest_service_address = "127.0.0.1:3002"       # LDK Server REST address
 [storage.disk]
 dir_path = "/tmp/ldk-server/"                 # Path for LDK and BDK data persistence
 
+[log]
+level = "Debug"                               # Log level (Error, Warn, Info, Debug, Trace)
+file_path = "/tmp/ldk-server/ldk-server.log"  # Log file path
 
 # Must set either bitcoind or esplora settings, but not both
 

ldk-server/ldk-server-config.toml

@@ -32,8 +32,10 @@ use ldk_node::lightning::ln::channelmanager::PaymentId;
 use ldk_server_protos::events;
 use ldk_server_protos::events::{event_envelope, EventEnvelope};
 use ldk_server_protos::types::Payment;
+use log::{error, info};
 use prost::Message;
 use rand::Rng;
+use simplelog::{CombinedLogger, SimpleLogger, WriteLogger};
 use std::fs;
 use std::path::{Path, PathBuf};
 use std::sync::Arc;
@@ -70,6 +72,47 @@ fn main() {
 		},
 	};
 
+	let log_file_path = config_file.log_file_path.map(|p| PathBuf::from(p)).unwrap_or_else(|| {
+		let mut default_log_path = PathBuf::from(&config_file.storage_dir_path);
+		default_log_path.push("ldk-server.log");
+		PathBuf::from(default_log_path)
+	});
+	let log_file = if log_file_path.exists() {
+		match fs::File::options().append(true).open(log_file_path) {
+			Ok(file) => file,
+			Err(e) => {
+				eprintln!("Could not open log file: {}", e);
+				std::process::exit(-1);
+			},
+		}
+	} else {
+		// make parents if they don't exist
+		if let Some(parent) = log_file_path.parent() {
+			if let Err(e) = fs::create_dir_all(parent) {
+				eprintln!("Could not create log file directory: {}", e);
+				std::process::exit(-1);
+			}
+		}
+		match fs::File::create(log_file_path) {
+			Ok(file) => file,
+			Err(e) => {
+				eprintln!("Could not create log file: {}", e);
+				std::process::exit(-1);
+			},
+		}
+	};
+
+	let log_config = simplelog::ConfigBuilder::new().set_time_format_rfc3339().build();
+	if let Err(e) = CombinedLogger::init(vec![
+		// add simple logger for console output
+		SimpleLogger::new(config_file.log_level, log_config.clone()),
+		// add write logger for file output
+		WriteLogger::new(config_file.log_level, log_config, log_file),
+	]) {
+		eprintln!("Failed to initialize logger: {}", e);
+		std::process::exit(-1);
+	}
+
 	ldk_node_config.storage_dir_path = config_file.storage_dir_path.clone();
 	ldk_node_config.listening_addresses = Some(vec![config_file.listening_addr]);
 	ldk_node_config.network = config_file.network;
@@ -142,7 +185,7 @@ fn main() {
 		Arc::new(RabbitMqEventPublisher::new(rabbitmq_config))
 	};
 
-	println!("Starting up...");
+	info!("Starting up...");
 	match node.start() {
 		Ok(()) => {},
 		Err(e) => {
@@ -151,7 +194,7 @@ fn main() {
 		},
 	}
 
-	println!(
+	info!(
 		"CONNECTION_STRING: {}@{}",
 		node.node_id(),
 		node.config().listening_addresses.as_ref().unwrap().first().unwrap()
@@ -161,7 +204,7 @@ fn main() {
 		let mut sigterm_stream = match tokio::signal::unix::signal(SignalKind::terminate()) {
 			Ok(stream) => stream,
 			Err(e) => {
-				println!("Failed to register for SIGTERM stream: {}", e);
+				eprintln!("Failed to register for SIGTERM stream: {}", e);
 				std::process::exit(-1);
 			}
 		};
@@ -174,25 +217,25 @@ fn main() {
 				event = event_node.next_event_async() => {
 					match event {
 						Event::ChannelPending { channel_id, counterparty_node_id, .. } => {
-							println!(
+							info!(
 								"CHANNEL_PENDING: {} from counterparty {}",
 								channel_id, counterparty_node_id
 							);
 							if let Err(e) = event_node.event_handled() {
-								eprintln!("Failed to mark event as handled: {e}");
+								error!("Failed to mark event as handled: {e}");
 							}
 						},
 						Event::ChannelReady { channel_id, counterparty_node_id, .. } => {
-							println!(
+							info!(
 								"CHANNEL_READY: {} from counterparty {:?}",
 								channel_id, counterparty_node_id
 							);
 							if let Err(e) = event_node.event_handled() {
-								eprintln!("Failed to mark event as handled: {e}");
+								error!("Failed to mark event as handled: {e}");
 							}
 						},
 						Event::PaymentReceived { payment_id, payment_hash, amount_msat, .. } => {
-							println!(
+							info!(
 								"PAYMENT_RECEIVED: with id {:?}, hash {}, amount_msat {}",
 								payment_id, payment_hash, amount_msat
 							);
@@ -233,7 +276,7 @@ fn main() {
 								let payment = payment_to_proto(payment_details);
 								upsert_payment_details(&event_node, Arc::clone(&paginated_store), &payment);
 							} else {
-								eprintln!("Unable to find payment with paymentId: {}", payment_id.to_string());
+								error!("Unable to find payment with paymentId: {}", payment_id.to_string());
 							}
 						},
 						Event::PaymentForwarded {
@@ -249,7 +292,7 @@ fn main() {
 							outbound_amount_forwarded_msat
 						} => {
 
-							println!("PAYMENT_FORWARDED: with outbound_amount_forwarded_msat {}, total_fee_earned_msat: {}, inbound channel: {}, outbound channel: {}",
+							info!("PAYMENT_FORWARDED: with outbound_amount_forwarded_msat {}, total_fee_earned_msat: {}, inbound channel: {}, outbound channel: {}",
 								outbound_amount_forwarded_msat.unwrap_or(0), total_fee_earned_msat.unwrap_or(0), prev_channel_id, next_channel_id
 							);
 
@@ -281,7 +324,7 @@ fn main() {
 							}).await {
 								Ok(_) => {},
 								Err(e) => {
-									println!("Failed to publish 'PaymentForwarded' event: {}", e);
+									error!("Failed to publish 'PaymentForwarded' event: {}", e);
 									continue;
 								}
 							};
@@ -293,17 +336,17 @@ fn main() {
 							) {
 								Ok(_) => {
 									if let Err(e) = event_node.event_handled() {
-										eprintln!("Failed to mark event as handled: {e}");
+										error!("Failed to mark event as handled: {e}");
 									}
 								}
 								Err(e) => {
-										println!("Failed to write forwarded payment to persistence: {}", e);
+										error!("Failed to write forwarded payment to persistence: {}", e);
 								}
 							}
 						},
 						_ => {
 							if let Err(e) = event_node.event_handled() {
-								eprintln!("Failed to mark event as handled: {e}");
+								error!("Failed to mark event as handled: {e}");
 							}
 						},
 					}
@@ -315,27 +358,27 @@ fn main() {
 							let node_service = NodeService::new(Arc::clone(&node), Arc::clone(&paginated_store));
 							runtime.spawn(async move {
 								if let Err(err) = http1::Builder::new().serve_connection(io_stream, node_service).await {
-									eprintln!("Failed to serve connection: {}", err);
+									error!("Failed to serve connection: {}", err);
 								}
 							});
 						},
-						Err(e) => eprintln!("Failed to accept connection: {}", e),
+						Err(e) => error!("Failed to accept connection: {}", e),
 					}
 				}
 				_ = tokio::signal::ctrl_c() => {
-					println!("Received CTRL-C, shutting down..");
+					info!("Received CTRL-C, shutting down..");
 					break;
 				}
 				_ = sigterm_stream.recv() => {
-					println!("Received SIGTERM, shutting down..");
+					info!("Received SIGTERM, shutting down..");
 					break;
 				}
 			}
 		}
 	});
 
 	node.stop().expect("Shutdown should always succeed.");
-	println!("Shutdown complete..");
+	info!("Shutdown complete..");
 }
 
 async fn publish_event_and_upsert_payment(
@@ -351,14 +394,14 @@ async fn publish_event_and_upsert_payment(
 		match event_publisher.publish(EventEnvelope { event: Some(event) }).await {
 			Ok(_) => {},
 			Err(e) => {
-				println!("Failed to publish '{}' event, : {}", event_name, e);
+				error!("Failed to publish '{event_name}' event, : {e}");
 				return;
 			},
 		};
 
 		upsert_payment_details(event_node, Arc::clone(&paginated_store), &payment);
 	} else {
-		eprintln!("Unable to find payment with paymentId: {}", payment_id);
+		error!("Unable to find payment with paymentId: {payment_id}");
 	}
 }
 
@@ -377,11 +420,11 @@ fn upsert_payment_details(
 	) {
 		Ok(_) => {
 			if let Err(e) = event_node.event_handled() {
-				eprintln!("Failed to mark event as handled: {e}");
+				error!("Failed to mark event as handled: {e}");
 			}
 		},
 		Err(e) => {
-			eprintln!("Failed to write payment to persistence: {}", e);
+			error!("Failed to write payment to persistence: {e}");
 		},
 	}
 }

ldk-server/src/main.rs

@@ -3,6 +3,7 @@ use ldk_node::lightning::ln::msgs::SocketAddress;
 use ldk_node::lightning::routing::gossip::NodeAlias;
 use ldk_node::liquidity::LSPS2ServiceConfig;
 use serde::{Deserialize, Serialize};
+use simplelog::LevelFilter;
 use std::net::SocketAddr;
 use std::path::Path;
 use std::str::FromStr;
@@ -20,6 +21,8 @@ pub struct Config {
 	pub rabbitmq_connection_string: String,
 	pub rabbitmq_exchange_name: String,
 	pub lsps2_service_config: Option<LSPS2ServiceConfig>,
+	pub log_level: LevelFilter,
+	pub log_file_path: Option<String>,
 }
 
 #[derive(Debug)]
@@ -86,6 +89,21 @@ impl TryFrom<TomlConfig> for Config {
 			None
 		};
 
+		let log_level = toml_config
+			.log
+			.as_ref()
+			.and_then(|log_config| log_config.level.as_ref())
+			.map(|level_str| {
+				LevelFilter::from_str(level_str).map_err(|e| {
+					io::Error::new(
+						io::ErrorKind::InvalidInput,
+						format!("Invalid log level configured: {}", e),
+					)
+				})
+			})
+			.transpose()?
+			.unwrap_or(LevelFilter::Debug);
+
 		let (rabbitmq_connection_string, rabbitmq_exchange_name) = {
 			let rabbitmq = toml_config.rabbitmq.unwrap_or(RabbitmqConfig {
 				connection_string: String::new(),
@@ -122,6 +140,8 @@ impl TryFrom<TomlConfig> for Config {
 			rabbitmq_connection_string,
 			rabbitmq_exchange_name,
 			lsps2_service_config,
+			log_level,
+			log_file_path: toml_config.log.and_then(|l| l.file),
 		})
 	}
 }
@@ -135,6 +155,7 @@ pub struct TomlConfig {
 	esplora: Option<EsploraConfig>,
 	rabbitmq: Option<RabbitmqConfig>,
 	liquidity: Option<LiquidityConfig>,
+	log: Option<LogConfig>,
 }
 
 #[derive(Deserialize, Serialize)]
@@ -167,6 +188,12 @@ struct EsploraConfig {
 	server_url: String,
 }
 
+#[derive(Deserialize, Serialize)]
+struct LogConfig {
+	level: Option<String>,
+	file: Option<String>,
+}
+
 #[derive(Deserialize, Serialize)]
 struct RabbitmqConfig {
 	connection_string: String,
@@ -260,6 +287,10 @@ mod tests {
 			
 			[storage.disk]
 			dir_path = "/tmp"
+
+			[log]
+			level = "Trace"
+			file = "/var/log/ldk-server.log"
 			
 			[esplora]
 			server_url = "https://mempool.space/api"
@@ -310,6 +341,8 @@ mod tests {
 				max_payment_size_msat: 25000000000,
 				client_trusts_lsp: true,
 			}),
+			log_level: LevelFilter::Trace,
+			log_file_path: Some("/var/log/ldk-server.log".to_string()),
 		};
 
 		assert_eq!(config.listening_addr, expected.listening_addr);
@@ -339,6 +372,10 @@ mod tests {
 			
 			[storage.disk]
 			dir_path = "/tmp"
+
+			[log]
+			level = "Trace"
+			file = "/var/log/ldk-server.log"
 			
 			[bitcoind]
 			rpc_address = "127.0.0.1:8332"    # RPC endpoint
@@ -383,6 +420,10 @@ mod tests {
 			
 			[storage.disk]
 			dir_path = "/tmp"
+
+			[log]
+			level = "Trace"
+			file = "/var/log/ldk-server.log"
 			
 			[bitcoind]
 			rpc_address = "127.0.0.1:8332"    # RPC endpoint