feat(tracing): add structured tracing instrumentation across workspace

Cargo.toml

@@ -50,6 +50,7 @@ serde_urlencoded = "0.7"
 serde_with = "3.0"
 tokio = { version = "1.46", features = ["rt", "macros", "rt-multi-thread"] }
 thiserror = "1.0"
+tracing = { version = "0.1", default-features = false, features = ["attributes", "std", "log"] }
 url = { version = "2", features = ["serde"] }
 utoipa = "5.5"
 

oid4vc-core/Cargo.toml

@@ -30,6 +30,7 @@ serde.workspace = true
 serde_json = "1.0"
 serde_urlencoded.workspace = true
 serde_with = "2.3"
+tracing.workspace = true
 url.workspace = true
 
 [dev-dependencies]

oid4vc-core/src/authorization_request.rs

@@ -143,6 +143,7 @@ impl<B: Body + DeserializeOwned> std::str::FromStr for AuthorizationRequest<B> {
 
     fn from_str(s: &str) -> Result<Self, Self::Err> {
         let url = url::Url::parse(s)?;
+        tracing::debug!(scheme = %url.scheme(), "Parsing AuthorizationRequest from URL string");
         let query = url.query().ok_or_else(|| anyhow::anyhow!("No query found."))?;
         let map = serde_urlencoded::from_str::<JsonObject>(query)?
             .into_iter()

oid4vc-core/src/jwt.rs

@@ -31,23 +31,26 @@ where
     }
 }
 
+#[tracing::instrument(level = "trace", err, skip(jwt))]
 pub fn extract_header(jwt: &str) -> Result<(String, Algorithm)> {
     let header = jsonwebtoken::decode_header(jwt)?;
     if let Some(kid) = header.kid {
+        tracing::trace!(algorithm = ?header.alg, %kid, "Extracted JWT header");
         Ok((kid, header.alg))
     } else {
         Err(anyhow!("No key identifier found in the header."))
     }
 }
 
+#[tracing::instrument(level = "debug", err, skip(jwt, public_key))]
 pub fn decode<T>(jwt: &str, public_key: Vec<u8>, algorithm: Algorithm) -> Result<T>
 where
     T: DeserializeOwned,
 {
     let decoding_key = match algorithm {
         Algorithm::EdDSA => DecodingKey::from_ed_der(public_key.as_slice()),
         Algorithm::ES256 => DecodingKey::from_ec_der(public_key.as_slice()),
-        _ => return Err(anyhow!("Unsupported algorithm.")),
+        _ => return Err(anyhow!("Unsupported algorithm {algorithm:?}")),
     };
 
     let mut validation = Validation::new(algorithm);
@@ -57,6 +60,7 @@ where
     Ok(jsonwebtoken::decode::<T>(jwt, &decoding_key, &validation)?.claims)
 }
 
+#[tracing::instrument(level = "debug", err, skip(signer, claims))]
 pub async fn encode<C, S>(signer: Arc<S>, header: Header, claims: C, subject_syntax_type: &str) -> Result<String>
 where
     C: Serialize,
@@ -66,7 +70,9 @@ where
     let kid = signer
         .key_id(subject_syntax_type, algorithm)
         .await
-        .ok_or(anyhow!("No key identifier found."))?;
+        .ok_or_else(|| anyhow!("No key identifier found for signer ({algorithm:?}, {subject_syntax_type})"))?;
+
+    tracing::debug!(?algorithm, %kid, %subject_syntax_type, "Encoding and signing JWT");
 
     let jwt = JsonWebToken::new(header, claims).kid(kid);
 

oid4vc-core/src/utils/did.rs

@@ -9,6 +9,7 @@ use jsonwebtoken::decode_header;
 ///
 /// Returns an error if the JWT header cannot be decoded, if `kid` is missing,
 /// or if a relative `kid` cannot be expanded because `iss` is missing or not a string.
