feat: log when Sentry is not configured (#2073)

* feat: log when Sentry is not configured

* Update syncserver-common/src/middleware/sentry.rs

Co-authored-by: Philip Jenvey <pjenvey@underboss.org>

* warn and optionally print backtrace

* Use error!

* panic!

* Cleanup and comment

* Cargo.lock

---------

Co-authored-by: Philip Jenvey <pjenvey@underboss.org>

Author: chenba

Cargo.lock

@@ -89,6 +89,7 @@ slog-mozlog-json = "0.1"
 slog-scope = "4.4"
 slog-stdlog = "4.1"
 slog-term = "2.9"
+temp-env = { version = "0.3", features = ["async_closure"] }
 tokio = "1"
 thiserror = "1.0.69"
 time = "0.3.47"

Cargo.toml

@@ -1,4 +1,4 @@
-use std::{cell::RefCell, collections::BTreeMap, marker::PhantomData, rc::Rc, sync::Arc};
+use std::{cell::RefCell, collections::BTreeMap, env, marker::PhantomData, rc::Rc, sync::Arc};
 
 use actix_web::{
     Error,
@@ -15,13 +15,20 @@ use crate::{ReportableError, Taggable};
 pub struct SentryWrapper<E> {
     metrics: Arc<StatsdClient>,
     phantom: PhantomData<E>,
+    sentry_enabled: bool,
+    backtrace_enabled: bool,
 }
 
 impl<E> SentryWrapper<E> {
     pub fn new(metrics: Arc<StatsdClient>) -> Self {
+        let sentry_enabled = env::var("SENTRY_DSN").is_ok_and(|dsn| !dsn.is_empty());
+        let backtrace_enabled = env::var("RUST_BACKTRACE").is_ok_and(|v| v == "1" || v == "full");
+
         Self {
             metrics,
             phantom: PhantomData,
+            sentry_enabled,
+            backtrace_enabled,
         }
     }
 }
@@ -43,6 +50,8 @@ where
             service: Rc::new(RefCell::new(service)),
             metrics: self.metrics.clone(),
             phantom: PhantomData,
+            sentry_enabled: self.sentry_enabled,
+            backtrace_enabled: self.backtrace_enabled,
         })
     }
 }
@@ -52,6 +61,8 @@ pub struct SentryWrapperMiddleware<S, E> {
     service: Rc<RefCell<S>>,
     metrics: Arc<StatsdClient>,
     phantom: PhantomData<E>,
+    sentry_enabled: bool,
+    backtrace_enabled: bool,
 }
 
 impl<S, B, E> Service<ServiceRequest> for SentryWrapperMiddleware<S, E>
@@ -77,6 +88,8 @@ where
 
         // get the tag information
         let metrics = self.metrics.clone();
+        let sentry_enabled = self.sentry_enabled;
+        let backtrace_enabled = self.backtrace_enabled;
         let tags = sreq.get_tags();
         let extras = sreq.get_extras();
 
@@ -99,12 +112,19 @@ where
                         }
                     };
                     debug!("Reporting error to Sentry (service error): {}", error);
+
                     let mut event = event_from_actix_error::<E>(&error);
                     // Add in the tags from the request
                     event.tags.extend(tags);
                     event.extra.extend(extras);
-                    let event_id = hub.capture_event(event);
-                    trace!("event_id = {}", event_id);
+
+                    if sentry_enabled {
+                        let event_id = hub.capture_event(event);
+                        trace!("event_id = {}", event_id);
+                    } else {
+                        // log if Sentry is not configured
+                        log_event::<E>(&event, &error, backtrace_enabled);
+                    }
                     return Err(error);
                 }
             };
@@ -118,9 +138,16 @@ where
                     return Ok(response);
                 }
                 debug!("Reporting error to Sentry (response error): {}", error);
+
                 let event = event_from_actix_error::<E>(error);
-                let event_id = hub.capture_event(event);
-                trace!("event_id = {}", event_id);
+
+                if sentry_enabled {
+                    let event_id = hub.capture_event(event);
+                    trace!("event_id = {}", event_id);
+                } else {
+                    // log if Sentry is not configured
+                    log_event::<E>(&event, error, backtrace_enabled);
+                }
             }
             Ok(response)
         }
@@ -266,3 +293,42 @@ pub fn exception_from_reportable_error(err: &dyn ReportableError) -> sentry::pro
         ..Default::default()
     }
 }
