From 8ff947455e55f1e730edf66dc74d68b1163aa9da Mon Sep 17 00:00:00 2001 From: Andrew Bryant Date: Fri, 23 Oct 2026 18:33:43 -0400 Subject: [PATCH] Harden error reporting, retry bounds, and credential handling MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Second hardening pass, over the code added in 23c660d. Error reporting: - Decode failures now carry an excerpt of the body that arrived. The serde message alone ("expected value at line 1 column 1") gives no hint that the response was an HTML error page from a proxy or a login redirect from a wrong base URL. The excerpt is collapsed to one line and truncated so a large body cannot become a large error. - API errors with an empty or message-less body report the status reason ("Not Found") rather than rendering blank. - `Error` is `#[non_exhaustive]`, so future variants are not breaking. Retry bounds: - `RetryPolicy::max_elapsed` (120s default) bounds the time one call may spend across attempts. The request timeout is per attempt, so the previous defaults could spend four minutes on a call that kept timing out — a surprise for anyone reading `with_timeout(60)` as a bound on the call. - `backoff` uses saturating arithmetic; a large `max_delay` could overflow the jitter span and panic in a debug build. - Response bodies are drained before a retry so the connection returns to the pool instead of the next attempt opening a fresh one. Credentials: - Test pinning that neither the token nor the password appears in `Debug` output. `reqwest`'s `Client` prints its default headers, so the sensitive flag set when building them is the only thing keeping the token out of logs, and nothing enforced that. Also drops `Option::is_none_or`, which raised the minimum toolchain to 1.82 for no benefit over a match. 91 tests, up from 80. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 18 +++- CLAUDE.md | 8 ++ README.md | 3 + src/client.rs | 89 +++++++++++++++--- src/error.rs | 17 +++- src/retry.rs | 36 +++++++- tests/client_requests.rs | 188 +++++++++++++++++++++++++++++++++++++++ tests/model_roundtrip.rs | 74 ++++++++++++++- 8 files changed, 412 insertions(+), 21 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index e0bd805..209d90d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -23,8 +23,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 `PhpVersion`. - `statics_as`, `search_as`, and `health_check_as` as generic escape hatches for callers who need to pin a shape the typed models leave in `extra`. -- `tests/client_requests.rs`: 43 tests covering the request plumbing against +- `tests/client_requests.rs`: 50 tests covering the request plumbing against a loopback `wiremock` server. No network or credentials required. +- `RetryPolicy::max_elapsed`, a ceiling on the time one call may spend across + all attempts, defaulting to 120 seconds. The request timeout is per + attempt, so without this the default policy could spend four minutes on a + call that times out repeatedly. ### Changed @@ -39,6 +43,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 missing scheme used to produce a 404 on every call instead of one error. - `list_all_*` terminates on `meta.pagination.total_pages` when the server sends it, falling back to the short-page heuristic only when it does not. +- `Error` is now `#[non_exhaustive]`, so later variants are not a breaking + change. Matches on it need a catch-all arm. +- `Error::Json` is now a struct variant carrying an `excerpt` of the body + that failed to decode. The serde message alone ("expected value at line 1 + column 1") does not reveal that the response was, say, an HTML error page + from a proxy or a login redirect from a wrong base URL. +- API errors with an empty or message-less body now report the status reason + ("Not Found") instead of rendering blank. ### Fixed @@ -67,6 +79,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 applied it before the response was lost and a replay would duplicate an invoice, payment, or email. A 429 is the exception — the server states it refused the request, so no work was done. +- The API token and password are held as headers marked sensitive, so + neither appears in `Debug` output. `reqwest`'s own `Client` debug prints + its default headers, so this is the only thing keeping the token out of + logs; there is now a regression test pinning it. ## [0.1.0] - 2026-10-23 diff --git a/CLAUDE.md b/CLAUDE.md index 723390c..43fa234 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -77,6 +77,14 @@ changes, doc tweaks) does not need an entry. single place retrying happens. **A new helper must use both** — calling `self.http` directly would skip the header, the timeout, and the retry policy. Only `req` and `execute` should touch `self.http`. +- **The request timeout is per attempt, not per call.** `RetryPolicy:: + max_elapsed` is what bounds a call overall; without it, four attempts at + the 60s default would take four minutes. Keep both in mind when changing + either. +- **Both credentials are stored as `HeaderValue`s with + `set_sensitive(true)`.** `reqwest`'s `Client` Debug prints its default + headers, so that flag is the only thing keeping the API token out of any + `{:?}` log. Don't build either header without it; a test pins this. - `src/retry.rs` — `RetryPolicy` plus the rules for what may be replayed. **The method matters, not just the status.** A 429 means the server refused the request without processing it, so any method is safe to diff --git a/README.md b/README.md index e82c3f6..8166505 100644 --- a/README.md +++ b/README.md @@ -62,6 +62,9 @@ let client = InvoiceNinjaClient::hosted(token)? .with_retry_policy(RetryPolicy::new(5)); ``` +Note that the timeout applies to each attempt, not to the call as a whole; +`RetryPolicy::max_elapsed` (120 seconds by default) is what bounds the total. + Retrying is deliberately conservative about `POST`. A `POST` that fails with a 5xx or times out is **not** replayed, because the server may have applied it before the response was lost and a repeat would create a second invoice diff --git a/src/client.rs b/src/client.rs index 728bc1f..2b08900 100644 --- a/src/client.rs +++ b/src/client.rs @@ -60,6 +60,37 @@ fn seg(value: &str) -> Result { Ok(utf8_percent_encode(value, PATH_SEGMENT)) } +/// Renders the start of a response body for an error message. +/// +/// Collapsed to one line and truncated, so a stray HTML error page or a +/// multi-megabyte payload cannot turn an error into a wall of text. +fn excerpt(bytes: &[u8]) -> String { + /// Enough to recognise an HTML page, a proxy error, or a short JSON + /// message without quoting a whole document. + const MAX: usize = 200; + + let head = &bytes[..bytes.len().min(MAX)]; + // Lossy because the body may be truncated mid-character, or not be text + // at all — a PDF arriving where JSON was expected is exactly the kind of + // mix-up this is here to explain. + let text = String::from_utf8_lossy(head); + let mut out: String = text + .chars() + .map(|c| if c.is_control() { ' ' } else { c }) + .collect(); + let trimmed = out.trim(); + if trimmed.len() != out.len() { + out = trimmed.to_string(); + } + if out.is_empty() { + return "".to_string(); + } + if bytes.len() > MAX { + out.push('…'); + } + out +} + /// An async client for the Invoice Ninja v5 API. /// /// `base_url` should point at the API root — note the `/api/v1` suffix, e.g. @@ -199,14 +230,13 @@ impl InvoiceNinjaClient { async fn execute(&self, builder: reqwest::RequestBuilder) -> Result { let mut request = builder.build()?; let method = request.method().clone(); + let started = std::time::Instant::now(); let mut attempt = 0u32; loop { - let replay = if attempt < self.retry.max_retries { - request.try_clone() - } else { - None - }; + let may_retry = + attempt < self.retry.max_retries && self.retry.within_budget(started.elapsed()); + let replay = if may_retry { request.try_clone() } else { None }; let delay = match self.http.execute(request).await { Ok(response) => { @@ -220,9 +250,15 @@ impl InvoiceNinjaClient { // as the error instead of slept through. let delay = retry::retry_after(response.headers()) .unwrap_or_else(|| self.retry.backoff(attempt)); - if delay > self.retry.max_delay { + if delay > self.retry.max_delay + || !self.retry.within_budget(started.elapsed() + delay) + { return Ok(response); } + // Drain the body before retrying so the connection can + // return to the pool; dropping it unread makes the next + // attempt open a fresh one. + let _ = response.bytes().await; request = next; delay } @@ -232,8 +268,12 @@ impl InvoiceNinjaClient { else { return Err(e.into()); }; + let delay = self.retry.backoff(attempt); + if !self.retry.within_budget(started.elapsed() + delay) { + return Err(e.into()); + } request = next; - self.retry.backoff(attempt) + delay } }; @@ -260,24 +300,47 @@ impl InvoiceNinjaClient { let bytes = response.bytes().await?; if status.is_success() { - Ok(serde_json::from_slice(&bytes)?) + serde_json::from_slice(&bytes).map_err(|source| Error::Json { + source, + excerpt: excerpt(&bytes), + }) } else { Err(Self::api_error(status, &bytes)) } } fn api_error(status: StatusCode, bytes: &[u8]) -> Error { + let fallback = |message: String| Error::Api { + status, + // An empty body would otherwise render as "api returned 404: ", + // which says less than the status line already did. + message: if message.trim().is_empty() { + status + .canonical_reason() + .unwrap_or("no message in response") + .to_string() + } else { + message + }, + errors: Default::default(), + }; + match serde_json::from_slice::(bytes) { + // A body that parses but carries neither a message nor field + // errors is no more useful than an unparseable one. + Ok(body) if body.message.trim().is_empty() && body.errors.is_empty() => { + fallback(String::new()) + } Ok(body) => Error::Api { status, message: body.message, errors: body.errors, }, - Err(_) => Error::Api { - status, - message: String::from_utf8_lossy(bytes).into_owned(), - errors: Default::default(), - }, + // Checked on the bytes rather than the excerpt, which + // substitutes a placeholder for an empty body and would read as + // a message. + Err(_) if bytes.iter().all(u8::is_ascii_whitespace) => fallback(String::new()), + Err(_) => fallback(excerpt(bytes)), } } diff --git a/src/error.rs b/src/error.rs index d7f7089..fcf108d 100644 --- a/src/error.rs +++ b/src/error.rs @@ -10,13 +10,26 @@ pub struct ApiErrorBody { pub errors: HashMap>, } +/// Marked `#[non_exhaustive]`: matching on it must include a catch-all arm, +/// so that new variants can be added without breaking callers. #[derive(Debug, thiserror::Error)] +#[non_exhaustive] pub enum Error { #[error("http transport error: {0}")] Http(#[from] reqwest::Error), - #[error("failed to decode JSON response: {0}")] - Json(#[from] serde_json::Error), + /// The response was not the JSON this endpoint is documented to return. + /// + /// Carries an excerpt of what actually arrived. Without it the inner + /// serde message ("expected value at line 1 column 1") gives no clue + /// that the body was, say, an HTML error page from a reverse proxy or a + /// login redirect from a misconfigured base URL. + #[error("failed to decode JSON response: {source}; body began: {excerpt}")] + Json { + #[source] + source: serde_json::Error, + excerpt: String, + }, #[error("api returned {status}: {message}")] Api { diff --git a/src/retry.rs b/src/retry.rs index aff27a9..f8fe973 100644 --- a/src/retry.rs +++ b/src/retry.rs @@ -22,6 +22,14 @@ pub struct RetryPolicy { pub base_delay: Duration, /// Ceiling on any single wait, including one asked for by `Retry-After`. pub max_delay: Duration, + /// Ceiling on the time spent across *all* attempts for one call. + /// + /// This exists because the request timeout is per attempt, not per call: + /// with the defaults, four attempts that each time out would otherwise + /// take four minutes. Once this much has elapsed no further retry + /// starts, and the last error is returned. `None` bounds a call only by + /// `max_retries`. + pub max_elapsed: Option, } impl Default for RetryPolicy { @@ -30,6 +38,7 @@ impl Default for RetryPolicy { max_retries: 3, base_delay: Duration::from_millis(500), max_delay: Duration::from_secs(10), + max_elapsed: Some(Duration::from_secs(120)), } } } @@ -58,6 +67,24 @@ impl RetryPolicy { self } + /// Sets the ceiling on total time across all attempts; `None` removes + /// it. + pub fn max_elapsed(mut self, max_elapsed: Option) -> Self { + self.max_elapsed = max_elapsed; + self + } + + /// Whether another attempt may start after `elapsed` spent so far. + /// + /// Spelled as a match rather than `is_none_or`, which would raise the + /// minimum toolchain to 1.82 for no benefit. + pub(crate) fn within_budget(&self, elapsed: Duration) -> bool { + match self.max_elapsed { + Some(budget) => elapsed < budget, + None => true, + } + } + /// Full-jitter exponential backoff: a uniform pick from /// `[0, min(max_delay, base_delay * 2^attempt)]`. /// @@ -66,10 +93,13 @@ impl RetryPolicy { pub(crate) fn backoff(&self, attempt: u32) -> Duration { let exponential = self .base_delay + // `checked_shl` yields None past 31 places, and the multiply can + // overflow well before that; either way the cap applies. .checked_mul(1u32.checked_shl(attempt).unwrap_or(u32::MAX)) .unwrap_or(self.max_delay) .min(self.max_delay); - Duration::from_millis(pseudo_random_millis(exponential.as_millis() as u64)) + let millis = u64::try_from(exponential.as_millis()).unwrap_or(u64::MAX); + Duration::from_millis(pseudo_random_millis(millis)) } } @@ -96,7 +126,9 @@ fn pseudo_random_millis(upper: u64) -> u64 { x ^= x >> 27; x = x.wrapping_mul(0x94D0_49BB_1331_11EB); x ^= x >> 31; - x % (upper + 1) + // Saturating, so an enormous `max_delay` cannot overflow the span and + // panic in a debug build. + x % upper.saturating_add(1) } /// Whether replaying the request can be assumed not to double an effect. diff --git a/tests/client_requests.rs b/tests/client_requests.rs index 9e78e21..7e63ca6 100644 --- a/tests/client_requests.rs +++ b/tests/client_requests.rs @@ -988,3 +988,191 @@ async fn generic_escape_hatches_still_work() { .expect("statics_as should bypass the typed model"); assert!(raw["sizes"].is_array()); } + +// --- secret handling ---------------------------------------------------- + +/// `reqwest`'s `Client` Debug prints its default headers, so the only thing +/// keeping the API token out of every `{:?}` log is the sensitive flag set +/// when the header is built. Lock that in. +#[test] +fn debug_output_never_contains_the_token_or_password() { + let client = InvoiceNinjaClient::new("https://example.com/api/v1", "SUPER_SECRET_TOKEN") + .unwrap() + .with_api_password("SUPER_SECRET_PASSWORD") + .unwrap(); + + let rendered = format!("{client:?}"); + assert!( + !rendered.contains("SUPER_SECRET_TOKEN"), + "api token leaked into Debug output: {rendered}" + ); + assert!( + !rendered.contains("SUPER_SECRET_PASSWORD"), + "api password leaked into Debug output: {rendered}" + ); + assert!( + rendered.contains("Sensitive"), + "expected the headers to render as redacted, got: {rendered}" + ); +} + +// --- error quality ------------------------------------------------------ + +/// A misconfigured base URL or an intercepting proxy returns HTML with a 200. +/// The bare serde message ("expected value at line 1 column 1") does not hint +/// at that, so the body excerpt is what makes it diagnosable. +#[tokio::test] +async fn decode_failures_quote_the_body_that_arrived() { + let server = MockServer::start().await; + Mock::given(method("GET")) + .and(path("/clients")) + .respond_with( + ResponseTemplate::new(200).set_body_string("Login required"), + ) + .mount(&server) + .await; + + let err = client(&server) + .list_clients(&ListParams::new()) + .await + .expect_err("HTML is not a decodable list response"); + + let rendered = err.to_string(); + assert!( + matches!(err, Error::Json { .. }), + "expected a decode error, got {err:?}" + ); + assert!( + rendered.contains("Login required"), + "the excerpt should name what actually arrived, got: {rendered}" + ); +} + +#[tokio::test] +async fn decode_excerpts_are_truncated_and_single_line() { + let server = MockServer::start().await; + let huge = format!("\n{}\n", "x".repeat(50_000)); + Mock::given(method("GET")) + .and(path("/clients")) + .respond_with(ResponseTemplate::new(200).set_body_string(huge)) + .mount(&server) + .await; + + let err = client(&server) + .list_clients(&ListParams::new()) + .await + .expect_err("should fail to decode"); + + let rendered = err.to_string(); + assert!( + rendered.len() < 400, + "a huge body must not become a huge error, got {} chars", + rendered.len() + ); + assert!( + !rendered.contains('\n'), + "the excerpt should be collapsed to one line" + ); + assert!(rendered.contains('…'), "truncation should be marked"); +} + +#[tokio::test] +async fn empty_error_bodies_fall_back_to_the_status_reason() { + let server = MockServer::start().await; + Mock::given(method("DELETE")) + .and(path("/clients/abc")) + .respond_with(ResponseTemplate::new(404)) + .mount(&server) + .await; + + let err = client(&server) + .with_retry_policy(RetryPolicy::none()) + .delete_client("abc") + .await + .expect_err("404 is an error"); + + match err { + Error::Api { message, .. } => assert_eq!( + message, "Not Found", + "an empty body should borrow the status reason rather than render blank" + ), + other => panic!("expected Error::Api, got {other:?}"), + } +} + +#[tokio::test] +async fn a_json_error_body_with_no_message_still_says_something() { + let server = MockServer::start().await; + Mock::given(method("GET")) + .and(path("/clients")) + .respond_with(ResponseTemplate::new(403).set_body_json(json!({}))) + .mount(&server) + .await; + + let err = client(&server) + .with_retry_policy(RetryPolicy::none()) + .list_clients(&ListParams::new()) + .await + .expect_err("403 is an error"); + assert!(err.to_string().contains("Forbidden"), "got {err}"); +} + +// --- retry budget ------------------------------------------------------- + +/// The request timeout is per attempt, so without a total budget four +/// attempts at 60s each would take four minutes. The budget caps the call. +#[tokio::test] +async fn the_total_budget_stops_retrying_even_with_retries_left() { + let server = MockServer::start().await; + Mock::given(method("GET")) + .and(path("/clients")) + .respond_with(ResponseTemplate::new(503).set_delay(Duration::from_millis(80))) + .mount(&server) + .await; + + let policy = RetryPolicy::new(50) + .base_delay(Duration::from_millis(1)) + .max_delay(Duration::from_millis(5)) + .max_elapsed(Some(Duration::from_millis(250))); + + let started = std::time::Instant::now(); + let err = client(&server) + .with_retry_policy(policy) + .list_clients(&ListParams::new()) + .await + .expect_err("should give up once the budget is spent"); + + assert!(matches!(err, Error::Api { status, .. } if status == 503)); + assert!( + started.elapsed() < Duration::from_secs(3), + "50 retries were allowed but the budget should have ended it, took {:?}", + started.elapsed() + ); + let attempts = server.received_requests().await.unwrap().len(); + assert!( + (2..=6).contains(&attempts), + "expected the budget to allow a few attempts, got {attempts}" + ); +} + +#[tokio::test] +async fn no_budget_means_only_max_retries_bounds_the_call() { + let server = MockServer::start().await; + Mock::given(method("GET")) + .and(path("/clients")) + .respond_with(ResponseTemplate::new(503)) + .mount(&server) + .await; + + let policy = RetryPolicy::new(4) + .base_delay(Duration::from_millis(1)) + .max_delay(Duration::from_millis(2)) + .max_elapsed(None); + + let _ = client(&server) + .with_retry_policy(policy) + .list_clients(&ListParams::new()) + .await + .expect_err("still fails"); + assert_eq!(server.received_requests().await.unwrap().len(), 5); +} diff --git a/tests/model_roundtrip.rs b/tests/model_roundtrip.rs index ff3e756..75e05a2 100644 --- a/tests/model_roundtrip.rs +++ b/tests/model_roundtrip.rs @@ -1,9 +1,10 @@ use invoiceninjars::models::{ BankIntegration, BankTransaction, BankTransactionRule, BulkRequest, Client, ClientGatewayToken, Company, CompanyGateway, CompanyToken, Credit, Design, Document, Expense, ExpenseCategory, - GroupSetting, Invoice, ListParams, ListResponse, Location, PaymentTerm, Project, PurchaseOrder, - Quote, RecurringExpense, RecurringInvoice, RecurringQuote, Subscription, SystemLog, Tag, Task, - TaskScheduler, TaskStatus, TaxRate, User, Vendor, Webhook, + GroupSetting, HealthCheck, Invoice, ListParams, ListResponse, Location, PaymentTerm, Project, + PurchaseOrder, Quote, RecurringExpense, RecurringInvoice, RecurringQuote, SearchResults, + Statics, Subscription, SystemLog, Tag, Task, TaskScheduler, TaskStatus, TaxRate, User, Vendor, + Webhook, }; use serde_json::json; @@ -694,3 +695,70 @@ fn design_body_round_trips_through_extra() { let round_tripped = serde_json::to_value(&design).unwrap(); assert_eq!(round_tripped["design"]["header"], "