+#[tracing::instrument(level = "debug", err, skip(jwt))]
 pub fn extract_normalized_did_kid_from_jwt(jwt: &str) -> Result<String, anyhow::Error> {
     let jwt = sd_jwt_to_jwt(jwt);
 
@@ -25,7 +26,16 @@ pub fn extract_normalized_did_kid_from_jwt(jwt: &str) -> Result<String, anyhow::
             .as_str()
             .ok_or_else(|| anyhow::anyhow!("'iss' claim is not a string"))?;
 
-        key_id = format!("{iss}{key_id}");
+        let full_key_id = format!("{iss}{key_id}");
+        tracing::debug!(
+            relative_kid = %key_id,
+            iss = %iss,
+            normalized_kid = %full_key_id,
+            "Normalized relative KID using 'iss' claim"
+        );
+        key_id = full_key_id;
+    } else {
+        tracing::debug!(kid = %key_id, "Extracted absolute DID KID from JWT header");
     }
 
     Ok(key_id)

oid4vc-core/src/verifier.rs

@@ -10,9 +10,12 @@ use identity_verification::{
 pub struct SignatureVerifier;
 
 impl JwsVerifier for SignatureVerifier {
+    #[tracing::instrument(level = "debug", err, skip(self, input, public_key))]
     fn verify(&self, input: VerificationInput, public_key: &Jwk) -> Result<(), SignatureVerificationError> {
         use JwsAlgorithm::*;
 
+        tracing::debug!(algorithm = ?input.alg, "Verifying JWS signature");
+
         match input.alg {
             EdDSA => EdDSAJwsVerifier::default().verify(input, public_key),
             ES256 | ES256K => EcDSAJwsVerifier::default().verify(input, public_key),

oid4vc-manager/Cargo.toml

@@ -32,6 +32,7 @@ serde_urlencoded.workspace = true
 serde_with.workspace = true
 tokio.workspace = true
 tower-http = { version = "0.4", features = ["cors"] }
+tracing.workspace = true
 url.workspace = true
 
 [dev-dependencies]

oid4vc-manager/src/managers/provider.rs

@@ -28,6 +28,7 @@ impl ProviderManager {
     }
 
     pub async fn validate_request(&self, authorization_request: String) -> Result<AuthorizationRequest<Object>> {
+        tracing::debug!("ProviderManager: validating request");
         self.provider.validate_request(authorization_request).await
     }
 
@@ -54,13 +55,15 @@ impl ProviderManager {
         authorization_request: &AuthorizationRequest<Object<E>>,
         input: <E::ResponseHandle as ResponseHandle>::Input,
     ) -> Result<AuthorizationResponse<E>> {
+        tracing::debug!("ProviderManager: generating response");
         self.provider.generate_response(authorization_request, input).await
     }
 
     pub async fn send_response<E: Extension>(
         &self,
         authorization_response: &AuthorizationResponse<E>,
     ) -> Result<StatusCode> {
+        tracing::debug!("ProviderManager: sending response");
         self.provider.send_response(authorization_response).await
     }
 

oid4vc-manager/src/managers/relying_party.rs

@@ -32,6 +32,7 @@ impl RelyingPartyManager {
         &self,
         authorization_request: &AuthorizationRequest<Object<E>>,
     ) -> Result<String> {
+        tracing::debug!("RelyingPartyManager: encoding authorization request");
         self.relying_party
             .encode(
                 authorization_request,
@@ -50,6 +51,7 @@ impl RelyingPartyManager {
         &self,
         authorization_response: &AuthorizationResponse<E>,
     ) -> Result<<E::ResponseHandle as ResponseHandle>::ResponseItem> {
+        tracing::debug!("RelyingPartyManager: validating authorization response");
         #[allow(deprecated)]
         self.relying_party.validate_response(authorization_response).await
     }

oid4vci/Cargo.toml

@@ -33,6 +33,7 @@ serde_urlencoded.workspace = true
 serde_with.workspace = true
 tokio.workspace = true
 thiserror.workspace = true
+tracing.workspace = true
 url.workspace = true
 utoipa = { workspace = true, optional = true }
 

oid4vci/src/proof.rs

@@ -63,6 +63,14 @@ impl ProofBuilder {
             .subject_syntax_type
             .ok_or(anyhow::anyhow!("subject_syntax_type is required"))?;
 
+        tracing::debug!(
+            proof_type = ?self.proof_type,
+            algorithm = ?self.algorithm,
+            subject_syntax_type = %subject_syntax_type,
+            has_nonce = self.nonce.is_some(),
+            "Building key possession proof for credential request"
+        );
+
         match self.proof_type {
             Some(ProofType::Jwt) => Ok(Proof::Jwt {
                 jwt: jwt::encode(