+
+/// Log the error event instead when Sentry is not configured.
+fn log_event<E>(
+    event: &sentry::protocol::Event<'static>,
+    error: &actix_web::Error,
+    backtrace_enabled: bool,
+) where
+    E: ReportableError + actix_web::ResponseError + 'static,
+{
+    let first_exception = event.exception.last();
+    let error_type = first_exception.map_or("UnknownError", |e| e.ty.as_str());
+    let error_value = first_exception
+        .and_then(|e| e.value.as_deref())
+        .unwrap_or("No error message");
+
+    let backtrace = if backtrace_enabled {
+        error
+            .as_error::<E>()
+            .and_then(|e| e.backtrace())
+            .map(|bt| format!("\n{bt:?}"))
+            .unwrap_or_default()
+    } else {
+        String::new()
+    };
+
+    error!(
+        "{}{}", error_value, backtrace;
+        "error_type" => error_type,
+        "tags" => ?event.tags,
+        "extra" => ?event.extra,
+        "url" => event.request.as_ref()
+            .and_then(|r| r.url.as_ref())
+            .map(|u| u.to_string())
+            .unwrap_or_default(),
+        "method" => event.request.as_ref()
+            .and_then(|r| r.method.as_deref())
+            .unwrap_or(""),
+    );
+}

syncserver-common/src/middleware/sentry.rs

@@ -17,4 +17,4 @@ tokenserver-settings = { path = "../tokenserver-settings" }
 url = "2.5"
 
 [dev-dependencies]
-temp-env = "0.3"
+temp-env.workspace = true

syncserver-settings/Cargo.toml

@@ -59,6 +59,9 @@ validator = "0.20"
 validator_derive = "0.20"
 woothee = "0.13"
 
+[dev-dependencies]
+temp-env.workspace = true
+
 [target.'cfg(target_os = "linux")'.dependencies]
 slog-journald = "2.2.0"
 

syncserver/Cargo.toml

@@ -1,5 +1,4 @@
-use std::collections::HashMap;
-use std::str::FromStr;
+use std::{collections::HashMap, env, str::FromStr};
 
 use actix_web::{
     dev::Service,
@@ -841,3 +840,56 @@ async fn lbheartbeat_ttl_check() {
     let sresp = app.call(lb_req).await.unwrap();
     assert_eq!(sresp.status(), StatusCode::INTERNAL_SERVER_ERROR);
 }
+
+#[actix_rt::test]
+async fn error_endpoint_logging_check() {
+    use slog::Drain as _;
+    use std::io::Write;
+    use std::sync::{Arc, Mutex};
+
+    temp_env::async_with_vars(
+        [("SENTRY_DSN", None::<&str>), ("RUST_BACKTRACE", Some("1"))],
+        async {
+            let app = init_app!().await;
+
+            struct CaptureDrain(Arc<Mutex<Vec<u8>>>);
+            impl slog::Drain for CaptureDrain {
+                type Ok = ();
+                type Err = std::io::Error;
+
+                fn log(
+                    &self,
+                    record: &slog::Record<'_>,
+                    _values: &slog::OwnedKVList,
+                ) -> Result<Self::Ok, Self::Err> {
+                    let mut buf = self.0.lock().unwrap();
+                    writeln!(buf, "{}", record.msg())?;
+                    Ok(())
+                }
+            }
+
+            let buffer = Arc::new(Mutex::new(Vec::new()));
+            let drain = CaptureDrain(buffer.clone()).fuse();
+            let logger = slog::Logger::root(drain, slog::o!());
+            let _guard = slog_scope::set_global_logger(logger);
+
+            let req = test::TestRequest::get().uri("/__error__").to_request();
+            let resp = test::call_service(&app, req).await;
+
+            assert_eq!(resp.status(), StatusCode::INTERNAL_SERVER_ERROR);
+
+            let log_msg = String::from_utf8(buffer.lock().unwrap().clone()).unwrap();
+
+            assert!(
+                log_msg.contains("Oh Noes!"),
+                "Unexpected error message: {log_msg}",
+            );
+            // Look for the fn name in the backtrace.
+            assert!(
+                log_msg.contains("test_error"),
+                "Unexpected error message: {log_msg}",
+            );
+        },
+    )
+    .await;
+}

syncserver/src/server/test.rs

@@ -1,6 +1,7 @@
 //! API Handlers
 use std::collections::HashMap;
 use std::convert::Into;
+use std::thread;
 use std::time::{Duration, Instant};
 
 use crate::server::user_agent::{DeviceInfo, get_device_info};
@@ -908,5 +909,9 @@ pub async fn test_error(
     error!("Test Error");
     let err = ApiError::from(ApiErrorKind::Internal("Oh Noes!".to_owned()));
 
+    thread::spawn(|| {
+        panic!("TestError");
+    });
+
     Err(err)
 }