diff --git a/src/front/front_end.rs b/src/front/front_end.rs index 5ba0e879..57f09368 100644 --- a/src/front/front_end.rs +++ b/src/front/front_end.rs @@ -56,35 +56,65 @@ impl FrontEndHandler { return; } }; + // Check if the request was sent without authentication - let response = if AuthType::NoAuth == request.header.auth_type { - let response = self.dispatcher.dispatch_request(request, None); - trace!("dispatch_request egress"); - response + let (app_name, err_response) = if AuthType::NoAuth == request.header.auth_type { + (None, None) // Otherwise find an authenticator that is capable to authenticate the request } else if let Some(authenticator) = self.authenticators.get(&request.header.auth_type) { // Authenticate the request match authenticator.authenticate(&request.auth) { // Send the request to the dispatcher // Get a response back - Ok(app_name) => { - let response = self.dispatcher.dispatch_request(request, Some(app_name)); - trace!("dispatch_request egress"); - response - } - Err(status) => Response::from_request_header(request.header, status), + Ok(app_name) => (Some(app_name), None), + Err(status) => ( + None, + Some(Response::from_request_header(request.header, status)), + ), } } else { - Response::from_request_header( - request.header, - ResponseStatus::AuthenticatorNotRegistered, + ( + None, + Some(Response::from_request_header( + request.header, + ResponseStatus::AuthenticatorNotRegistered, + )), ) }; - // Serialise the responso into bytes + let response = if let Some(err_response) = err_response { + err_response + } else { + if crate::utils::GlobalConfig::log_error_details() { + if let Some(app_name_string) = app_name.clone() { + info!( + "New request received from application name \"{}\"", + app_name_string + ) + } else { + info!("New request received without authentication") + } + }; + let response = self.dispatcher.dispatch_request(request, app_name.clone()); + trace!("dispatch_request egress"); + response + }; + + // Serialise the response into bytes // Write bytes to stream match response.write_to_stream(&mut stream) { - Ok(_) => info!("Request handled successfully"), + Ok(_) => { + if crate::utils::GlobalConfig::log_error_details() { + if let Some(app_name_string) = app_name { + info!( + "Response from application name \"{}\" sent back", + app_name_string + ); + } else { + info!("Response sent back from request without authentication"); + } + } + } Err(err) => format_error!("Failed to send response", err), } } diff --git a/src/key_info_managers/on_disk_manager/mod.rs b/src/key_info_managers/on_disk_manager/mod.rs index a9bbae68..1b161263 100644 --- a/src/key_info_managers/on_disk_manager/mod.rs +++ b/src/key_info_managers/on_disk_manager/mod.rs @@ -14,7 +14,7 @@ //! For security reasons, only the PARSEC service should have the ability to modify these files. use super::{KeyInfo, KeyTriple, ManageKeyInfo}; use crate::authenticators::ApplicationName; -use log::{error, info}; +use log::{error, info, warn}; use parsec_interface::requests::ProviderID; use std::collections::HashMap; use std::convert::TryFrom; @@ -187,9 +187,6 @@ impl OnDiskKeyInfoManager { for app_name_dir_path in list_dirs(&mappings_dir_path)?.iter() { for provider_dir_path in list_dirs(&app_name_dir_path)?.iter() { for key_name_file_path in list_files(&provider_dir_path)?.iter() { - if crate::utils::GlobalConfig::log_error_details() { - info!("Found mapping file: {:?}.", key_name_file_path); - } let mut key_info = Vec::new(); let mut key_info_file = File::open(&key_name_file_path)?; let _ = key_info_file.read_to_end(&mut key_info)?; @@ -209,6 +206,12 @@ impl OnDiskKeyInfoManager { ))?, ) { Ok(key_triple) => { + if crate::utils::GlobalConfig::log_error_details() { + warn!( + "Inserting Key Triple ({}) mapping read from disk.", + key_triple.clone() + ); + } let _ = key_store.insert(key_triple, key_info); } Err(string) => { @@ -236,6 +239,12 @@ impl OnDiskKeyInfoManager { /// The filename will be `mappings/[APP_NAME]/[PROVIDER_NAME]/[KEY_NAME]` under the same path as the /// on-disk manager. It will contain the Key info data. fn save_mapping(&self, key_triple: &KeyTriple, key_info: &KeyInfo) -> std::io::Result<()> { + if crate::utils::GlobalConfig::log_error_details() { + warn!( + "Saving Key Triple ({}) mapping to disk.", + key_triple.clone() + ); + } // Create the directories with base64 names. let (app_name, prov, key_name) = key_triple_to_base64_filenames(key_triple); let provider_dir_path = self.mappings_dir_path.join(app_name).join(prov); diff --git a/src/providers/pkcs11_provider/asym_sign.rs b/src/providers/pkcs11_provider/asym_sign.rs index 9356c4b1..4f4be602 100644 --- a/src/providers/pkcs11_provider/asym_sign.rs +++ b/src/providers/pkcs11_provider/asym_sign.rs @@ -4,7 +4,7 @@ use super::Pkcs11Provider; use super::{key_management::get_key_info, utils, KeyPairType, ReadWriteSession, Session}; use crate::authenticators::ApplicationName; use crate::key_info_managers::KeyTriple; -use log::{error, info}; +use log::{error, info, trace}; use parsec_interface::operations::psa_algorithm::*; use parsec_interface::operations::{psa_sign_hash, psa_verify_hash}; use parsec_interface::requests::{ProviderID, ResponseStatus, Result}; @@ -78,6 +78,7 @@ impl Pkcs11Provider { let key = self.find_key(session.session_handle(), key_id, KeyPairType::PrivateKey)?; info!("Located signing key."); + trace!("SignInit command"); match self.backend.sign_init(session.session_handle(), &mech, key) { Ok(_) => { info!("Signing operation initialized."); @@ -89,6 +90,7 @@ impl Pkcs11Provider { // should not fail - if it does, there's some error in our stack .or(Err(ResponseStatus::PsaErrorGenericError))?; + trace!("Sign command"); match self.backend.sign(session.session_handle(), &digest_info) { Ok(signature) => Ok(psa_sign_hash::Result { signature }), Err(e) => { @@ -164,6 +166,7 @@ impl Pkcs11Provider { let key = self.find_key(session.session_handle(), key_id, KeyPairType::PublicKey)?; info!("Located public key."); + trace!("VerifyInit command"); match self .backend .verify_init(session.session_handle(), &mech, key) @@ -178,6 +181,7 @@ impl Pkcs11Provider { // should not fail - if it does, there's some error in our stack .or(Err(ResponseStatus::PsaErrorGenericError))?; + trace!("Verify command"); match self .backend .verify(session.session_handle(), &digest_info, &signature) diff --git a/src/providers/pkcs11_provider/key_management.rs b/src/providers/pkcs11_provider/key_management.rs index 7a83ba86..8b53fe19 100644 --- a/src/providers/pkcs11_provider/key_management.rs +++ b/src/providers/pkcs11_provider/key_management.rs @@ -7,7 +7,7 @@ use super::{ use crate::authenticators::ApplicationName; use crate::key_info_managers::KeyTriple; use crate::key_info_managers::{self, ManageKeyInfo}; -use log::{error, info, warn}; +use log::{error, info, trace, warn}; use parsec_interface::operations::psa_key_attributes::*; use parsec_interface::operations::{ psa_destroy_key, psa_export_public_key, psa_generate_key, psa_import_key, @@ -116,12 +116,15 @@ impl Pkcs11Provider { KeyPairType::Any => (), } + trace!("FindObjectsInit command"); if let Err(e) = self.backend.find_objects_init(session, &template) { format_error!("Object enumeration init failed", e); Err(utils::to_response_status(e)) } else { + trace!("FindObjects command"); match self.backend.find_objects(session, 1) { Ok(objects) => { + trace!("FindObjectsFinal command"); if let Err(e) = self.backend.find_objects_final(session) { format_error!("Object enumeration final failed", e); Err(utils::to_response_status(e)) @@ -220,6 +223,7 @@ impl Pkcs11Provider { ); } + trace!("GenerateKeyPair command"); match self.backend.generate_key_pair( session.session_handle(), &mech, @@ -362,6 +366,7 @@ impl Pkcs11Provider { ); } + trace!("CreateObject command"); match self .backend .create_object(session.session_handle(), &template) @@ -408,6 +413,7 @@ impl Pkcs11Provider { size_attrs.push(CK_ATTRIBUTE::new(pkcs11::types::CKA_PUBLIC_EXPONENT)); // Get the length of the attributes to retrieve. + trace!("GetAttributeValue command"); let (modulus_len, public_exponent_len) = match self .backend @@ -440,6 +446,7 @@ impl Pkcs11Provider { .with_bytes(public_exponent.as_mut_slice()), ); + trace!("GetAttributeValue command"); match self .backend .get_attribute_value(session.session_handle(), key, &mut extract_attrs) @@ -502,6 +509,7 @@ impl Pkcs11Provider { match self.find_key(session.session_handle(), key_id, KeyPairType::Any) { Ok(key) => { + trace!("DestroyObject command"); match self.backend.destroy_object(session.session_handle(), key) { Ok(_) => info!("Private part of the key destroyed successfully."), Err(e) => { @@ -519,6 +527,7 @@ impl Pkcs11Provider { // Second key is optional. match self.find_key(session.session_handle(), key_id, KeyPairType::Any) { Ok(key) => { + trace!("DestroyObject command"); match self.backend.destroy_object(session.session_handle(), key) { Ok(_) => info!("Private part of the key destroyed successfully."), Err(e) => { diff --git a/src/providers/pkcs11_provider/mod.rs b/src/providers/pkcs11_provider/mod.rs index c90a90f0..579e77e3 100644 --- a/src/providers/pkcs11_provider/mod.rs +++ b/src/providers/pkcs11_provider/mod.rs @@ -250,6 +250,7 @@ impl Provide for Pkcs11Provider { impl Drop for Pkcs11Provider { fn drop(&mut self) { + trace!("Finalize command"); if let Err(e) = self.backend.finalize() { format_error!("Error when dropping the PKCS 11 provider", e); } @@ -332,6 +333,7 @@ impl Pkcs11ProviderBuilder { args.LockMutex = None; args.UnlockMutex = None; args.flags = CKF_OS_LOCKING_OK; + trace!("Initialize command"); backend.initialize(Some(args)).or_else(|e| { format_error!("Error initializing the PKCS 11 backend", e); Err(Error::new( diff --git a/src/providers/pkcs11_provider/utils.rs b/src/providers/pkcs11_provider/utils.rs index 1df90348..3c5d5622 100644 --- a/src/providers/pkcs11_provider/utils.rs +++ b/src/providers/pkcs11_provider/utils.rs @@ -3,7 +3,7 @@ use super::Pkcs11Provider; use log::error; -use log::{info, warn}; +use log::{info, trace, warn}; use parsec_interface::requests::ResponseStatus; use parsec_interface::requests::Result; use picky_asn1::wrapper::IntegerAsn1; @@ -104,6 +104,7 @@ impl Session<'_> { session_flags |= CKF_RW_SESSION; } + trace!("OpenSession command"); match provider .backend .open_session(provider.slot_number, session_flags, None, None) @@ -167,6 +168,7 @@ impl Session<'_> { self.is_logged_in = true; Ok(()) } else if let Some(user_pin) = self.provider.user_pin.as_ref() { + trace!("Login command"); match self .provider .backend @@ -209,6 +211,7 @@ impl Session<'_> { Ok(()) } else if *logged_sessions_counter == 1 { // Only this session requires authentication. + trace!("Logout command"); match self.provider.backend.logout(self.session_handle) { Ok(_) => { if crate::utils::GlobalConfig::log_error_details() { @@ -247,6 +250,7 @@ impl Drop for Session<'_> { if self.logout().is_err() { error!("Error while logging out. Continuing..."); } + trace!("CloseSession command"); match self.provider.backend.close_session(self.session_handle) { Ok(_) => { if crate::utils::GlobalConfig::log_error_details() {