"); } + +#[test] +fn statics_round_trip_preserves_unmodeled_tables_and_fields() { + let payload = json!({ + "currencies": [{ "id": 1, "name": "US Dollar", "code": "USD", "precision": 2 }], + "countries": [{ "id": 840, "name": "United States", "iso_3166_3": "USA" }], + "gateways": [{ "id": 1, "name": "Stripe" }], + "some_future_table": [{ "x": 1 }] + }); + + let statics: Statics = serde_json::from_value(payload).unwrap(); + let back = serde_json::to_value(&statics).unwrap(); + + assert_eq!(back["countries"][0]["iso_3166_3"], "USA"); + assert_eq!(back["some_future_table"][0]["x"], 1); + assert_eq!(back["gateways"][0]["name"], "Stripe"); + assert_eq!( + back["currencies"][0]["id"], "1", + "ids are normalised to strings on the way back out" + ); +} + +#[test] +fn search_results_round_trip_preserves_unknown_buckets() { + let payload = json!({ + "clients": [{ "name": "Acme", "type": "/client", "id": "a1", "path": "/clients/a1" }], + "future_bucket": [{ "name": "x" }] + }); + + let results: SearchResults = serde_json::from_value(payload).unwrap(); + assert_eq!(results.clients[0].r#type, "/client"); + + let back = serde_json::to_value(&results).unwrap(); + assert_eq!(back["future_bucket"][0]["name"], "x"); + assert_eq!(back["clients"][0]["type"], "/client"); +} + +#[test] +fn health_check_round_trip_preserves_unknown_fields() { + let payload = json!({ + "system_health": false, + "api_version": "5.8.56", + "queue_data": { "pending": 3 }, + "brand_new_probe": true + }); + + let health: HealthCheck = serde_json::from_value(payload).unwrap(); + assert_eq!(health.system_health, Some(false)); + + let back = serde_json::to_value(&health).unwrap(); + assert_eq!(back["brand_new_probe"], true); + assert_eq!(back["queue_data"]["pending"], 3); +} + +#[test] +fn statics_ids_accept_both_strings_and_numbers() { + let payload = json!({ + "payment_types": [{ "id": "1", "name": "Bank Transfer" }], + "industries": [{ "id": 3, "name": "Advertising" }], + "sizes": [{ "id": null, "name": "Unknown" }] + }); + + let statics: Statics = serde_json::from_value(payload).unwrap(); + assert_eq!(statics.payment_types[0].id, "1"); + assert_eq!(statics.industries[0].id, "3"); + assert_eq!(statics.sizes[0].id, "", "a null id decodes as empty"); +}