From bdef1caa1eef11a5dc99dc413fae87054a57e21b Mon Sep 17 00:00:00 2001 From: Amos Jun-yeung Ng Date: Sat, 13 Jan 2024 12:25:31 +1100 Subject: [PATCH 1/2] Make debugging unmatched requests easier --- src/lib.rs | 67 +++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 66 insertions(+), 1 deletion(-) diff --git a/src/lib.rs b/src/lib.rs index 5b19534..7bebae3 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -238,6 +238,13 @@ impl VCRMiddleware { vcr_response } + fn header_values_to_string(&self, header_values: Option<&Vec>) -> String { + match header_values { + Some(values) => values.join(", "), + None => "".to_string(), + } + } + fn find_response_in_vcr(&self, req: vcr_cassette::Request) -> Option { let cassette = self.storage.lock().unwrap(); let iteractions: Vec<&HttpInteraction> = match self.search { @@ -249,11 +256,66 @@ impl VCRMiddleware { VCRReplaySearch::SearchAll => cassette.http_interactions.iter().collect(), }; + // save diff in a string for debugging purposes + let mut diff = String::new(); for interaction in iteractions { if interaction.request == req { return Some(interaction.response.clone()); + } else { + diff.push_str(&format!( + "Unmatched {method:?} to {uri}:\n", + method = interaction.request.method, + uri = interaction.request.uri.as_str() + )); + if interaction.request.method != req.method { + diff.push_str(&format!( + " Method differs: recorded {expected:?}, got {got:?}\n", + expected = interaction.request.method, + got = req.method + )); + } + if interaction.request.uri != req.uri { + diff.push_str(" URI differs:\n"); + diff.push_str(&format!( + " recorded: \"{}\"\n", + interaction.request.uri.as_str() + )); + diff.push_str(&format!(" got: \"{}\"\n", req.uri.as_str())); + } + if interaction.request.headers != req.headers { + diff.push_str(" Headers differ:\n"); + for (recorded_header_name, recorded_header_values) in + &interaction.request.headers + { + let expected = self.header_values_to_string(Some(recorded_header_values)); + let got = + self.header_values_to_string(req.headers.get(recorded_header_name)); + if expected != got { + diff.push_str(&format!(" {}:\n", recorded_header_name)); + diff.push_str(&format!(" recorded: \"{}\"\n", expected)); + diff.push_str(&format!(" got: \"{}\"\n", got)); + } + } + for (got_header_name, got_header_values) in &req.headers { + if !interaction.request.headers.contains_key(got_header_name) { + let got = self.header_values_to_string(Some(got_header_values)); + diff.push_str(&format!(" {}:\n", got_header_name)); + diff.push_str(&format!(" recorded: \n")); + diff.push_str(&format!(" got: \"{}\"\n", got)); + } + } + } + if interaction.request.body != req.body { + diff.push_str(" Body differs:\n"); + diff.push_str(&format!( + " recorded: \"{}\"\n", + interaction.request.body.string + )); + diff.push_str(&format!(" got: \"{}\"\n", req.body.string)); + } } } + eprintln!("{}", diff); None } @@ -328,7 +390,10 @@ impl Middleware for VCRMiddleware { } VCRMode::Replay => { let vcr_response = self.find_response_in_vcr(vcr_request).unwrap_or_else(|| { - panic!("Can not read cassette contents from {:?}", self.path) + panic!( + "Cannot find corresponding request in cassette {:?}", + self.path + ) }); let response = self.vcr_to_response(vcr_response); Ok(response) From f97c4e491c9c8c5bb6529d4b6f2abca18c8b76bd Mon Sep 17 00:00:00 2001 From: Amos Jun-yeung Ng Date: Tue, 27 Feb 2024 17:47:30 +1100 Subject: [PATCH 2/2] Use tracing instead of eprintln!, and add test --- Cargo.toml | 2 ++ src/lib.rs | 54 +++++++++++++++++++++++++++++----------- tests/integration/e2e.rs | 50 +++++++++++++++++++++++++++++++++++++ 3 files changed, 92 insertions(+), 14 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 151aa28..8f469c9 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -24,6 +24,7 @@ compress = ["dep:zip"] [dependencies] +anyhow = "^1" async-trait = "^0.1" base64 = "0.21.0" bytes = "1" @@ -42,5 +43,6 @@ vcr-cassette = "2" [dev-dependencies] tokio = { version = "1.17.0", features = ["full"] } tracing-subscriber = { version = "0.3", features = ["registry", "env-filter"] } +tracing-test = { version = "0.2.4", features = ["no-env-filter"] } url = "2.4" diff --git a/src/lib.rs b/src/lib.rs index 7bebae3..2b01d9a 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -51,6 +51,7 @@ pub struct VCRMiddleware { search: VCRReplaySearch, skip: Mutex, compress: bool, + rich_diff: bool, modify_request: Option>, modify_response: Option>, } @@ -119,6 +120,12 @@ impl VCRMiddleware { self } + /// Adjust rich diff in the middleware and return it + pub fn with_rich_diff(mut self, rich_diff: bool) -> Self { + self.rich_diff = rich_diff; + self + } + /// Make VCR files to be compressed before creating #[cfg(feature = "compress")] pub fn compressed(mut self, compress: bool) -> Self { @@ -256,14 +263,20 @@ impl VCRMiddleware { VCRReplaySearch::SearchAll => cassette.http_interactions.iter().collect(), }; - // save diff in a string for debugging purposes - let mut diff = String::new(); + // we only want to log match failures if no match is found, so capture + // everything at the beginning and then output it all at once if none + // are found + let mut diff_log = if self.rich_diff { + Some(String::new()) + } else { + None + }; for interaction in iteractions { if interaction.request == req { return Some(interaction.response.clone()); - } else { + } else if let Some(diff) = diff_log.as_mut() { diff.push_str(&format!( - "Unmatched {method:?} to {uri}:\n", + "Did not match {method:?} to {uri}:\n", method = interaction.request.method, uri = interaction.request.uri.as_str() )); @@ -313,9 +326,16 @@ impl VCRMiddleware { )); diff.push_str(&format!(" got: \"{}\"\n", req.body.string)); } + diff.push_str("\n"); + } + } + if let Some(diff) = diff_log { + // tracing_test does not appear to capture multiline outputs for test + // assertion purposes, so we print each line out separately + for line in diff.split('\n') { + tracing::info!("{}", line); } } - eprintln!("{}", diff); None } @@ -388,16 +408,21 @@ impl Middleware for VCRMiddleware { self.record(vcr_request, vcr_response); Ok(converted_response) } - VCRMode::Replay => { - let vcr_response = self.find_response_in_vcr(vcr_request).unwrap_or_else(|| { - panic!( + VCRMode::Replay => match self.find_response_in_vcr(vcr_request) { + None => { + let message = format!( "Cannot find corresponding request in cassette {:?}", - self.path - ) - }); - let response = self.vcr_to_response(vcr_response); - Ok(response) - } + self.path, + ); + Err(reqwest_middleware::Error::Middleware(anyhow::anyhow!( + message + ))) + } + Some(response) => { + let response = self.vcr_to_response(response); + Ok(response) + } + }, } } } @@ -412,6 +437,7 @@ impl From for VCRMiddleware { skip: Mutex::new(0), search: VCRReplaySearch::SkipFound, compress: false, + rich_diff: false, modify_request: None, modify_response: None, } diff --git a/tests/integration/e2e.rs b/tests/integration/e2e.rs index 4972c74..0f4b089 100644 --- a/tests/integration/e2e.rs +++ b/tests/integration/e2e.rs @@ -102,6 +102,56 @@ async fn test_rvcr_replay() { .await; } +#[tracing_test::traced_test] +#[tokio::test] +async fn test_rvcr_failed_debug() { + crate::SCOPE.clone().init().await; + let mut bundle = PathBuf::from(env!("CARGO_MANIFEST_DIR")); + bundle.push("tests/resources/replay.vcr.json"); + + let middleware = VCRMiddleware::try_from(bundle.clone()) + .unwrap() + .with_rich_diff(true); + + let vcr_client: ClientWithMiddleware = ClientBuilder::new(reqwest::Client::new()) + .with(middleware) + .build(); + + let mut unmatched_req = vcr_client.request( + reqwest::Method::POST, + format!("{}/post", crate::ADDRESS.to_string()), + ); + + unmatched_req = unmatched_req.header(ACCEPT, "text/html"); + unmatched_req = unmatched_req.body("Something different".to_string()); + let unmatched_req = unmatched_req.build().unwrap(); + + let result = vcr_client.execute(unmatched_req).await; + assert!(result.is_err()); + + let expected_logs = r#"Did not match Get to http://127.0.0.1:38282/get: + Method differs: recorded Get, got Post + URI differs: + recorded: "http://127.0.0.1:38282/get" + got: "http://127.0.0.1:38282/post" + Headers differ: + accept: + recorded: "application/json" + got: "text/html" + Body differs: + recorded: "" + got: "Something different""#; + logs_assert(|lines: &[&str]| { + let processed_logs = lines + .iter() + .map(|line| line.split("rvcr: ").collect::>()[1]) + .collect::>() + .join("\n"); + assert!(processed_logs.contains(expected_logs)); + Ok(()) + }); +} + #[tokio::test] async fn test_rvcr_replay_search_all() { crate::SCOPE.clone().init().await;