Add structured logging of all previously-swallowed errors

Cargo.toml

@@ -21,6 +21,7 @@ async-trait = "0.1.89"
 base64 = "0.22"
 generic-array = "1.3.5"
 rand = "0.8"
+log = { version = "0.4", features = ["kv"] }
 serde = "1"
 sha2 = "0.10.9"
 thiserror = "2"

src/amortized_tokens/response.rs

@@ -1,6 +1,7 @@
 //! Response implementation of the Amortized Tokens protocol.
 
 use generic_array::GenericArray;
+use log::warn;
 use tls_codec::{Deserialize, Serialize, Size};
 use typenum::Unsigned;
 use voprf::{EvaluationElement, Group, Proof, Result, VoprfClient};
@@ -76,10 +77,15 @@ impl<CS: PrivateCipherSuite> AmortizedBatchTokenResponse<CS> {
                 .get(index)
                 .map(|token_input| token_input.token_type)
                 .unwrap_or(default_token_type);
-            let evaluated_element = EvaluationElement::<CS>::deserialize(
-                &element.evaluated_element,
-            )
-            .map_err(|source| IssueTokenError::InvalidEvaluationElement { token_type, source })?;
+            let evaluated_element =
+                EvaluationElement::<CS>::deserialize(&element.evaluated_element)
+                    .inspect_err(
+                        |e| warn!(error:% = e, index; "Failed to deserialize evaluated element"),
+                    )
+                    .map_err(|source| IssueTokenError::InvalidEvaluationElement {
+                        token_type,
+                        source,
+                    })?;
             evaluated_elements.push(evaluated_element);
         }
 
@@ -101,11 +107,13 @@ impl<CS: PrivateCipherSuite> AmortizedBatchTokenResponse<CS> {
             &proof,
             token_state.public_key,
         )
+        .inspect_err(|e| warn!(error:% = e; "Failed to batch finalize"))
         .map_err(|source| IssueTokenError::BatchFinalizationFailed {
             token_type: default_token_type,
             source,
         })?
         .collect::<Result<Vec<_>>>()
