New logging output

Cargo.toml

@@ -30,6 +30,7 @@ broken_intra_doc_links = "deny"
 mas-axum-utils = { path = "./crates/axum-utils/", version = "=0.15.0" }
 mas-cli = { path = "./crates/cli/", version = "=0.15.0" }
 mas-config = { path = "./crates/config/", version = "=0.15.0" }
+mas-context = { path = "./crates/context/", version = "=0.15.0" }
 mas-data-model = { path = "./crates/data-model/", version = "=0.15.0" }
 mas-email = { path = "./crates/email/", version = "=0.15.0" }
 mas-graphql = { path = "./crates/graphql/", version = "=0.15.0" }
@@ -111,6 +112,10 @@ version = "1.1.9"
 [workspace.dependencies.compact_str]
 version = "0.9.0"
 
+# Terminal formatting
+[workspace.dependencies.console]
+version = "0.15.11"
+
 # Time utilities
 [workspace.dependencies.chrono]
 version = "0.4.40"
@@ -248,6 +253,10 @@ features = ["std"]
 version = "0.7.0"
 features = ["std"]
 
+# Pin projection
+[workspace.dependencies.pin-project-lite]
+version = "0.2.16"
+
 # PKCS#1 encoding
 [workspace.dependencies.pkcs1]
 version = "0.7.5"
@@ -258,6 +267,10 @@ features = ["std"]
 version = "0.10.2"
 features = ["std", "pkcs5", "encryption"]
 
+# High-precision clock
+[workspace.dependencies.quanta]
+version = "0.12.5"
+
 # Random values
 [workspace.dependencies.rand]
 version = "0.8.5"
@@ -374,6 +387,14 @@ features = ["rt"]
 version = "0.5.2"
 features = ["util"]
 
+# Tower service trait
+[workspace.dependencies.tower-service]
+version = "0.3.3"
+
+# Tower layer trait
+[workspace.dependencies.tower-layer]
+version = "0.3.3"
+
 # Tower HTTP layers
 [workspace.dependencies.tower-http]
 version = "0.6.2"

crates/axum-utils/src/client_authorization.rs

@@ -28,6 +28,8 @@ use serde::{Deserialize, de::DeserializeOwned};
 use serde_json::Value;
 use thiserror::Error;
 
+use crate::record_error;
+
 static JWT_BEARER_CLIENT_ASSERTION: &str = "urn:ietf:params:oauth:client-assertion-type:jwt-bearer";
 
 #[derive(Deserialize)]
