Implement mitigation 4 of TM

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),
         }
     }

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);

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)

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) => {

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(

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() {