+        .inspect_err(|e| warn!(error:% = e; "Failed to collect finalized tokens"))
         .map_err(|source| IssueTokenError::BatchFinalizationFailed {
             token_type: default_token_type,
             source,
@@ -117,8 +125,7 @@ impl<CS: PrivateCipherSuite> AmortizedBatchTokenResponse<CS> {
             .iter()
             .zip(token_state.token_inputs.iter())
         {
-            let authenticator =
-                GenericArray::from_slice(authenticator.as_ref()).clone();
+            let authenticator = GenericArray::from_slice(authenticator.as_ref()).clone();
             let token = Token::new(
                 token_input.token_type,
                 token_input.nonce,

src/amortized_tokens/server.rs

@@ -1,6 +1,7 @@
 //! Server-side implementation of the Amortized Tokens protocol.
 
 use generic_array::GenericArray;
+use log::{debug, warn};
 use rand::{RngCore, rngs::OsRng};
 use sha2::digest::OutputSizeUser;
 use typenum::Unsigned;
@@ -31,6 +32,7 @@ impl<CS: PrivateCipherSuite> Server<CS> {
         <CS::Group as Group>::Elem: Send + Sync,
     {
         VoprfServer::<CS>::new_from_seed(seed, info)
+            .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server from seed"))
             .map_err(|source| CreateKeypairError::SeedError { source })
     }
 
@@ -115,8 +117,11 @@ impl<CS: PrivateCipherSuite> Server<CS> {
             .ok_or(IssueTokenResponseError::KeyIdNotFound)?;
 
         let mut blinded_elements = Vec::new();
-        for element in token_request.blinded_elements.iter() {
+        for (idx, element) in token_request.blinded_elements.iter().enumerate() {
             let blinded_element = BlindedElement::<CS>::deserialize(&element.blinded_element)
+                .inspect_err(
+                    |e| warn!(error:% = e, index = idx; "Failed to deserialize blinded element"),
+                )
                 .map_err(|source| IssueTokenResponseError::InvalidBlindedMessage { source })?;
             blinded_elements.push(blinded_element);
         }
@@ -126,6 +131,7 @@ impl<CS: PrivateCipherSuite> Server<CS> {
             .collect::<Vec<_>>();
         let VoprfServerBatchEvaluateFinishResult { messages, proof } = server
             .batch_blind_evaluate_finish(&mut OsRng, blinded_elements.iter(), &prepared_elements)
+            .inspect_err(|e| warn!(error:% = e; "Failed to batch evaluate blinded elements"))
             .map_err(|source| IssueTokenResponseError::BlindEvaluationFailed { source })?;
 
         let evaluated_elements = messages
@@ -183,6 +189,7 @@ impl<CS: PrivateCipherSuite> Server<CS> {
             .ok_or(RedeemTokenError::KeyIdNotFound)?;
         let token_authenticator = server
             .evaluate(&token_input.serialize())
+            .inspect_err(|e| warn!(error:% = e; "Failed to evaluate token during redemption"))
             .map_err(|source| RedeemTokenError::AuthenticatorDerivationFailed {
                 token_type,
                 source,
@@ -208,6 +215,7 @@ impl<CS: PrivateCipherSuite> Server<CS> {
         <CS::Group as Group>::Elem: Send + Sync,
     {
         let server = VoprfServer::<CS>::new_with_key(private_key)
+            .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server with key"))
             .map_err(|source| CreateKeypairError::SeedError { source })?;
         let public_key = server.get_public_key();
         let token_key_id = public_key_to_token_key_id::<CS>(&server.get_public_key());

src/private_tokens/response.rs

@@ -1,6 +1,7 @@
 //! Response implementation of the Privately Verifiable Token protocol.
 
 use generic_array::GenericArray;
+use log::warn;
 use tls_codec::{Deserialize, Serialize, Size};
 use typenum::Unsigned;
 use voprf::*;
@@ -98,8 +99,10 @@ impl<CS: PrivateCipherSuite> TokenResponse<CS> {
     ) -> Result<PrivateToken<CS>, IssueTokenError> {
         let token_type = token_state.token_input.token_type;
         let evaluation_element = EvaluationElement::deserialize(&self.evaluate_msg)
+            .inspect_err(|e| warn!(error:% = e; "Failed to deserialize evaluation element"))
             .map_err(|source| IssueTokenError::InvalidEvaluationElement { token_type, source })?;
         let proof = Proof::deserialize(&self.evaluate_proof)
+            .inspect_err(|e| warn!(error:% = e; "Failed to deserialize proof"))
             .map_err(|source| IssueTokenError::InvalidProof { token_type, source })?;
         let token_input = token_state.token_input.serialize();
         // authenticator = client_context.Finalize(token_input, blind, evaluated_element, blinded_element, proof)
@@ -111,6 +114,7 @@ impl<CS: PrivateCipherSuite> TokenResponse<CS> {
                 &proof,
                 token_state.public_key,
             )
+            .inspect_err(|e| warn!(error:% = e; "Failed to finalize token"))
             .map_err(|source| IssueTokenError::FinalizationFailed { token_type, source })?;
         let authenticator = GenericArray::from_slice(authenticator.as_ref()).clone();
 

src/private_tokens/server.rs

@@ -1,6 +1,7 @@
 //! Server-side implementation of Privately Verifiable Token protocol.
 
 use generic_array::{ArrayLength, GenericArray};
+use log::{debug, warn};
 use rand::{RngCore, rngs::OsRng};
 use sha2::digest::OutputSizeUser;
 use typenum::Unsigned;
@@ -28,6 +29,7 @@ pub struct Server<CS: PrivateCipherSuite> {
 impl<CS: PrivateCipherSuite> Server<CS> {
     fn server_from_seed(seed: &[u8], info: &[u8]) -> Result<VoprfServer<CS>, CreateKeypairError> {
         VoprfServer::<CS>::new_from_seed(seed, info)
+            .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server from seed"))
             .map_err(|source| CreateKeypairError::SeedError { source })
     }
 
@@ -103,6 +105,7 @@ impl<CS: PrivateCipherSuite> Server<CS> {
             .await
             .ok_or(IssueTokenResponseError::KeyIdNotFound)?;
         let blinded_element = BlindedElement::<CS>::deserialize(&token_request.blinded_msg)
+            .inspect_err(|e| warn!(error:% = e; "Failed to deserialize blinded element"))
             .map_err(|source| IssueTokenResponseError::InvalidBlindedMessage { source })?;
         let evaluated_result = server.blind_evaluate(&mut OsRng, &blinded_element);
 
@@ -154,6 +157,7 @@ impl<CS: PrivateCipherSuite> Server<CS> {
             .ok_or(RedeemTokenError::KeyIdNotFound)?;
         let token_authenticator = server
             .evaluate(&token_input.serialize())
+            .inspect_err(|e| warn!(error:% = e; "Failed to evaluate token during redemption"))
             .map_err(|source| RedeemTokenError::AuthenticatorDerivationFailed {
                 token_type,
                 source,
@@ -175,6 +179,7 @@ impl<CS: PrivateCipherSuite> Server<CS> {
         private_key: &[u8],
     ) -> Result<PublicKey<CS>, CreateKeypairError> {
         let server = VoprfServer::<CS>::new_with_key(private_key)
+            .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server with key"))
             .map_err(|source| CreateKeypairError::SeedError { source })?;
         let public_key = server.get_public_key();
         let truncated_token_key_id =

src/public_tokens/request.rs

@@ -1,6 +1,7 @@
 //! Request implementation of the Publicly Verifiable Token protocol.
 
 use blind_rsa_signatures::{BlindingResult, Options, PublicKey};
+use log::warn;
 use rand::{CryptoRng, RngCore};
 use tls_codec_derive::{TlsDeserialize, TlsSerialize, TlsSize};
 
@@ -51,6 +52,7 @@ impl TokenRequest {
 
         let challenge_digest = challenge
             .digest()
+            .inspect_err(|e| warn!(error:% = e; "Failed to create challenge digest"))
             .map_err(|source| IssueTokenRequestError::InvalidTokenChallenge { source })?;
 
         let token_key_id = public_key_to_token_key_id(&public_key);
@@ -65,6 +67,7 @@ impl TokenRequest {
         let options = Options::default();
         let blinding_result = public_key
             .blind(rng, token_input.serialize(), false, &options)
+            .inspect_err(|e| warn!(error:% = e; "Failed to blind token input"))
             .map_err(|source| IssueTokenRequestError::BlindingError {
                 source: source.into(),
             })?;

src/public_tokens/response.rs

@@ -2,6 +2,7 @@
 
 use blind_rsa_signatures::{BlindSignature, Options};
 use generic_array::{GenericArray, typenum::U256};
+use log::warn;
 use tls_codec_derive::{TlsDeserialize, TlsSerialize, TlsSize};
 
 use crate::{TokenType, auth::authorize::Token, common::errors::IssueTokenError};
@@ -40,6 +41,7 @@ impl TokenResponse {
                 token_input,
                 &options,
             )
+            .inspect_err(|e| warn!(error:% = e; "Failed to finalize blind signature"))
             .map_err(|source| IssueTokenError::SignatureFinalizationFailed {
                 token_type,
                 source,

src/public_tokens/server.rs

@@ -3,6 +3,7 @@
 use async_trait::async_trait;
 use blind_rsa_signatures::{KeyPair, Options, PublicKey, Signature};
 use generic_array::ArrayLength;
+use log::{debug, warn};
 use rand::{CryptoRng, RngCore, rngs::OsRng};
 
 use crate::{
@@ -70,6 +71,7 @@ impl IssuerServer {
     ) -> Result<PublicKey, CreateKeypairError> {
         for _ in 0..COLLISION_AVOIDANCE_ATTEMPTS {
             let key_pair = KeyPair::generate(rng, KEYSIZE_IN_BITS)
+                .inspect_err(|e| debug!(error:% = e; "Failed to generate RSA keypair"))
                 .map_err(|source| CreateKeypairError::KeyGenerationFailed { source })?;
             let truncated_token_key_id =
                 truncate_token_key_id(&public_key_to_token_key_id(&key_pair.pk));
@@ -113,6 +115,7 @@ impl IssuerServer {
         let blind_signature = key_pair
             .sk
             .blind_sign(rng, token_request.blinded_msg, &options)
+            .inspect_err(|e| warn!(error:% = e; "Failed to blind_sign token"))
             .map_err(|source| IssueTokenResponseError::BlindSignatureFailed { source })?;
 
         debug_assert!(blind_signature.len() == NK);
@@ -189,6 +192,7 @@ impl OriginServer {
         let verified = public_keys.iter().any(|public_key| {
             signature
                 .verify(public_key, None, &token_input_bytes, &options)
+                .inspect_err(|e| warn!(error:% = e; "Verify failed"))
                 .is_ok()
         });