From 1f5be7fcd9320789a316b21b408ce2639ef86edf Mon Sep 17 00:00:00 2001 From: "J.C. Jones" Date: Mon, 1 Dec 2025 15:35:24 -0700 Subject: [PATCH] Add structured logging of all previously-swallowed errors This change pulls in the log facade with its key-value feature, and then uses `inspect_err` before each call to `map_err` (and `is_ok`) to get the errors surfaced, should a user want to see them. I chose `warn!` for most of the errors, and `debug!` primarily for construction/generation tasks, where failures may be less surprising. I'm not committed to any of the levels, and happy to remove any that you think aren't useful. --- Cargo.toml | 1 + src/amortized_tokens/response.rs | 7 ++++++- src/amortized_tokens/server.rs | 11 +++++++++-- src/private_tokens/response.rs | 4 ++++ src/private_tokens/server.rs | 8 +++++++- src/public_tokens/request.rs | 2 ++ src/public_tokens/response.rs | 2 ++ src/public_tokens/server.rs | 4 ++++ 8 files changed, 35 insertions(+), 4 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 9edfe8c..719ce96 100644 --- a/Cargo.toml +++ b/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" diff --git a/src/amortized_tokens/response.rs b/src/amortized_tokens/response.rs index 9e046de..b414544 100644 --- a/src/amortized_tokens/response.rs +++ b/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}; @@ -64,14 +65,16 @@ impl AmortizedBatchTokenResponse { token_state: &TokenState, ) -> Result>, IssueTokenError> { let mut evaluated_elements = Vec::new(); - for element in self.evaluated_elements.iter() { + for (idx, element) in self.evaluated_elements.iter().enumerate() { let evaluated_element = EvaluationElement::::deserialize(&element.evaluated_element) + .inspect_err(|e| warn!(error:% = e, index = idx; "Failed to deserialize evaluated element")) .map_err(|_| IssueTokenError::InvalidTokenResponse)?; evaluated_elements.push(evaluated_element); } let proof = Proof::deserialize(&self.evaluated_proof) + .inspect_err(|e| warn!(error:% = e; "Failed to deserialize proof")) .map_err(|_| IssueTokenError::InvalidTokenResponse)?; let client_batch_finalize_result = VoprfClient::batch_finalize( @@ -85,8 +88,10 @@ impl AmortizedBatchTokenResponse { &proof, token_state.public_key, ) + .inspect_err(|e| warn!(error:% = e; "Failed to batch finalize")) .map_err(|_| IssueTokenError::InvalidTokenResponse)? .collect::>>() + .inspect_err(|e| warn!(error:% = e; "Failed to collect finalized tokens")) .map_err(|_| IssueTokenError::InvalidTokenResponse)?; let mut tokens = Vec::new(); diff --git a/src/amortized_tokens/server.rs b/src/amortized_tokens/server.rs index 81e23b1..f12d6cc 100644 --- a/src/amortized_tokens/server.rs +++ b/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; @@ -30,7 +31,9 @@ impl Server { ::Scalar: Send + Sync, ::Elem: Send + Sync, { - VoprfServer::::new_from_seed(seed, info).map_err(|_| CreateKeypairError::SeedError) + VoprfServer::::new_from_seed(seed, info) + .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server from seed")) + .map_err(|_| CreateKeypairError::SeedError) } /// Create a new server. The new server does not contain any key material. @@ -111,8 +114,9 @@ impl Server { .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::::deserialize(&element.blinded_element) + .inspect_err(|e| warn!(error:% = e, index = idx; "Failed to deserialize blinded element")) .map_err(|_| IssueTokenResponseError::InvalidTokenRequest)?; blinded_elements.push(blinded_element); } @@ -122,6 +126,7 @@ impl Server { .collect::>(); 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(|_| IssueTokenResponseError::InvalidTokenRequest)?; let evaluated_elements = messages @@ -171,6 +176,7 @@ impl Server { .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(|_| RedeemTokenError::InvalidToken)? .to_vec(); if token.authenticator() == token_authenticator { @@ -193,6 +199,7 @@ impl Server { ::Elem: Send + Sync, { let server = VoprfServer::::new_with_key(private_key) + .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server with key")) .map_err(|_| CreateKeypairError::SeedError)?; let public_key = server.get_public_key(); let token_key_id = public_key_to_token_key_id::(&server.get_public_key()); diff --git a/src/private_tokens/response.rs b/src/private_tokens/response.rs index a425e6d..0dae294 100644 --- a/src/private_tokens/response.rs +++ b/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::*; @@ -96,8 +97,10 @@ impl TokenResponse { token_state: &TokenState, ) -> Result, IssueTokenError> { let evaluation_element = EvaluationElement::deserialize(&self.evaluate_msg) + .inspect_err(|e| warn!(error:% = e; "Failed to deserialize evaluation element")) .map_err(|_| IssueTokenError::InvalidTokenResponse)?; let proof = Proof::deserialize(&self.evaluate_proof) + .inspect_err(|e| warn!(error:% = e; "Failed to deserialize proof")) .map_err(|_| IssueTokenError::InvalidTokenResponse)?; let token_input = token_state.token_input.serialize(); // authenticator = client_context.Finalize(token_input, blind, evaluated_element, blinded_element, proof) @@ -109,6 +112,7 @@ impl TokenResponse { &proof, token_state.public_key, ) + .inspect_err(|e| warn!(error:% = e; "Failed to finalize token")) .map_err(|_| IssueTokenError::InvalidTokenResponse)?; let authenticator = GenericArray::from_slice(authenticator.as_ref()).clone(); diff --git a/src/private_tokens/server.rs b/src/private_tokens/server.rs index fa90ab2..5f0d6f4 100644 --- a/src/private_tokens/server.rs +++ b/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; @@ -27,7 +28,9 @@ pub struct Server { impl Server { fn server_from_seed(seed: &[u8], info: &[u8]) -> Result, CreateKeypairError> { - VoprfServer::::new_from_seed(seed, info).map_err(|_| CreateKeypairError::SeedError) + VoprfServer::::new_from_seed(seed, info) + .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server from seed")) + .map_err(|_| CreateKeypairError::SeedError) } /// Creates a new server. @@ -99,6 +102,7 @@ impl Server { .await .ok_or(IssueTokenResponseError::KeyIdNotFound)?; let blinded_element = BlindedElement::::deserialize(&token_request.blinded_msg) + .inspect_err(|e| warn!(error:% = e; "Failed to deserialize blinded element")) .map_err(|_| IssueTokenResponseError::InvalidTokenRequest)?; let evaluated_result = server.blind_evaluate(&mut OsRng, &blinded_element); @@ -142,6 +146,7 @@ impl Server { .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(|_| RedeemTokenError::InvalidToken)? .to_vec(); if token.authenticator() == token_authenticator { @@ -160,6 +165,7 @@ impl Server { private_key: &[u8], ) -> Result, CreateKeypairError> { let server = VoprfServer::::new_with_key(private_key) + .inspect_err(|e| debug!(error:% = e; "Failed to create VOPRF server with key")) .map_err(|_| CreateKeypairError::SeedError)?; let public_key = server.get_public_key(); let truncated_token_key_id = diff --git a/src/public_tokens/request.rs b/src/public_tokens/request.rs index d64b165..8205e4b 100644 --- a/src/public_tokens/request.rs +++ b/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}; @@ -65,6 +66,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(|_| IssueTokenRequestError::BlindingError)?; debug_assert!(blinding_result.blind_msg.len() == NK); diff --git a/src/public_tokens/response.rs b/src/public_tokens/response.rs index 1d1ab4e..b4d24c6 100644 --- a/src/public_tokens/response.rs +++ b/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}; @@ -39,6 +40,7 @@ impl TokenResponse { token_input, &options, ) + .inspect_err(|e| warn!(error:% = e; "Failed to finalize blind signature")) .map_err(|_| IssueTokenError::InvalidTokenResponse)?; let authenticator: GenericArray = *GenericArray::from_slice(&signature[0..256]); Ok(Token::new( diff --git a/src/public_tokens/server.rs b/src/public_tokens/server.rs index 42b9370..3fb202e 100644 --- a/src/public_tokens/server.rs +++ b/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 { 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(|_| CreateKeypairError::SeedError)?; let truncated_token_key_id = truncate_token_key_id(&public_key_to_token_key_id(&key_pair.pk)); @@ -110,6 +112,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(|_| IssueTokenResponseError::InvalidTokenRequest)?; debug_assert!(blind_signature.len() == NK); @@ -178,6 +181,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() });