From 3fbf64e5f6e98a76f11b8b219cb11d5cd6ad0ddf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Thomas=20Pr=C3=A9vost?= Date: Wed, 21 Feb 2024 11:40:23 +0100 Subject: [PATCH] Add datetime and KME's nickname to web logging --- Cargo.toml | 4 +- config_kme1.json | 1 + src/config/mod.rs | 3 + src/qkd_manager/config_extractor.rs | 8 +- src/qkd_manager/key_handler.rs | 78 ++++++++++++++----- src/qkd_manager/mod.rs | 70 +++++++++++++---- src/routes/request_context.rs | 4 +- src/server/log_http_server/index.html | 2 +- src/server/log_http_server/logging_message.rs | 40 ++++++++++ src/server/log_http_server/mod.rs | 18 +++-- tests/common/mod.rs | 14 ++-- tests/config_parsing.rs | 17 ++-- tests/data/test_kme_config.json | 1 + 13 files changed, 202 insertions(+), 58 deletions(-) create mode 100644 src/server/log_http_server/logging_message.rs diff --git a/Cargo.toml b/Cargo.toml index 90e60e8..be5a427 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -32,9 +32,11 @@ notify = "6.1.1" reqwest = { version = "0.11.24" , features = ["native-tls", "blocking", "json"] } futures = "0.3.30" url = "2.5.0" +chrono = "0.4.34" [dev-dependencies] assert_cmd = "2.0.13" reqwest = {version = "0.11.24", features = ["native-tls"]} serial_test = "3.0.0" -const_format = "0.2.32" \ No newline at end of file +const_format = "0.2.32" +regex = "1.10.3" \ No newline at end of file diff --git a/config_kme1.json b/config_kme1.json index 39c45cc..e511c7b 100644 --- a/config_kme1.json +++ b/config_kme1.json @@ -1,6 +1,7 @@ { "this_kme": { "id": 1, + "nickname": "Alice", "sqlite_db_path": ":memory:", "key_directory_to_watch": "raw_keys/kme-1-1", "saes_https_interface": { diff --git a/src/config/mod.rs b/src/config/mod.rs index 5784fbd..c881f06 100644 --- a/src/config/mod.rs +++ b/src/config/mod.rs @@ -37,6 +37,8 @@ impl Config { pub struct ThisKmeConfig { /// ID of this KME, in the QKD network pub(crate) id: KmeId, + /// Optional nickname for this KME, used for debugging purposes (eg "Alice" or "Bob") + pub(crate) nickname: Option, /// Path to SQLite database file, used to store keys, certificates and other data /// You can use `:memory:` to use in-memory database pub(crate) sqlite_db_path: String, @@ -116,6 +118,7 @@ mod tests { let config = Config::from_json_path(JSON_CONFIG_PATH).unwrap(); assert_eq!(config.this_kme_config.id, 1); assert_eq!(config.this_kme_config.sqlite_db_path, ":memory:"); + assert_eq!(config.this_kme_config.nickname, Some("Alice".to_string())); assert_eq!(config.this_kme_config.key_directory_to_watch, "tests/data/raw_keys/kme-1-1"); assert_eq!(config.this_kme_config.saes_https_interface.listen_address, "127.0.0.1:3000"); assert_eq!(config.this_kme_config.saes_https_interface.ca_client_cert_path, "certs/zone1/CA-zone1.crt"); diff --git a/src/qkd_manager/config_extractor.rs b/src/qkd_manager/config_extractor.rs index 7568b45..a024030 100644 --- a/src/qkd_manager/config_extractor.rs +++ b/src/qkd_manager/config_extractor.rs @@ -13,7 +13,7 @@ pub(super) struct ConfigExtractor {} impl ConfigExtractor { pub(super) fn extract_config_to_qkd_manager(config: &Config) -> Result, io::Error> { - let qkd_manager = Arc::new(QkdManager::new(&config.this_kme_config.sqlite_db_path, config.this_kme_config.id)); + let qkd_manager = Arc::new(QkdManager::new(&config.this_kme_config.sqlite_db_path, config.this_kme_config.id, &config.this_kme_config.nickname)); Self::extract_all_saes(Arc::clone(&qkd_manager), config)?; Self::extract_other_kmes_and_keys(Arc::clone(&qkd_manager), config)?; Self::add_classical_net_routing_info_kmes(Arc::clone(&qkd_manager), config)?; @@ -181,14 +181,14 @@ mod tests { #[test] fn test_extract_all_keys_from_dir() { - let qkd_manager = Arc::new(crate::qkd_manager::QkdManager::new(":memory:", 1)); + let qkd_manager = Arc::new(crate::qkd_manager::QkdManager::new(":memory:", 1, &None)); assert!(ConfigExtractor::extract_all_keys_from_dir(Arc::clone(&qkd_manager), "raw_keys/kme-1-1", 1).is_ok()); assert!(ConfigExtractor::extract_all_keys_from_dir(qkd_manager, "unexisting/directory", 1).is_err()); } #[test] fn test_extract_all_keys_from_file() { - let qkd_manager = Arc::new(crate::qkd_manager::QkdManager::new(":memory:", 1)); + let qkd_manager = Arc::new(crate::qkd_manager::QkdManager::new(":memory:", 1, &None)); assert!(ConfigExtractor::extract_all_keys_from_file(Arc::clone(&qkd_manager), "raw_keys/", 1).is_err()); assert!(ConfigExtractor::extract_all_keys_from_file(Arc::clone(&qkd_manager), "path/to/unexisting/file", 1).is_err()); assert!(ConfigExtractor::extract_all_keys_from_file(Arc::clone(&qkd_manager), "raw_keys/kme-1-1/211202_1159_CD6ADBF2.cor", 1).is_ok()); @@ -196,7 +196,7 @@ mod tests { #[test] fn test_extract_and_watch_raw_keys_dir() { - let qkd_manager = Arc::new(crate::qkd_manager::QkdManager::new(":memory:", 1)); + let qkd_manager = Arc::new(crate::qkd_manager::QkdManager::new(":memory:", 1, &None)); assert!(ConfigExtractor::extract_and_watch_raw_keys_dir(Arc::clone(&qkd_manager), 1, "raw_keys/kme-1-1").is_ok()); assert!(ConfigExtractor::extract_and_watch_raw_keys_dir(Arc::clone(&qkd_manager), 1, "unexisting/directory").is_err()); } diff --git a/src/qkd_manager/key_handler.rs b/src/qkd_manager/key_handler.rs index f3f3f24..dd0ac4b 100644 --- a/src/qkd_manager/key_handler.rs +++ b/src/qkd_manager/key_handler.rs @@ -28,6 +28,8 @@ pub(super) struct KeyHandler { qkd_router: router::QkdRouter, /// Subscribers to important events, for demonstration purpose event_notification_subscribers: Vec>, + /// Optional nickname for this KME, used for debugging purposes (eg "Alice" or "Bob") + nickname: Option, } impl KeyHandler { @@ -37,11 +39,13 @@ impl KeyHandler { /// * `sqlite_db_path` - The path to the sqlite database file, or ":memory:" to use an in-memory database /// * `command_rx` - The channel to receive commands from the QKD manager (main thread) /// * `response_tx` - The channel to send responses to the QKD manager (main thread) + /// * `this_kme_id` - The ID of this KME + /// * `kme_nickname` - The nickname of this KME, for debugging purposes /// # Returns /// A new key handler /// # Errors /// If the sqlite database cannot be opened or if the tables cannot be created - pub(super) fn new(sqlite_db_path: &str, command_rx: crossbeam_channel::Receiver, response_tx: crossbeam_channel::Sender, this_kme_id: KmeId) -> Result { + pub(super) fn new(sqlite_db_path: &str, command_rx: crossbeam_channel::Receiver, response_tx: crossbeam_channel::Sender, this_kme_id: KmeId, kme_nickname: Option) -> Result { const DATABASE_INIT_REQ: &'static str = include_str!("init_qkd_database.sql"); let key_handler = Self { @@ -54,6 +58,7 @@ impl KeyHandler { this_kme_id, qkd_router: router::QkdRouter::new(), event_notification_subscribers: vec![], + nickname: kme_nickname, }; // Create the tables if they do not exist key_handler.sqlite_db.execute(DATABASE_INIT_REQ).map_err(|e| { @@ -275,7 +280,7 @@ impl KeyHandler { let origin_kme_id = self.this_kme_id; let target_kme_id = self.get_kme_id_from_sae_id(target_sae_id).ok_or(QkdManagerResponse::NotFound)?; - export_important_logging_message!(&self, &format!("[KME {}] SAE {} requested a key to communicate with {}", self.this_kme_id, origin_sae_id, target_sae_id)); + export_important_logging_message!(&self, &format!("SAE {} requested a key to communicate with {}", origin_sae_id, target_sae_id)); let mut stmt = ensure_prepared_statement_ok!(self.sqlite_db, FETCH_PREINIT_KEY_PREPARED_STATEMENT); stmt.bind((1, target_kme_id)).map_err(|_| { @@ -312,7 +317,7 @@ impl KeyHandler { error!("Error activating key on other KME"); qkd_manager_activation_error })?; - export_important_logging_message!(&self, &format!("[KME {}] As SAE {} belongs to KME {}, activating it through inter KMEs network", self.this_kme_id, target_sae_id, target_kme_id)); + export_important_logging_message!(&self, &format!("As SAE {} belongs to KME {}, activating it through inter KMEs network", target_sae_id, target_kme_id)); } self.delete_pre_init_key_with_id(id).map_err(|_| { @@ -463,7 +468,7 @@ impl KeyHandler { error!("Error executing SQL statement"); QkdManagerResponse::Ko })?; - export_important_logging_message!(&self, &format!("[KME {}] Key {} activated between SAEs {} and {}", self.this_kme_id, key_uuid, origin_sae_id, target_sae_id)); + export_important_logging_message!(&self, &format!("Key {} activated between SAEs {} and {}", key_uuid, origin_sae_id, target_sae_id)); Ok(QkdManagerResponse::Ok) } @@ -532,7 +537,7 @@ impl KeyHandler { QkdManagerResponse::Ko })?; - export_important_logging_message!(&self, &format!("[KME {}] SAE {} requested key {} (from {})", self.this_kme_id, current_sae_id, key_uuid, origin_sae_id)); + export_important_logging_message!(&self, &format!("SAE {} requested key {} (from {})", current_sae_id, key_uuid, origin_sae_id)); // Encode the key in base64 Ok(ResponseQkdKey { @@ -669,9 +674,14 @@ macro_rules! ensure_prepared_statement_ok { #[macro_export] macro_rules! export_important_logging_message { ($key_handler_reference:expr, $message:expr) => { + let displayed_producer = match $key_handler_reference.nickname { + Some(ref nickname) => nickname.to_owned(), + None => std::string::String::from(&format!("KME {}", $key_handler_reference.this_kme_id)), + }; + let message = &format!("[{}] {}", displayed_producer, $message); info!("{}", $message); for subscriber in $key_handler_reference.event_notification_subscribers.iter() { - let _ = subscriber.notify($message); // We ignore the result here + let _ = subscriber.notify(message); // We ignore the result here } } } @@ -709,7 +719,7 @@ mod tests { fn test_get_sae_id_from_certificate() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let sae_id = 1; let kme_id = 1; let sae_certificate_serial = vec![0u8; CLIENT_CERT_SERIAL_SIZE_BYTES]; @@ -724,7 +734,7 @@ mod tests { fn test_add_preinit_key() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let key = crate::qkd_manager::PreInitQkdKeyWrapper { other_kme_id: 1, key_uuid: *uuid::Uuid::from_bytes([0u8; 16]).as_bytes(), @@ -737,7 +747,7 @@ mod tests { fn test_get_sae_status() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let sae_id = 1; let sae_certificate_serial = vec![0u8; CLIENT_CERT_SERIAL_SIZE_BYTES]; key_handler.add_sae(sae_id, 1, &Some(sae_certificate_serial.clone())).unwrap(); @@ -795,7 +805,7 @@ mod tests { fn test_get_sae_keys() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let sae_id = 1; let kme_id = 1; let sae_certificate_serial = vec![0u8; CLIENT_CERT_SERIAL_SIZE_BYTES]; @@ -857,7 +867,7 @@ mod tests { fn test_get_sae_keys_with_ids() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let sae_id = 1; let kme_id = 1; let sae_1_certificate_serial = vec![0u8; CLIENT_CERT_SERIAL_SIZE_BYTES]; @@ -902,7 +912,7 @@ mod tests { fn test_get_kme_id_from_sae() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let sae_id = 1; let kme_id = 1; let sae_1_certificate_serial = vec![0u8; CLIENT_CERT_SERIAL_SIZE_BYTES]; @@ -917,7 +927,7 @@ mod tests { fn test_get_sae_infos_from_certificate() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let sae_id = 1; let kme_id = 1; @@ -938,7 +948,7 @@ mod tests { fn test_delete_pre_init_key_with_id() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let key = crate::qkd_manager::PreInitQkdKeyWrapper { other_kme_id: 1, key_uuid: *uuid::Uuid::from_bytes([0u8; 16]).as_bytes(), @@ -950,10 +960,10 @@ mod tests { } #[test] - fn test_add_important_event_subscriber() { + fn test_add_important_event_subscriber_without_nickname() { let (_, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, _) = crossbeam_channel::unbounded(); - let mut key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let mut key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, None).unwrap(); let subscriber = Arc::new(TestImportantEventSubscriber::new()); let subscriber2 = Arc::new(TestImportantEventSubscriber::new()); @@ -981,11 +991,43 @@ mod tests { assert_eq!(subscriber2.events.lock().unwrap()[1], "[KME 1] Key 00000000-0000-0000-0000-000000000000 activated between SAEs 1 and 1"); } + #[test] + fn test_add_important_event_subscriber_with_nickname() { + let (_, command_channel_rx) = crossbeam_channel::unbounded(); + let (response_channel_tx, _) = crossbeam_channel::unbounded(); + let mut key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, Some("Alice".to_string())).unwrap(); + + let subscriber = Arc::new(TestImportantEventSubscriber::new()); + let subscriber2 = Arc::new(TestImportantEventSubscriber::new()); + + key_handler.event_notification_subscribers.push(Arc::clone(&subscriber) as Arc); + key_handler.event_notification_subscribers.push(Arc::clone(&subscriber2) as Arc); + assert_eq!(key_handler.event_notification_subscribers.len(), 2); + assert_eq!(subscriber.events.lock().unwrap().len(), 0); + assert_eq!(subscriber2.events.lock().unwrap().len(), 0); + + let sae_certificate_serial = vec![0u8; CLIENT_CERT_SERIAL_SIZE_BYTES]; + key_handler.add_sae(1, 1, &Some(sae_certificate_serial.clone())).unwrap(); + key_handler.add_preinit_qkd_key(crate::qkd_manager::PreInitQkdKeyWrapper { + other_kme_id: 1, + key_uuid: *uuid::Uuid::from_bytes([0u8; 16]).as_bytes(), + key: [0u8; crate::QKD_KEY_SIZE_BITS / 8], + }).unwrap(); + key_handler.get_sae_keys(&sae_certificate_serial, 1).unwrap(); + + assert_eq!(subscriber.events.lock().unwrap().len(), 2); + assert_eq!(subscriber2.events.lock().unwrap().len(), 2); + assert_eq!(subscriber.events.lock().unwrap()[0], "[Alice] SAE 1 requested a key to communicate with 1"); + assert_eq!(subscriber.events.lock().unwrap()[1], "[Alice] Key 00000000-0000-0000-0000-000000000000 activated between SAEs 1 and 1"); + assert_eq!(subscriber2.events.lock().unwrap()[0], "[Alice] SAE 1 requested a key to communicate with 1"); + assert_eq!(subscriber2.events.lock().unwrap()[1], "[Alice] Key 00000000-0000-0000-0000-000000000000 activated between SAEs 1 and 1"); + } + #[test] fn test_run() { let (command_tx, command_channel_rx) = crossbeam_channel::unbounded(); let (response_channel_tx, response_rx) = crossbeam_channel::unbounded(); - let mut key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1).unwrap(); + let mut key_handler = super::KeyHandler::new(":memory:", command_channel_rx, response_channel_tx, 1, Some("Alice".to_string())).unwrap(); let subscriber = Arc::new(TestImportantEventSubscriber::new()); key_handler.event_notification_subscribers.push(Arc::clone(&subscriber) as Arc); @@ -1020,7 +1062,7 @@ mod tests { assert!(matches!(qkd_manager_response, QkdManagerResponse::NotFound)); assert_eq!(subscriber.events.lock().unwrap().len(), 1); - assert_eq!(subscriber.events.lock().unwrap()[0], "[KME 1] SAE 1 requested a key to communicate with 1"); + assert_eq!(subscriber.events.lock().unwrap()[0], "[Alice] SAE 1 requested a key to communicate with 1"); command_tx.send(super::QkdManagerCommand::GetStatus(sae_certificate_serial.clone(), 2)).unwrap(); let qkd_manager_response = response_rx.recv().unwrap(); diff --git a/src/qkd_manager/mod.rs b/src/qkd_manager/mod.rs index 88d982e..a1b40ee 100644 --- a/src/qkd_manager/mod.rs +++ b/src/qkd_manager/mod.rs @@ -29,25 +29,30 @@ pub struct QkdManager { pub kme_id: KmeId, /// Shannon's entropy calculator for keys stored in the database shannon_entropy_calculator: Arc>, + /// KME's nickname if any (eg: Alice, Bob...) + pub nick_name: Option, } impl QkdManager { /// Create a new QKD manager handler /// # Arguments /// * `sqlite_db_path` - The path to the SQLite database file, or ":memory:" to use an in-memory database + /// * `this_kme_id` - The ID of the KME this QKD manager belongs to + /// * `kme_nickname` - The nickname of the KME, if any (eg: `"Alice"`, `"Bob"`...) /// # Returns /// A new QKD manager handler /// # Notes /// This function spawns a new thread to handle the QKD manager - pub fn new(sqlite_db_path: &str, this_kme_id: KmeId) -> Self { + pub fn new(sqlite_db_path: &str, this_kme_id: KmeId, kme_nickname: &Option) -> Self { // crossbeam_channel allows cloning the sender and receiver let (command_tx, command_rx) = crossbeam_channel::unbounded::(); let (response_tx, response_rx) = crossbeam_channel::unbounded::(); let sqlite_db_path = String::from(sqlite_db_path); // Spawn a new thread to handle the QKD manager + let nickname = kme_nickname.to_owned(); thread::spawn(move || { - let mut key_handler = match key_handler::KeyHandler::new(&sqlite_db_path, command_rx, response_tx, this_kme_id) { + let mut key_handler = match key_handler::KeyHandler::new(&sqlite_db_path, command_rx, response_tx, this_kme_id, nickname.to_owned()) { Ok(handler) => handler, Err(_) => { error!("Error creating key handler"); @@ -65,6 +70,7 @@ impl QkdManager { dir_watcher, kme_id: this_kme_id, shannon_entropy_calculator: Arc::new(Mutex::new(ShannonEntropyAccumulator::new())), + nick_name: kme_nickname.to_owned(), } } @@ -435,7 +441,7 @@ mod test { #[tokio::test] async fn test_add_qkd_key() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); let key = super::PreInitQkdKeyWrapper::new(1, &[0; crate::QKD_KEY_SIZE_BYTES]).unwrap(); let response = qkd_manager.add_pre_init_qkd_key(key); assert!(response.is_ok()); @@ -449,7 +455,7 @@ mod test { let first_key: QkdEncKey = <[u8; crate::QKD_KEY_SIZE_BYTES]>::try_from("ABCDEFGHIJKLMNOPQRSTUVWXYZ012345".as_bytes()).unwrap(); let second_key: QkdEncKey = <[u8; crate::QKD_KEY_SIZE_BYTES]>::try_from("6789+-abcdefghijklmnopqrstuvwxyz".as_bytes()).unwrap(); - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); let key = super::PreInitQkdKeyWrapper::new(1, &first_key).unwrap(); qkd_manager.add_pre_init_qkd_key(key).unwrap(); assert_eq!(qkd_manager.get_total_keys_shannon_entropy().await.unwrap(), 5.0); @@ -461,7 +467,7 @@ mod test { #[test] fn test_add_sae() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); let response = qkd_manager.add_sae(1, 1, &Some(vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES])); assert!(response.is_ok()); assert_eq!(response.unwrap(), super::QkdManagerResponse::Ok); @@ -491,7 +497,7 @@ mod test { #[serial] async fn test_get_qkd_key() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); qkd_manager.add_sae(1, 1, &Some(vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); qkd_manager.add_sae(2, 2, &None).unwrap(); // No certificate as this SAE doesn't belong to KME1 let key = super::PreInitQkdKeyWrapper::new(1, &[0; crate::QKD_KEY_SIZE_BYTES]).unwrap(); @@ -513,7 +519,7 @@ mod test { #[serial] async fn test_get_qkd_keys_with_ids() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); qkd_manager.add_sae(1, 1, &Some(vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); qkd_manager.add_sae(2, 1, &Some(vec![1; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); let key = super::PreInitQkdKeyWrapper::new(1,&[0; crate::QKD_KEY_SIZE_BYTES]).unwrap(); @@ -556,7 +562,7 @@ mod test { #[test] fn test_get_qkd_key_status() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); qkd_manager.add_sae(1, 1, &Some(vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); qkd_manager.add_sae(2, 1, &Some(vec![1; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); let key = super::PreInitQkdKeyWrapper::new(1, &[0; crate::QKD_KEY_SIZE_BYTES]).unwrap(); @@ -577,7 +583,7 @@ mod test { #[test] fn test_get_sae_info_from_client_auth_certificate() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); qkd_manager.add_sae(1, 1, &Some(vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); let response = qkd_manager.get_sae_info_from_client_auth_certificate(&vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES]); assert!(response.is_ok()); @@ -594,7 +600,7 @@ mod test { #[test] fn test_get_kme_id_from_sae_id() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); qkd_manager.add_sae(1, 1, &Some(vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); let response = qkd_manager.get_kme_id_from_sae_id(1); assert!(response.is_some()); @@ -609,7 +615,7 @@ mod test { #[test] fn test_add_kme_classical_net_info() { const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); let response = qkd_manager.add_kme_classical_net_info(1, "test.fr:1234;bad_addr", "certs/inter_kmes/client-kme1-to-kme2.pfx", "", true); assert!(response.is_err()); @@ -634,7 +640,7 @@ mod test { #[tokio::test] #[serial] - async fn test_add_important_event_subscriber() { + async fn test_add_important_event_subscriber_with_nickname() { struct TestImportantEventSubscriber { events: Mutex>, } @@ -652,7 +658,45 @@ mod test { } } const SQLITE_DB_PATH: &'static str = ":memory:"; - let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1); + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &Some("Alice".to_string())); + let subscriber = Arc::new(TestImportantEventSubscriber::new()); + let response = qkd_manager.add_important_event_subscriber(Arc::clone(&subscriber) as Arc); + assert!(response.is_ok()); + assert_eq!(subscriber.events.lock().unwrap().deref().len(), 0); + + // Request a key + qkd_manager.add_sae(1, 1, &Some(vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES])).unwrap(); + let key = super::PreInitQkdKeyWrapper::new(1, &[0; crate::QKD_KEY_SIZE_BYTES]).unwrap(); + qkd_manager.add_pre_init_qkd_key(key).unwrap(); + let response = qkd_manager.get_qkd_key(1, &vec![0; CLIENT_CERT_SERIAL_SIZE_BYTES]).await; + assert!(response.is_ok()); + + assert_eq!(subscriber.events.lock().unwrap().deref().len(), 2); + assert_eq!(subscriber.events.lock().unwrap().deref_mut().pop(), Some("[Alice] Key 7b848ade-8cff-3d54-a9b8-53a215e6ee77 activated between SAEs 1 and 1".to_string())); + assert_eq!(subscriber.events.lock().unwrap().deref_mut().pop(), Some("[Alice] SAE 1 requested a key to communicate with 1".to_string())); + } + + #[tokio::test] + #[serial] + async fn test_add_important_event_subscriber_without_nickname() { + struct TestImportantEventSubscriber { + events: Mutex>, + } + impl TestImportantEventSubscriber { + fn new() -> Self { + Self { + events: Mutex::new(Vec::new()), + } + } + } + impl ImportantEventSubscriber for TestImportantEventSubscriber { + fn notify(&self, message: &str) -> Result<(), Error> { + self.events.lock().unwrap().push(message.to_string()); + Ok(()) + } + } + const SQLITE_DB_PATH: &'static str = ":memory:"; + let qkd_manager = super::QkdManager::new(SQLITE_DB_PATH, 1, &None); let subscriber = Arc::new(TestImportantEventSubscriber::new()); let response = qkd_manager.add_important_event_subscriber(Arc::clone(&subscriber) as Arc); assert!(response.is_ok()); diff --git a/src/routes/request_context.rs b/src/routes/request_context.rs index 36b6d01..a421e42 100644 --- a/src/routes/request_context.rs +++ b/src/routes/request_context.rs @@ -102,7 +102,7 @@ mod test { #[test] fn test_context_no_cert() { - let context = super::RequestContext::new(None, crate::qkd_manager::QkdManager::new(":memory:", 1)).unwrap(); + let context = super::RequestContext::new(None, crate::qkd_manager::QkdManager::new(":memory:", 1, &None)).unwrap(); assert!(!context.has_client_certificate()); assert!(context.get_client_certificate_cn().is_err()); assert!(context.get_client_certificate_serial_as_string().is_err()); @@ -114,7 +114,7 @@ mod test { const CERT_FILENAME: &'static str = "certs/zone1/kme1.crt"; let certs = load_cert(CERT_FILENAME).unwrap(); assert_eq!(certs.len(), 1); - let context = super::RequestContext::new(Some(&certs[0]), crate::qkd_manager::QkdManager::new(":memory:", 1)).unwrap(); + let context = super::RequestContext::new(Some(&certs[0]), crate::qkd_manager::QkdManager::new(":memory:", 1, &None)).unwrap(); assert!(context.has_client_certificate()); assert_eq!(context.get_client_certificate_cn().unwrap(), "localhost"); assert_eq!(context.get_client_certificate_serial_as_string().unwrap(), "70:f4:4f:56:0c:3f:27:d4:b2:11:a4:78:13:af:d0:3c:03:81:3b:8d"); diff --git a/src/server/log_http_server/index.html b/src/server/log_http_server/index.html index 4d6b7f7..a73dba1 100644 --- a/src/server/log_http_server/index.html +++ b/src/server/log_http_server/index.html @@ -14,7 +14,7 @@

Events

.then(response => response.json()) .then(events => { eventList.innerHTML = events.map(event => { - return `

${event}

`; + return `

${event.datetime}: ${event.message}

`; }).join(''); }); }, 500); diff --git a/src/server/log_http_server/logging_message.rs b/src/server/log_http_server/logging_message.rs new file mode 100644 index 0000000..fe5b2e2 --- /dev/null +++ b/src/server/log_http_server/logging_message.rs @@ -0,0 +1,40 @@ +use chrono; +use chrono::{DateTime, Utc}; +use serde::{Serialize, Serializer}; + +#[derive(Debug, Clone, Serialize)] +pub(super) struct LoggingMessage { + message: String, + #[serde(serialize_with = "LoggingMessage::serialize_datetime_json")] + datetime: DateTime, +} + +impl LoggingMessage { + pub(super) fn new(message: &str) -> Self { + Self { + message: message.to_string(), + datetime: Utc::now(), + } + } + + fn serialize_datetime_json(dt: &DateTime, serializer: S) -> Result { + format!("{:?}", dt).serialize(serializer) + } +} + +#[cfg(test)] +mod tests { + use regex::Regex; + use super::*; + use serde_json; + + #[test] + fn test_logging_message() { + const MESSAGE: &'static str = "Test message"; + let log_message = LoggingMessage::new(MESSAGE); + let json = serde_json::to_string(&log_message).unwrap(); + assert!(json.contains(MESSAGE)); + let check_json_regex = Regex::new(r#"\{"message":"Test message","datetime":"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d+Z"}"#).unwrap(); + assert!(check_json_regex.is_match(&json)); + } +} \ No newline at end of file diff --git a/src/server/log_http_server/mod.rs b/src/server/log_http_server/mod.rs index 5cce739..597eb17 100644 --- a/src/server/log_http_server/mod.rs +++ b/src/server/log_http_server/mod.rs @@ -1,6 +1,8 @@ //! HTTP server for logging important events, in a demonstration purpose (intended to be visited using a web browser) //! Events are displayed on index HTML page, and retrieved periodically by AJAX requests from /messages +mod logging_message; + use std::convert::Infallible; use std::io; use std::ops::Deref; @@ -14,13 +16,14 @@ use hyper::service::service_fn; use hyper_util::rt::TokioIo; use tokio::net::TcpListener; use crate::event_subscription::ImportantEventSubscriber; +use crate::server::log_http_server::logging_message::LoggingMessage; /// HTTP logging server struct #[derive(Debug)] pub struct LoggingHttpServer { /// HTTP listen address, e.g. "0.0.0.0:8080" pub listen_addr: String, - received_log_messages: Arc>>, + received_log_messages: Arc>>, } impl LoggingHttpServer { @@ -35,8 +38,9 @@ impl LoggingHttpServer { received_log_messages: Arc::new(Mutex::new(Vec::new())), } } - /// Run the HTTP server + /// # Arguments + /// * `qkd_manager` - The QKD manager associated with this logging server /// # Returns /// Never (`!`) in case of success, an io::Error otherwise pub async fn run(&self) -> Result<(), io::Error> { @@ -64,7 +68,7 @@ impl LoggingHttpServer { } /// Called at each incoming request - async fn handle_incoming_request(request: Request, received_log_messages: Arc>>) -> Result>, Infallible> { + async fn handle_incoming_request(request: Request, received_log_messages: Arc>>) -> Result>, Infallible> { const INDEX_HTML_RESPONSE: &str = include_str!("index.html"); let response_obj = match request.uri().path() { @@ -79,7 +83,7 @@ impl LoggingHttpServer { } /// Generates JSON array HTTP response containing all received log messages, or HTTP error status if an error occurred - fn generate_messages_http_json_response(received_log_messages: &Arc>>) -> Response> { + fn generate_messages_http_json_response(received_log_messages: &Arc>>) -> Response> { let received_log_messages = match received_log_messages.lock() { Ok(received_log_messages) => received_log_messages, Err(_) => { @@ -108,7 +112,7 @@ impl ImportantEventSubscriber for LoggingHttpServer { .map_err(|_| io::Error::new(io::ErrorKind::Other, "Mutex lock error" ))? - .push(message.to_string()); + .push(LoggingMessage::new(message)); Ok(()) } } @@ -116,6 +120,7 @@ impl ImportantEventSubscriber for LoggingHttpServer { #[cfg(test)] mod tests { use std::sync::Arc; + use regex::Regex; use serial_test::serial; use crate::event_subscription::ImportantEventSubscriber; use crate::server::log_http_server::LoggingHttpServer; @@ -144,6 +149,7 @@ mod tests { let get_messages_response = reqwest::get("http://127.0.0.1:8080/messages").await.unwrap(); assert_eq!(get_messages_response.status(), 200); - assert_eq!(get_messages_response.text().await.unwrap(), "[\"Hello\",\"World\"]"); + let check_json_regex = Regex::new(r#"\[\{"message":"Hello","datetime":"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d+Z"},\{"message":"World","datetime":"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d+Z"}]"#).unwrap(); + assert!(check_json_regex.is_match(&get_messages_response.text().await.unwrap())); } } \ No newline at end of file diff --git a/tests/common/mod.rs b/tests/common/mod.rs index 2250eca..bf72bca 100644 --- a/tests/common/mod.rs +++ b/tests/common/mod.rs @@ -21,7 +21,7 @@ pub fn setup() { "certs/zone1/kme1.key", ); - let qkd_manager = QkdManager::new(":memory:", 1); + let qkd_manager = QkdManager::new(":memory:", 1, &Some("Alice".to_string())); qkd_manager.add_sae(1, 1, &Some(vec![0x70, 0xf4, 0x4f, 0x56, 0x0c, 0x3f, 0x27, 0xd4, 0xb2, 0x11, 0xa4, 0x78, 0x13, 0xaf, 0xd0, 0x3c, 0x03, 0x81, 0x3b, 0x8e]) @@ -110,7 +110,7 @@ pub fn setup_2_kmes_network() { "certs/zone2/kme2.key", ); - let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1)); + let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1, &Some("Alice".to_string()))); kme1_qkd_manager.add_sae(1, 1, &Some(vec![0x70, 0xf4, 0x4f, 0x56, 0x0c, 0x3f, 0x27, 0xd4, 0xb2, 0x11, 0xa4, 0x78, 0x13, 0xaf, 0xd0, 0x3c, 0x03, 0x81, 0x3b, 0x8e]) @@ -129,7 +129,7 @@ pub fn setup_2_kmes_network() { b"this_is_secret_key_2_of_32_bytes", ).unwrap()).unwrap(); - let kme2_qkd_manager = Arc::new(QkdManager::new(":memory:", 2)); + let kme2_qkd_manager = Arc::new(QkdManager::new(":memory:", 2, &Some("Bob".to_string()))); kme2_qkd_manager.add_sae(1, 1, &None @@ -193,7 +193,7 @@ pub fn setup_2_kmes_network_keys_not_sync() { "certs/zone2/kme2.key", ); - let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1)); + let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1, &Some("Alice".to_string()))); kme1_qkd_manager.add_sae(1, 1, &Some(vec![0x70, 0xf4, 0x4f, 0x56, 0x0c, 0x3f, 0x27, 0xd4, 0xb2, 0x11, 0xa4, 0x78, 0x13, 0xaf, 0xd0, 0x3c, 0x03, 0x81, 0x3b, 0x8e]) @@ -208,7 +208,7 @@ pub fn setup_2_kmes_network_keys_not_sync() { b"this_is_secret_key_1_of_32_bytes", ).unwrap()).unwrap(); - let kme2_qkd_manager = Arc::new(QkdManager::new(":memory:", 2)); + let kme2_qkd_manager = Arc::new(QkdManager::new(":memory:", 2, &Some("Bob".to_string()))); kme2_qkd_manager.add_sae(1, 1, &None @@ -256,7 +256,7 @@ pub fn setup_2_kmes_network_1_kme_down() { "certs/zone1/kme1.key", ); - let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1)); + let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1, &Some("Alice".to_string()))); kme1_qkd_manager.add_sae(1, 1, &Some(vec![0x70, 0xf4, 0x4f, 0x56, 0x0c, 0x3f, 0x27, 0xd4, 0xb2, 0x11, 0xa4, 0x78, 0x13, 0xaf, 0xd0, 0x3c, 0x03, 0x81, 0x3b, 0x8e]) @@ -302,7 +302,7 @@ pub fn setup_2_kmes_network_missing_conf() { "certs/zone1/kme1.key", ); - let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1)); + let kme1_qkd_manager = Arc::new(QkdManager::new(":memory:", 1, &Some("Alice".to_string()))); kme1_qkd_manager.add_sae(1, 1, &Some(vec![0x70, 0xf4, 0x4f, 0x56, 0x0c, 0x3f, 0x27, 0xd4, 0xb2, 0x11, 0xa4, 0x78, 0x13, 0xaf, 0xd0, 0x3c, 0x03, 0x81, 0x3b, 0x8e]) diff --git a/tests/config_parsing.rs b/tests/config_parsing.rs index 7d130fb..469ee3f 100644 --- a/tests/config_parsing.rs +++ b/tests/config_parsing.rs @@ -27,9 +27,6 @@ async fn test_key_transfer_from_file_config() { const LOG_DEMO_REQUEST_URL_INDEX: &'static str = concatcp!("http://localhost:8080"); const LOG_DEMO_REQUEST_URL_JSON_DATA: &'static str = concatcp!("http://localhost:8080/messages"); - const LOG_MESSAGE_STEP_1: &'static str = "[]"; - const LOG_MESSAGE_STEP_2: &'static str = "[\"[KME 1] SAE 1 requested a key to communicate with 3\",\"[KME 1] As SAE 3 belongs to KME 2, activating it through inter KMEs network\",\"[KME 1] Key 2ae3e385-4e51-7458-b1c1-69066a4cb6d7 activated between SAEs 1 and 3\"]"; - const LOG_MESSAGE_STEP_3: &'static str = "[\"[KME 1] SAE 1 requested a key to communicate with 3\",\"[KME 1] As SAE 3 belongs to KME 2, activating it through inter KMEs network\",\"[KME 1] Key 2ae3e385-4e51-7458-b1c1-69066a4cb6d7 activated between SAEs 1 and 3\",\"[KME 1] Key 9768257a-1c59-d255-a93d-d4bb1b693651 activated between SAEs 3 and 1\",\"[KME 1] SAE 1 requested key 9768257a-1c59-d255-a93d-d4bb1b693651 (from 3)\"]"; tokio::spawn(async move { launch_kme_from_config_file(CONFIG_FILE_PATH_KME1).await; @@ -46,7 +43,7 @@ async fn test_key_transfer_from_file_config() { assert_eq!(log_index_response.status(), 200); let log_data_response = log_demo_reqwest_client.get(LOG_DEMO_REQUEST_URL_JSON_DATA).send().await.unwrap(); assert_eq!(log_data_response.status(), 200); - assert_eq!(log_data_response.text().await.unwrap(), LOG_MESSAGE_STEP_1); + assert_eq!(log_data_response.text().await.unwrap(), "[]"); let post_key_response = sae1_reqwest_client.post(INIT_POST_KEY_REQUEST_URL).send().await; assert!(post_key_response.is_ok()); @@ -57,7 +54,10 @@ async fn test_key_transfer_from_file_config() { let log_data_response = log_demo_reqwest_client.get(LOG_DEMO_REQUEST_URL_JSON_DATA).send().await.unwrap(); assert_eq!(log_data_response.status(), 200); - assert_eq!(log_data_response.text().await.unwrap(), LOG_MESSAGE_STEP_2); + let text_log_message = log_data_response.text().await.unwrap(); + assert!(text_log_message.contains("[Alice] SAE 1 requested a key to communicate with 3")); + assert!(text_log_message.contains("[Alice] As SAE 3 belongs to KME 2, activating it through inter KMEs network")); + assert!(text_log_message.contains("[Alice] Key 2ae3e385-4e51-7458-b1c1-69066a4cb6d7 activated between SAEs 1 and 3")); const REMOTE_DEC_KEYS_REQ_BODY: &'static str = "{\n\"key_IDs\": [{\"key_ID\": \"2ae3e385-4e51-7458-b1c1-69066a4cb6d7\"}]\n}"; let req_key_remote_response = sae2_reqwest_client.post(REMOTE_DEC_KEYS_REQUEST_URL).header(CONTENT_TYPE, "application/json").body(REMOTE_DEC_KEYS_REQ_BODY).send().await; @@ -84,7 +84,12 @@ async fn test_key_transfer_from_file_config() { let log_data_response = log_demo_reqwest_client.get(LOG_DEMO_REQUEST_URL_JSON_DATA).send().await.unwrap(); assert_eq!(log_data_response.status(), 200); - assert_eq!(log_data_response.text().await.unwrap(), LOG_MESSAGE_STEP_3); + let text_log_message = log_data_response.text().await.unwrap(); + assert!(text_log_message.contains("[Alice] SAE 1 requested a key to communicate with 3")); + assert!(text_log_message.contains("[Alice] As SAE 3 belongs to KME 2, activating it through inter KMEs network")); + assert!(text_log_message.contains("[Alice] Key 2ae3e385-4e51-7458-b1c1-69066a4cb6d7 activated between SAEs 1 and 3")); + assert!(text_log_message.contains("[Alice] Key 9768257a-1c59-d255-a93d-d4bb1b693651 activated between SAEs 3 and 1")); + assert!(text_log_message.contains("[Alice] SAE 1 requested key 9768257a-1c59-d255-a93d-d4bb1b693651 (from 3)")); } // Quite similar to program's main function diff --git a/tests/data/test_kme_config.json b/tests/data/test_kme_config.json index 560088c..1941d1d 100644 --- a/tests/data/test_kme_config.json +++ b/tests/data/test_kme_config.json @@ -1,6 +1,7 @@ { "this_kme": { "id": 1, + "nickname": "Alice", "sqlite_db_path": ":memory:", "key_directory_to_watch": "tests/data/raw_keys/kme-1-1", "saes_https_interface": {