From 159959cc32c341e111a626729fb1bd9a2851e8a7 Mon Sep 17 00:00:00 2001 From: Brian Pearce Date: Tue, 18 Jul 2023 08:45:45 +0200 Subject: [PATCH] feat: chat-ffi logging (#5591) Description --- Adds logging management and capabilities to chat-ffi. Motivation and Context --- Hard to debug when you get no feedback. How Has This Been Tested? --- Locally in cucumber What process can a PR reviewer use to test or verify this change? --- Review Breaking Changes --- - [x] None - [ ] Requires data directory on base node to be deleted - [ ] Requires hard fork - [ ] Other - Please specify --- Cargo.lock | 1 + base_layer/chat_ffi/Cargo.toml | 1 + base_layer/chat_ffi/chat.h | 1 + base_layer/chat_ffi/src/lib.rs | 180 ++++++++++++++++++ .../examples/chat_client/src/config.rs | 10 + integration_tests/src/chat_client.rs | 1 + integration_tests/src/world.rs | 1 + 7 files changed, 195 insertions(+) diff --git a/Cargo.lock b/Cargo.lock index 6b0be99c77..3d7d3681b1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -5243,6 +5243,7 @@ dependencies = [ "cbindgen 0.24.5", "libc", "log", + "log4rs", "openssl", "tari_app_utilities", "tari_chat_client", diff --git a/base_layer/chat_ffi/Cargo.toml b/base_layer/chat_ffi/Cargo.toml index 33c53c7abb..4befe08a9d 100644 --- a/base_layer/chat_ffi/Cargo.toml +++ b/base_layer/chat_ffi/Cargo.toml @@ -17,6 +17,7 @@ tari_shutdown = { path = "../../infrastructure/shutdown" } libc = "0.2.65" log = "0.4.6" +log4rs = { git = "https://github.com/tari-project/log4rs.git", features = ["console_appender", "file_appender", "yaml_format"] } thiserror = "1.0.26" tokio = "1.23" diff --git a/base_layer/chat_ffi/chat.h b/base_layer/chat_ffi/chat.h index 7f39d69f67..b53a03179e 100644 --- a/base_layer/chat_ffi/chat.h +++ b/base_layer/chat_ffi/chat.h @@ -78,6 +78,7 @@ void destroy_client_ffi(struct ClientFFI *client); ApplicationConfig *create_chat_config(const char *network_str, const char *public_address, const char *datastore_path, + const char *log_path, int *error_out); /** diff --git a/base_layer/chat_ffi/src/lib.rs b/base_layer/chat_ffi/src/lib.rs index b77cf6c760..5cd0c2523e 100644 --- a/base_layer/chat_ffi/src/lib.rs +++ b/base_layer/chat_ffi/src/lib.rs @@ -26,6 +26,18 @@ use std::{convert::TryFrom, ffi::CStr, path::PathBuf, ptr, str::FromStr, sync::A use callback_handler::CallbackContactStatusChange; use libc::{c_char, c_int}; +use log::{debug, info, warn, LevelFilter}; +use log4rs::{ + append::{ + rolling_file::{ + policy::compound::{roll::fixed_window::FixedWindowRoller, trigger::size::SizeTrigger, CompoundPolicy}, + RollingFileAppender, + }, + Append, + }, + config::{Appender, Config, Logger, Root}, + encode::pattern::PatternEncoder, +}; use tari_app_utilities::identity_management::load_from_json; use tari_chat_client::{ config::{ApplicationConfig, ChatClientConfig}, @@ -49,6 +61,13 @@ use crate::{ mod callback_handler; mod error; +const LOG_TARGET: &str = "chat_ffi"; + +mod consts { + // Import the auto-generated const values from the Manifest and Git + include!(concat!(env!("OUT_DIR"), "/consts.rs")); +} + #[derive(Clone)] pub struct ChatMessages(Vec); @@ -87,6 +106,19 @@ pub unsafe extern "C" fn create_chat_client( return ptr::null_mut(); } + if let Some(log_path) = (*config).clone().chat_client.log_path { + init_logging(log_path, error_out); + + if error > 0 { + return ptr::null_mut(); + } + } + info!( + target: LOG_TARGET, + "Starting Tari Chat FFI version: {}", + consts::APP_VERSION + ); + let mut bad_identity = |e| { error = LibChatError::from(InterfaceError::InvalidArgument(e)).code; ptr::swap(error_out, &mut error as *mut c_int); @@ -172,6 +204,7 @@ pub unsafe extern "C" fn create_chat_config( network_str: *const c_char, public_address: *const c_char, datastore_path: *const c_char, + log_path: *const c_char, error_out: *mut c_int, ) -> *mut ApplicationConfig { let mut error = 0; @@ -246,10 +279,30 @@ pub unsafe extern "C" fn create_chat_config( }, }; + let log_path_string; + if log_path.is_null() { + error = LibChatError::from(InterfaceError::NullError("log_path".to_string())).code; + ptr::swap(error_out, &mut error as *mut c_int); + return ptr::null_mut(); + } else { + match CStr::from_ptr(log_path).to_str() { + Ok(v) => { + log_path_string = v.to_owned(); + }, + _ => { + error = LibChatError::from(InterfaceError::InvalidArgument("log_path".to_string())).code; + ptr::swap(error_out, &mut error as *mut c_int); + return ptr::null_mut(); + }, + } + } + let log_path = PathBuf::from(log_path_string); + let mut chat_client_config = ChatClientConfig::default(); chat_client_config.network = network; chat_client_config.p2p.transport.tcp.listener_address = address.clone(); chat_client_config.p2p.public_addresses = MultiaddrList::from(vec![address]); + chat_client_config.log_path = Some(log_path); chat_client_config.set_base_path(datastore_path); let config = ApplicationConfig { @@ -277,6 +330,133 @@ pub unsafe extern "C" fn destroy_config(config: *mut ApplicationConfig) { } } +/// Inits logging, this function is deliberately not exposed externally in the header +/// +/// ## Arguments +/// `log_path` - Path to where the log will be stored +/// `error_out` - Pointer to an int which will be modified to an error code should one occur, may not be null. Functions +/// as an out parameter. +/// +/// ## Returns +/// `()` - Does not return a value, equivalent to void in C +/// +/// # Safety +/// None +#[allow(clippy::too_many_lines)] +unsafe fn init_logging(log_path: PathBuf, error_out: *mut c_int) { + let mut error = 0; + ptr::swap(error_out, &mut error as *mut c_int); + + let num_rolling_log_files = 2; + let size_per_log_file_bytes: u64 = 10 * 1024 * 1024; + + let path = log_path.to_str().expect("Convert path to string"); + let encoder = PatternEncoder::new("{d(%Y-%m-%d %H:%M:%S.%f)} [{t}] {l:5} {m}{n}"); + + let mut pattern; + let split_str: Vec<&str> = path.split('.').collect(); + if split_str.len() <= 1 { + pattern = format!("{}{}", path, "{}"); + } else { + pattern = split_str[0].to_string(); + for part in split_str.iter().take(split_str.len() - 1).skip(1) { + pattern = format!("{}.{}", pattern, part); + } + + pattern = format!("{}{}", pattern, ".{}."); + pattern = format!("{}{}", pattern, split_str[split_str.len() - 1]); + } + let roller = FixedWindowRoller::builder() + .build(pattern.as_str(), num_rolling_log_files) + .expect("Should be able to create a Roller"); + let size_trigger = SizeTrigger::new(size_per_log_file_bytes); + let policy = CompoundPolicy::new(Box::new(size_trigger), Box::new(roller)); + + let log_appender: Box = Box::new( + RollingFileAppender::builder() + .encoder(Box::new(encoder)) + .append(true) + .build(path, Box::new(policy)) + .expect("Should be able to create an appender"), + ); + + let lconfig = Config::builder() + .appender(Appender::builder().build("logfile", log_appender)) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("comms", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("comms::noise", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("tokio_util", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("tracing", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("chat_ffi::callback_handler", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("chat_ffi", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("contacts", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("p2p", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("yamux", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("dht", LevelFilter::Warn), + ) + .logger( + Logger::builder() + .appender("logfile") + .additive(false) + .build("mio", LevelFilter::Warn), + ) + .build(Root::builder().appender("logfile").build(LevelFilter::Warn)) + .expect("Should be able to create a Config"); + + match log4rs::init_config(lconfig) { + Ok(_) => debug!(target: LOG_TARGET, "Logging started"), + Err(_) => warn!(target: LOG_TARGET, "Logging has already been initialized"), + } +} + /// Sends a message over a client /// /// ## Arguments diff --git a/base_layer/contacts/examples/chat_client/src/config.rs b/base_layer/contacts/examples/chat_client/src/config.rs index 254f7f1de6..ebf533126e 100644 --- a/base_layer/contacts/examples/chat_client/src/config.rs +++ b/base_layer/contacts/examples/chat_client/src/config.rs @@ -91,6 +91,8 @@ pub struct ChatClientConfig { /// Liveness meta data auto ping interval between peers #[serde(with = "serializers::seconds")] pub metadata_auto_ping_interval: Duration, + /// The location of the log path + pub log_path: Option, } impl Default for ChatClientConfig { @@ -117,6 +119,7 @@ impl Default for ChatClientConfig { lmdb_path: PathBuf::from("db"), force_sync_peers: StringList::default(), metadata_auto_ping_interval: Duration::from_secs(30), + log_path: None, } } } @@ -144,6 +147,13 @@ impl ChatClientConfig { if !self.db_file.is_absolute() { self.db_file = self.data_dir.join(self.db_file.as_path()); } + if self.log_path.is_some() && !self.log_path.as_ref().expect("There to be a path").is_absolute() { + self.log_path = Some( + base_path + .as_ref() + .join(self.log_path.as_ref().expect("There to be a path").as_path()), + ); + } self.p2p.set_base_path(base_path); } diff --git a/integration_tests/src/chat_client.rs b/integration_tests/src/chat_client.rs index 2326a1efce..8cb921ac93 100644 --- a/integration_tests/src/chat_client.rs +++ b/integration_tests/src/chat_client.rs @@ -72,6 +72,7 @@ pub fn test_config(address: Multiaddr) -> ApplicationConfig { let mut chat_client_config = ChatClientConfig::default_local_test(); chat_client_config.p2p.transport.tcp.listener_address = address.clone(); chat_client_config.p2p.public_addresses = MultiaddrList::from(vec![address]); + chat_client_config.log_path = Some(PathBuf::from("log/chat_client/chat_client.log")); ApplicationConfig { chat_client: chat_client_config, diff --git a/integration_tests/src/world.rs b/integration_tests/src/world.rs index 30f1208ee8..b2236a5fef 100644 --- a/integration_tests/src/world.rs +++ b/integration_tests/src/world.rs @@ -133,6 +133,7 @@ impl Debug for TariWorld { .field("ffi_wallets", &self.ffi_wallets) .field("wallets", &self.wallets) .field("merge_mining_proxies", &self.merge_mining_proxies) + .field("chat_clients", &self.chat_clients.keys()) .field("transactions", &self.transactions) .field("wallet_addresses", &self.wallet_addresses) .field("utxos", &self.utxos)