diff --git a/Cargo.lock b/Cargo.lock index f46006f06..4e75dd2cf 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1639,6 +1639,12 @@ dependencies = [ "winapi", ] +[[package]] +name = "dissimilar" +version = "1.0.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "86e3bdc80eee6e16b2b6b0f87fbc98c04bee3455e35174c0de1a125d0688c632" + [[package]] name = "doc-comment" version = "0.3.3" @@ -1725,6 +1731,16 @@ dependencies = [ "windows-sys 0.48.0", ] +[[package]] +name = "expect-test" +version = "1.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "30d9eafeadd538e68fb28016364c9732d78e420b9ff8853fa5e4058861e9f8d3" +dependencies = [ + "dissimilar", + "once_cell", +] + [[package]] name = "faster-hex" version = "0.8.1" @@ -4418,6 +4434,7 @@ dependencies = [ "derive_builder", "directories", "dunce", + "expect-test", "fs4", "fs_extra", "futures", diff --git a/Cargo.toml b/Cargo.toml index 75453fd97..d5a109f4f 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -53,6 +53,7 @@ deno_task_shell = ">=0.13" derive_builder = ">=0.12" directories = "5" dunce = "1" +expect-test = "1.4" fs4 = { version = "0.7", features = ["tokio"] } fs_extra = "1" futures = { version = "0.3", default-features = false, features = ["std", "async-await"] } diff --git a/scarb/Cargo.toml b/scarb/Cargo.toml index 02d790d87..f3b6f3814 100644 --- a/scarb/Cargo.toml +++ b/scarb/Cargo.toml @@ -85,6 +85,7 @@ reqwest = { workspace = true, features = ["rustls-tls-native-roots"] } [dev-dependencies] assert_fs.workspace = true +expect-test.workspace = true fs_extra.workspace = true io_tee.workspace = true libc.workspace = true diff --git a/scarb/tests/http_registry.rs b/scarb/tests/http_registry.rs index cbb93464e..a1e3fabf8 100644 --- a/scarb/tests/http_registry.rs +++ b/scarb/tests/http_registry.rs @@ -1,8 +1,10 @@ +use std::fs; +use std::time::Duration; + use assert_fs::prelude::*; use assert_fs::TempDir; +use expect_test::expect; use indoc::indoc; -use std::fs; -use std::time::Duration; use scarb_test_support::command::Scarb; use scarb_test_support::project_builder::{Dep, DepBuilder, ProjectBuilder}; @@ -37,6 +39,52 @@ fn usage() { .stdout_matches(indoc! {r#" [..] Downloading bar v1.0.0 ([..]) "#}); + + let expected = expect![[" + GET /config.json + accept: */* + accept-encoding: gzip, br, deflate + host: ... + user-agent: ... + + 200 OK + accept-ranges: bytes + content-length: ... + content-type: application/json + etag: ... + last-modified: ... + + ### + + GET /index/3/b/bar.json + accept: */* + accept-encoding: gzip, br, deflate + host: ... + user-agent: ... + + 200 OK + accept-ranges: bytes + content-length: ... + content-type: application/json + etag: ... + last-modified: ... + + ### + + GET /bar-1.0.0.tar.zst + accept: */* + accept-encoding: gzip, br, deflate + host: ... + user-agent: ... + + 200 OK + accept-ranges: bytes + content-length: ... + content-type: application/octet-stream + etag: ... + last-modified: ... + "]]; + expected.assert_eq(®istry.logs()); } #[test] @@ -71,6 +119,34 @@ fn not_found() { Caused by: package not found in registry: baz ^1 (registry+http://[..]) "#}); + + let expected = expect![[" + GET /config.json + accept: */* + accept-encoding: gzip, br, deflate + host: ... + user-agent: ... + + 200 OK + accept-ranges: bytes + content-length: ... + content-type: application/json + etag: ... + last-modified: ... + + ### + + GET /index/3/b/baz.json + accept: */* + accept-encoding: gzip, br, deflate + host: ... + user-agent: ... + + 404 Not Found + content-length: 0 + etag: ... + "]]; + expected.assert_eq(®istry.logs()); } #[test] @@ -98,8 +174,21 @@ fn missing_config_json() { 0: failed to fetch registry config 1: HTTP status client error (404 Not Found) for url (http://[..]/config.json) "#}); + + let expected = expect![[" + GET /config.json + accept: */* + accept-encoding: gzip, br, deflate + host: ... + user-agent: ... + + 404 Not Found + content-length: 0 + etag: ... + "]]; + expected.assert_eq(®istry.logs()); } // TODO(mkaput): Test errors properly when package is in index, but tarball is missing. // TODO(mkaput): Test interdependencies. -// TODO(mkaput): Test offline mode. +// TODO(mkaput): Test offline mode, including with some cache prepopulated. diff --git a/utils/scarb-test-support/src/main.rs b/utils/scarb-test-support/src/main.rs index 8d247aefb..0e9a25b61 100644 --- a/utils/scarb-test-support/src/main.rs +++ b/utils/scarb-test-support/src/main.rs @@ -44,7 +44,7 @@ fn hang_on_tcp(args: HangOnTcpArgs) -> Result<()> { #[tokio::main] async fn http_server() -> Result<()> { let http = SimpleHttpServer::serve(env::current_dir().unwrap()); - http.log_requests(true); + http.print_logs(true); println!("🚀 {}", http.url()); println!("Press enter to continue..."); let _ = io::stdin().read(&mut [0u8]).unwrap(); diff --git a/utils/scarb-test-support/src/registry/http.rs b/utils/scarb-test-support/src/registry/http.rs index 5860ba9e9..8d02c036c 100644 --- a/utils/scarb-test-support/src/registry/http.rs +++ b/utils/scarb-test-support/src/registry/http.rs @@ -1,8 +1,8 @@ -use assert_fs::fixture::ChildPath; -use assert_fs::prelude::*; use std::fmt; use std::path::Path; +use assert_fs::fixture::ChildPath; +use assert_fs::prelude::*; use assert_fs::TempDir; use once_cell::sync::Lazy; use serde_json::json; @@ -11,6 +11,16 @@ use tokio::runtime; use crate::registry::local::LocalRegistry; use crate::simple_http_server::SimpleHttpServer; +// Keep a global multi-threading runtime to contain all running servers in one shared +// thread pool, while maintaining synchronous nature of tests. +static RUNTIME: Lazy = Lazy::new(|| { + runtime::Builder::new_multi_thread() + .worker_threads(1) + .enable_all() + .build() + .unwrap() +}); + pub struct HttpRegistry { local: LocalRegistry, url: String, @@ -21,16 +31,6 @@ pub struct HttpRegistry { impl HttpRegistry { pub fn serve() -> Self { - // Keep a global multi-threading runtime to contain all running servers in one shared - // thread pool, while maintaining synchronous nature of tests. - static RUNTIME: Lazy = Lazy::new(|| { - runtime::Builder::new_multi_thread() - .worker_threads(1) - .enable_all() - .build() - .unwrap() - }); - let local = LocalRegistry::create(); let server = { let _guard = RUNTIME.enter(); @@ -58,8 +58,13 @@ impl HttpRegistry { } /// Enable this when writing tests to see what requests are being made in the test. - pub fn debug_log_requests(&self) { - self.server.log_requests(true); + pub fn print_logs(&self) { + self.server.print_logs(true); + } + + pub fn logs(&self) -> String { + let _guard = RUNTIME.enter(); + RUNTIME.block_on(async { self.server.logs_to_string().await }) } } diff --git a/utils/scarb-test-support/src/simple_http_server.rs b/utils/scarb-test-support/src/simple_http_server.rs index 914a5e165..7ba619d32 100644 --- a/utils/scarb-test-support/src/simple_http_server.rs +++ b/utils/scarb-test-support/src/simple_http_server.rs @@ -1,3 +1,5 @@ +use std::collections::BTreeMap; +use std::fmt; use std::net::{SocketAddr, TcpListener}; use std::path::PathBuf; use std::sync::atomic::{AtomicBool, AtomicU32, Ordering}; @@ -6,32 +8,56 @@ use std::sync::Arc; use axum::body::Body; use axum::extract::State; use axum::http::header::ETAG; +use axum::http::HeaderMap; +use axum::http::Method; use axum::http::Request; +use axum::http::StatusCode; +use axum::middleware; use axum::middleware::Next; use axum::response::Response; -use axum::{middleware, Router}; +use axum::Router; use data_encoding::HEXLOWER; use itertools::Itertools; use sha2::digest::FixedOutput; use sha2::Digest; +use tokio::sync::Mutex; use tower_http::services::ServeDir; +/// Key is request count from logger middleware. Keeping logs in ordered map allows sorting logs by +/// request incoming time, not by response outgoing one. +type LogsStore = Arc>>; + +type LoggerState = (LogsStore, Arc); + pub struct SimpleHttpServer { addr: SocketAddr, - log_requests: Arc, + print_logs: Arc, + logs: LogsStore, ct: Option>, } +pub struct HttpLog { + pub req_method: Method, + pub req_uri: String, + pub req_headers: HeaderMap, + pub res_status: StatusCode, + pub res_headers: HeaderMap, +} + impl SimpleHttpServer { pub fn serve(dir: PathBuf) -> Self { let (ct, ctrx) = tokio::sync::oneshot::channel::<()>(); - let log_requests = Arc::new(AtomicBool::new(false)); + let print_logs = Arc::new(AtomicBool::new(false)); + let logs: LogsStore = Default::default(); let app = Router::new() .fallback_service(ServeDir::new(dir)) - .layer(middleware::from_fn_with_state(log_requests.clone(), logger)) - .layer(middleware::map_response(set_etag)); + .layer(middleware::map_response(set_etag)) + .layer(middleware::from_fn_with_state( + (logs.clone(), print_logs.clone()), + logger, + )); let tcp = TcpListener::bind("127.0.0.1:0").unwrap(); let addr = tcp.local_addr().unwrap(); @@ -49,7 +75,8 @@ impl SimpleHttpServer { Self { addr, - log_requests, + print_logs, + logs, ct: Some(ct), } } @@ -59,8 +86,13 @@ impl SimpleHttpServer { } /// Enable this when writing tests to see what requests are being made in the test. - pub fn log_requests(&self, enable: bool) { - self.log_requests.store(enable, Ordering::Relaxed); + pub fn print_logs(&self, enable: bool) { + self.print_logs.store(enable, Ordering::Relaxed); + } + + pub async fn logs_to_string(&self) -> String { + let logs = self.logs.lock().await; + logs.values().map(ToString::to_string).join("\n###\n\n") } } @@ -71,16 +103,16 @@ impl Drop for SimpleHttpServer { } async fn logger( - State(enable): State>, + State((logs, print_logs)): State, request: Request, next: Next, ) -> Response { static COUNTER: AtomicU32 = AtomicU32::new(0); let count = COUNTER.fetch_add(1, Ordering::Relaxed); - let enable = enable.load(Ordering::Relaxed); + let print_logs = print_logs.load(Ordering::Relaxed); - if enable { + if print_logs { eprintln!( "http[{count}]: {method} {uri}", method = request.method(), @@ -88,9 +120,13 @@ async fn logger( ); } + let req_method = request.method().clone(); + let req_uri = request.uri().to_string(); + let req_headers = request.headers().clone(); + let response = next.run(request).await; - if enable { + if print_logs { eprintln!( "http[{count}]: {status} => {headers}", count = count, @@ -104,6 +140,22 @@ async fn logger( ); } + let res_status = response.status(); + let res_headers = response.headers().clone(); + + let log = HttpLog { + req_method, + req_uri, + req_headers, + res_status, + res_headers, + }; + + { + let mut logs = logs.lock().await; + logs.insert(count, log); + } + response } @@ -120,3 +172,39 @@ async fn set_etag(res: Response) -> Response { Response::from_parts(parts, Body::from(bytes)) } + +impl fmt::Display for HttpLog { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + use axum::http::header::*; + + writeln!( + f, + "{method} {uri}", + method = self.req_method, + uri = self.req_uri + )?; + self.req_headers + .iter() + .sorted_by_key(|(k, _)| k.as_str()) + .map(|(k, v)| (k, String::from_utf8_lossy(v.as_bytes()))) + .map(|(k, v)| match *k { + HOST | IF_NONE_MATCH | IF_MODIFIED_SINCE | USER_AGENT => (k, "...".into()), + _ => (k, v), + }) + .try_for_each(|(k, v)| writeln!(f, "{k}: {v}"))?; + writeln!(f)?; + writeln!(f, "{status}", status = self.res_status)?; + self.res_headers + .iter() + .sorted_by_key(|(k, _)| k.as_str()) + .map(|(k, v)| (k, String::from_utf8_lossy(v.as_bytes()))) + .map(|(k, v)| match *k { + CONTENT_LENGTH if v == "0" => (k, v), + CONTENT_LENGTH => (k, "...".into()), + ETAG | LAST_MODIFIED => (k, "...".into()), + _ => (k, v), + }) + .try_for_each(|(k, v)| writeln!(f, "{k}: {v}"))?; + Ok(()) + } +}