add test for api_client slow API call logging (#127)

cli-tests/src/upload.rs

@@ -17,7 +17,7 @@ use lazy_static::lazy_static;
 use tempfile::tempdir;
 use test_utils::{
     mock_git_repo::setup_repo_with_commit,
-    mock_server::{spawn_mock_server, RequestPayload},
+    mock_server::{MockServerBuilder, RequestPayload},
 };
 use trunk_analytics_cli::{
     codeowners::CodeOwners,
@@ -63,7 +63,7 @@ async fn upload_bundle() {
     generate_mock_junit_xmls(&temp_dir);
     generate_mock_codeowners(&temp_dir);
 
-    let state = spawn_mock_server().await;
+    let state = MockServerBuilder::new().spawn_mock_server().await;
 
     let assert = Command::new(CARGO_RUN.path())
         .current_dir(&temp_dir)
@@ -211,7 +211,7 @@ async fn upload_bundle_no_files() {
     let temp_dir = tempdir().unwrap();
     generate_mock_git_repo(&temp_dir);
 
-    let state = spawn_mock_server().await;
+    let state = MockServerBuilder::new().spawn_mock_server().await;
 
     let assert = Command::new(CARGO_RUN.path())
         .current_dir(&temp_dir)
@@ -239,7 +239,7 @@ async fn upload_bundle_no_files_allow_missing_junit_files() {
     let temp_dir = tempdir().unwrap();
     generate_mock_git_repo(&temp_dir);
 
-    let state = spawn_mock_server().await;
+    let state = MockServerBuilder::new().spawn_mock_server().await;
 
     let assert = Command::new(CARGO_RUN.path())
         .current_dir(&temp_dir)

cli/Cargo.toml

@@ -46,7 +46,9 @@ uuid = { version = "1.10.0", features = ["v5"] }
 quick-junit = "0.5.0"
 
 [dev-dependencies]
+axum = { version = "0.7.5", features = ["macros"] }
 lazy_static = "1.5.0"
+test_utils = { path = "../test_utils" }
 tokio = { version = "*", default-features = false, features = [
   "rt-multi-thread",
   "macros",

cli/src/api_client/mod.rs

@@ -274,3 +274,61 @@ fn status_code_help<T: FnMut(&Response) -> String>(
 
     Err(anyhow::Error::msg(error_message_with_help))
 }
+
+#[cfg(test)]
+mod tests {
+    use std::{env, time::Duration};
+
+    use axum::response::Response;
+    use tempfile::NamedTempFile;
+    use test_utils::{mock_logger, mock_sentry, mock_server::MockServerBuilder};
+    use tokio::time;
+
+    use super::ApiClient;
+
+    #[tokio::test(start_paused = true)]
+    async fn logs_and_reports_for_slow_api_calls() {
+        let mut mock_server_builder = MockServerBuilder::new();
+        let logs = mock_logger(None);
+        let (events, guard) = mock_sentry();
+
+        async fn slow_s3_upload_handler() -> Response<String> {
+            time::sleep(Duration::from_secs(11)).await;
+            Response::new(String::from("OK"))
+        }
+        mock_server_builder.set_s3_upload_handler(slow_s3_upload_handler);
+
+        let state = mock_server_builder.spawn_mock_server().await;
+
+        env::set_var("TRUNK_PUBLIC_API_ADDRESS", &state.host);
+        let api_client = ApiClient::new(String::from("mock-token")).unwrap();
+
+        let bundle_file = NamedTempFile::new().unwrap();
+        api_client
+            .put_bundle_to_s3(format!("{}/s3upload", state.host), bundle_file)
+            .await
+            .unwrap();
+
+        let first_two_slow_s3_upload_logs = logs
+            .lock()
+            .unwrap()
+            .iter()
+            .filter(|(_, message)| message.starts_with("Uploading bundle to S3"))
+            .cloned()
+            .take(2)
+            .collect::<Vec<_>>();
+        assert_eq!(first_two_slow_s3_upload_logs, vec![
+            (log::Level::Info, String::from("Uploading bundle to S3 is taking longer than expected. It has taken 2 seconds so far.")),
+            (log::Level::Info, String::from("Uploading bundle to S3 is taking longer than expected. It has taken 4 seconds so far.")),
+        ]);
+
+        guard.flush(None);
+        assert_eq!(
+            *events.lock().unwrap(),
+            vec![(
+                sentry::Level::Error,
+                String::from("Uploading bundle to S3 is taking longer than 10 seconds"),
+            ),]
+        );
+    }
+}

test_utils/Cargo.toml

@@ -4,11 +4,14 @@ version = "0.1.0"
 edition = "2021"
 
 [dependencies]
-api = { path = "../api" }
 anyhow = "1.0.44"
+api = { path = "../api" }
 axum = { version = "0.7.5", features = ["macros"] }
 git2 = "0.19.0"
 junit-mock = { path = "../junit-mock" }
+lazy_static = "1.4"
+log = { version = "0.4.14", features = ["std"] }
+sentry = "0.34.0"
 tar = { version = "0.4.30", default-features = false }
 tempfile = "3.2.0"
 tokio = { version = "*", default-features = false, features = [

test_utils/src/lib.rs

@@ -1,2 +1,7 @@
 pub mod mock_git_repo;
+mod mock_logger;
+mod mock_sentry;
 pub mod mock_server;
+
+pub use mock_logger::mock_logger;
+pub use mock_sentry::mock_sentry;

test_utils/src/mock_logger.rs

@@ -0,0 +1,48 @@
+use std::sync::{Arc, Mutex};
+
+use lazy_static::lazy_static;
+
+#[derive(Debug, Clone, Default)]
+struct MockLogger {
+    pub logs: Arc<Mutex<Vec<(log::Level, String)>>>,
+}
+
+impl log::Log for MockLogger {
+    fn enabled(&self, _: &log::Metadata) -> bool {
+        true
+    }
+    fn flush(&self) {}
+    fn log(&self, record: &log::Record) {
+        self.logs
+            .lock()
+            .unwrap()
+            .push((record.level(), record.args().to_string()));
+    }
+}
+
+pub fn mock_logger(max_level: Option<log::LevelFilter>) -> Arc<Mutex<Vec<(log::Level, String)>>> {
+    lazy_static! {
+        static ref MOCK_LOGGER: MockLogger = MockLogger::default();
+    }
+
+    log::set_logger(&MOCK_LOGGER as &'static MockLogger).unwrap();
+    log::set_max_level(max_level.unwrap_or(log::LevelFilter::Debug));
+
+    MOCK_LOGGER.logs.clone()
+}
+
+#[cfg(test)]
+mod tests {
+    use super::mock_logger;
+
+    #[test]
+    fn captures_logs() {
+        let logs = mock_logger(None);
+        const TEST_MESSAGE: &str = "test";
+        log::error!("{}", TEST_MESSAGE);
+        assert_eq!(
+            *logs.lock().unwrap(),
+            [(log::Level::Error, String::from(TEST_MESSAGE))]
+        );
+    }
+}

test_utils/src/mock_sentry.rs

@@ -0,0 +1,54 @@
+use std::sync::{Arc, Mutex};
+
+use sentry::{protocol::Event, ClientInitGuard, Integration, Level};
+
+struct MockSentryIntegration {
+    events: Arc<Mutex<Vec<(Level, String)>>>,
+}
+
+impl Integration for MockSentryIntegration {
+    fn process_event(
+        &self,
+        event: Event<'static>,
+        _: &sentry::ClientOptions,
+    ) -> Option<Event<'static>> {
+        self.events
+            .lock()
+            .unwrap()
+            .push((event.level, event.message.unwrap_or_default()));
+        None
+    }
+}
+
+pub fn mock_sentry() -> (Arc<Mutex<Vec<(Level, String)>>>, ClientInitGuard) {
+    let events: Arc<Mutex<Vec<(Level, String)>>> = Default::default();
+
+    let options = sentry::ClientOptions {
+        environment: Some("development".into()),
+        ..Default::default()
+    }
+    .add_integration(MockSentryIntegration {
+        events: events.clone(),
+    });
+
+    let guard = sentry::init(("https://public@sentry.example.com/1", options));
+
+    (events, guard)
+}
+
+#[cfg(test)]
+mod tests {
+    use super::mock_sentry;
+
+    #[test]
+    fn captures_events() {
+        let (events, guard) = mock_sentry();
+        const TEST_MESSAGE: &str = "test";
+        sentry::capture_message(TEST_MESSAGE, sentry::Level::Error);
+        guard.flush(None);
+        assert_eq!(
+            *events.lock().unwrap(),
+            [(sentry::Level::Error, String::from(TEST_MESSAGE))]
+        );
+    }
+}