@@ -97,7 +99,7 @@ impl Credentials {
     /// # Errors
     ///
     /// Returns an error if the credentials are invalid.
-    #[tracing::instrument(skip_all, err)]
+    #[tracing::instrument(skip_all)]
     pub async fn verify(
         &self,
         http_client: &reqwest::Client,
@@ -144,7 +146,7 @@ impl Credentials {
 
                 let jwks = fetch_jwks(http_client, jwks)
                     .await
-                    .map_err(|_| CredentialsVerificationError::JwksFetchFailed)?;
+                    .map_err(CredentialsVerificationError::JwksFetchFailed)?;
 
                 jwt.verify_with_jwks(&jwks)
                     .map_err(|_| CredentialsVerificationError::InvalidAssertionSignature)?;
@@ -214,7 +216,18 @@ pub enum CredentialsVerificationError {
     InvalidAssertionSignature,
 
     #[error("failed to fetch jwks")]
-    JwksFetchFailed,
+    JwksFetchFailed(#[source] Box<dyn std::error::Error + Send + Sync + 'static>),
+}
+
+impl CredentialsVerificationError {
+    /// Returns true if the error is an internal error, not caused by the client
+    #[must_use]
+    pub fn is_internal(&self) -> bool {
+        matches!(
+            self,
+            Self::DecryptionError | Self::InvalidClientConfig | Self::JwksFetchFailed(_)
+        )
+    }
 }
 
 #[derive(Debug, PartialEq, Eq)]
@@ -231,23 +244,40 @@ impl<F> ClientAuthorization<F> {
     }
 }
 
-#[derive(Debug)]
+#[derive(Debug, Error)]
 pub enum ClientAuthorizationError {
+    #[error("Invalid Authorization header")]
     InvalidHeader,
-    BadForm(FailedToDeserializeForm),
+
+    #[error("Could not deserialize request body")]
+    BadForm(#[source] FailedToDeserializeForm),
+
+    #[error("client_id in form ({form:?}) does not match credential ({credential:?})")]
     ClientIdMismatch { credential: String, form: String },
+
+    #[error("Unsupported client_assertion_type: {client_assertion_type}")]
     UnsupportedClientAssertion { client_assertion_type: String },
+
+    #[error("No credentials were presented")]
     MissingCredentials,
+
+    #[error("Invalid request")]
     InvalidRequest,
+
+    #[error("Invalid client_assertion")]
     InvalidAssertion,
+
+    #[error(transparent)]
     Internal(Box<dyn std::error::Error>),
 }
 
 impl IntoResponse for ClientAuthorizationError {
     fn into_response(self) -> axum::response::Response {
-        match self {
+        let sentry_event_id = record_error!(self, Self::Internal(_));
+        match &self {
             ClientAuthorizationError::InvalidHeader => (
                 StatusCode::BAD_REQUEST,
+                sentry_event_id,
                 Json(ClientError::new(
                     ClientErrorCode::InvalidRequest,
                     "Invalid Authorization header",
@@ -256,39 +286,34 @@ impl IntoResponse for ClientAuthorizationError {
 
             ClientAuthorizationError::BadForm(err) => (
                 StatusCode::BAD_REQUEST,
+                sentry_event_id,
                 Json(
                     ClientError::from(ClientErrorCode::InvalidRequest)
                         .with_description(format!("{err}")),
                 ),
             ),
 
-            ClientAuthorizationError::ClientIdMismatch { form, credential } => {
-                let description = format!(
-                    "client_id in form ({form:?}) does not match credential ({credential:?})"
-                );
-
-                (
-                    StatusCode::BAD_REQUEST,
-                    Json(
-                        ClientError::from(ClientErrorCode::InvalidGrant)
-                            .with_description(description),
-                    ),
-                )
-            }
+            ClientAuthorizationError::ClientIdMismatch { .. } => (
+                StatusCode::BAD_REQUEST,
+                sentry_event_id,
+                Json(
+                    ClientError::from(ClientErrorCode::InvalidGrant)
+                        .with_description(format!("{self}")),
+                ),
+            ),
 
-            ClientAuthorizationError::UnsupportedClientAssertion {
-                client_assertion_type,
-            } => (
+            ClientAuthorizationError::UnsupportedClientAssertion { .. } => (
                 StatusCode::BAD_REQUEST,
+                sentry_event_id,
                 Json(
-                    ClientError::from(ClientErrorCode::InvalidRequest).with_description(format!(
-                        "Unsupported client_assertion_type: {client_assertion_type}",
-                    )),
+                    ClientError::from(ClientErrorCode::InvalidRequest)
+                        .with_description(format!("{self}")),
                 ),
             ),
 
             ClientAuthorizationError::MissingCredentials => (
                 StatusCode::BAD_REQUEST,
+                sentry_event_id,
                 Json(ClientError::new(
                     ClientErrorCode::InvalidRequest,
                     "No credentials were presented",
@@ -297,11 +322,13 @@ impl IntoResponse for ClientAuthorizationError {
 
             ClientAuthorizationError::InvalidRequest => (
                 StatusCode::BAD_REQUEST,
+                sentry_event_id,
                 Json(ClientError::from(ClientErrorCode::InvalidRequest)),
             ),
 
             ClientAuthorizationError::InvalidAssertion => (
                 StatusCode::BAD_REQUEST,
+                sentry_event_id,
                 Json(ClientError::new(
                     ClientErrorCode::InvalidRequest,
                     "Invalid client_assertion",
@@ -310,6 +337,7 @@ impl IntoResponse for ClientAuthorizationError {
 
             ClientAuthorizationError::Internal(e) => (
                 StatusCode::INTERNAL_SERVER_ERROR,
+                sentry_event_id,
                 Json(
                     ClientError::from(ClientErrorCode::ServerError)
                         .with_description(format!("{e}")),

crates/axum-utils/src/error_wrapper.rs

@@ -7,17 +7,25 @@
 use axum::response::{IntoResponse, Response};
 use http::StatusCode;
 
+use crate::record_error;
+
 /// A simple wrapper around an error that implements [`IntoResponse`].
 #[derive(Debug, thiserror::Error)]
 #[error(transparent)]
 pub struct ErrorWrapper<T>(#[from] pub T);
 
 impl<T> IntoResponse for ErrorWrapper<T>
 where
-    T: std::error::Error,
+    T: std::error::Error + 'static,
 {
     fn into_response(self) -> Response {
         // TODO: make this a bit more user friendly
-        (StatusCode::INTERNAL_SERVER_ERROR, self.0.to_string()).into_response()
+        let sentry_event_id = record_error!(self.0);
+        (
+            StatusCode::INTERNAL_SERVER_ERROR,
+            sentry_event_id,
+            self.0.to_string(),
+        )
+            .into_response()
     }
 }

crates/axum-utils/src/fancy_error.rs

@@ -54,12 +54,13 @@ impl<E: std::fmt::Debug + std::fmt::Display> From<E> for FancyError {
 
 impl IntoResponse for FancyError {
     fn into_response(self) -> Response {
+        tracing::error!(message = %self.context);
         let error = format!("{}", self.context);
-        let event_id = sentry::capture_message(&error, sentry::Level::Error);
+        let event_id = SentryEventID::for_last_event();
         (
             StatusCode::INTERNAL_SERVER_ERROR,
             TypedHeader(ContentType::text()),
-            SentryEventID::from(event_id),
+            event_id,
             Extension(self.context),
             error,
         )

crates/axum-utils/src/sentry.rs

@@ -13,6 +13,13 @@ use sentry::types::Uuid;
 #[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]
 pub struct SentryEventID(Uuid);
 
+impl SentryEventID {
+    /// Create a new Sentry event ID header for the last event on the hub.
+    pub fn for_last_event() -> Option<Self> {
+        sentry::last_event_id().map(Self)
+    }
+}
+
 impl From<Uuid> for SentryEventID {
     fn from(uuid: Uuid) -> Self {
         Self(uuid)
@@ -28,3 +35,31 @@ impl IntoResponseParts for SentryEventID {
         Ok(res)
     }
 }
+
+/// Record an error. It will emit a tracing event with the error level if
+/// matches the pattern, warning otherwise. It also returns the Sentry event ID
+/// if the error was recorded.
+#[macro_export]
+macro_rules! record_error {
+    ($error:expr, !) => {{
+        tracing::warn!(message = &$error as &dyn std::error::Error);
+        Option::<$crate::sentry::SentryEventID>::None
+    }};
+
+    ($error:expr) => {{
+        tracing::error!(message = &$error as &dyn std::error::Error);
+
+        // With the `sentry-tracing` integration, Sentry should have
+        // captured an error, so let's extract the last event ID from the
+        // current hub
+        $crate::sentry::SentryEventID::for_last_event()
+    }};
+
+    ($error:expr, $pattern:pat) => {
+        if let $pattern = $error {
+            record_error!($error)
+        } else {
+            record_error!($error, !)
+        }
+    };
+}

crates/cli/Cargo.toml

@@ -27,6 +27,7 @@ dialoguer = { version = "0.11.0", default-features = false, features = [
 dotenvy = "0.15.7"
 figment.workspace = true
 futures-util.workspace = true
+headers.workspace = true
 http-body-util.workspace = true
 hyper.workspace = true
 ipnetwork = "0.20.0"
@@ -66,6 +67,7 @@ sentry-tracing.workspace = true
 sentry-tower.workspace = true
 
 mas-config.workspace = true
+mas-context.workspace = true
 mas-data-model.workspace = true
 mas-email.workspace = true
 mas-handlers.workspace = true