diff --git a/CHANGELOG.md b/CHANGELOG.md index c236924..c707676 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -19,6 +19,23 @@ that may never merge. They are not releases and are not listed here. ## Unreleased +- Diagnostic logs, off by default: `mapbox config set log on` (or + `MAPBOX_LOG=1`) keeps, for each run in history, the command line, each + request and the error message, tokens redacted, on your machine only. + `mapbox history show` includes the log, or says it was not captured or is + no longer available (`diagnostics.status`: `captured`, `not_captured`, + `unavailable`). Kept up to 30 days and 100 MB; needs history on. + `mapbox config list` now reports a third key, `log`. + +- Command history, on by default: each run appends one line to + `~/.mapbox/history/.jsonl`, kept 30 days and at most 10 MB, with its command path, exit + code, error code, duration and request ids — never an argument value. It + stays on your machine. `mapbox history list` and `mapbox history show` + read it back. Turn it off with `mapbox config set history off` or + `MAPBOX_HISTORY=0`. A script sees no change on stdout, stderr or the exit + code; it does find a `~/.mapbox/history` directory it didn't before, and + `mapbox config list` now reports a second key, `history`. + - `MAPBOX_CLI_EXTRA_QUERY` appends raw query parameters to every request, in the same `k1=v1&k2=v2` shape as a URL's own query string — for an API parameter this CLI's specs don't declare a flag for. diff --git a/README.md b/README.md index 714d97e..b6de39a 100644 --- a/README.md +++ b/README.md @@ -23,6 +23,8 @@ time from OpenAPI specs, so they always match the specs. - [`--schema`](#--schema) - [Confirmation and `--yes`](#confirmation-and---yes) - [Update notices](#update-notices) + - [Command history](#command-history) + - [Diagnostic logs](#diagnostic-logs) - [Privacy](#privacy) - [Uninstall](#uninstall) - [Contributing](#contributing) @@ -438,6 +440,45 @@ between runs. A build that names no release channel never checks at all, and see [Config](docs/commands.md#config) — rather than just the session an environment variable happens to be set in. +### Command history + +Each run appends one line to `~/.mapbox/history/.jsonl` (or under +`$MAPBOX_CONFIG_DIR`), kept for 30 days and at most 10 MB, oldest dropped +first: which command ran (its command path, +like `search forward`), how it ended, how long it took and the request ids +support can look up. Argument values are never recorded — not what you +searched for, not a file path, not a token. The files are readable only by +you and never leave your machine. + +```sh +mapbox history list # the most recent runs, newest first +mapbox history show # everything recorded about the newest run +mapbox history show be40d711 # or one run, by any prefix of its id +``` + +`--help`, `--version`, `completion`, `history` itself and runs under `sudo` +are not recorded. `mapbox config set history off` turns history off for +good, and `MAPBOX_HISTORY=0` for one shell; with it off, nothing is written +and no directory is created, but what was already recorded stays until you +delete `~/.mapbox/history`. `MAPBOX_CLI_NO_TELEMETRY` does not affect it. + +### Diagnostic logs + +Off by default. `mapbox config set log on` (or `MAPBOX_LOG=1` for one shell) +adds, for each run history records, a line of detail in +`~/.mapbox/logs/.jsonl`: the command line, each request's method, +URL, status, request id and timing, which token was used (where it came +from, its type and account, never the token itself) and the error message. +Tokens are replaced with `` wherever they appear, and the files +never leave your machine. + +`mapbox history show` includes a run's log, or says it was not captured +(logging was off) or is no longer available. Logs are kept up to 30 days and +100 MB in total; past that the oldest go first, and the run's history record +stays. A day of logs goes when that day of history does. Logging needs +history: with history off it never runs, and with the `history` setting off +`config set log on` refuses. + ### Privacy **YOUR PRIVACY - COLLECTION OF TELEMETRY** diff --git a/docs/commands.md b/docs/commands.md index 2c2ca03..b320671 100644 --- a/docs/commands.md +++ b/docs/commands.md @@ -64,6 +64,9 @@ nests, and is typed `mapbox styles draft get`. [config.set](#mapbox-config-set) · [config.list](#mapbox-config-list) · [config.unset](#mapbox-config-unset) +**[History](#history)** — [history.list](#mapbox-history-list) · +[history.show](#mapbox-history-show) + **[Doctor](#doctor)** — [doctor](#mapbox-doctor) **[Usage](#usage)** — [usage](#mapbox-usage) @@ -3194,10 +3197,15 @@ Removed /home/user/.local/bin/mapbox. ## Config Settings that persist across shells and sessions — `~/.mapbox/config.json` -(or `$MAPBOX_CONFIG_DIR`), written the same way credentials are. One setting -today, `update-check`, which mirrors `MAPBOX_NO_UPDATE_CHECK` (see [Update -notices](../README.md#update-notices)) but stays off in every future shell -rather than only the one the environment variable was set in. +(or `$MAPBOX_CONFIG_DIR`), written the same way credentials are. Each is the +persisted form of an environment variable that only lasts for the shell it +was set in, and stays in every future shell instead. + +| Key | Default | What it controls | +| --- | --- | --- | +| `update-check` | `on` | The update notice; mirrors `MAPBOX_NO_UPDATE_CHECK` (see [Update notices](../README.md#update-notices)) | +| `history` | `on` | [Command history](../README.md#command-history), read by `mapbox history`; `MAPBOX_HISTORY=0` or `=1` overrides it for a session | +| `log` | `off` | [Diagnostic logs](../README.md#diagnostic-logs), shown by `mapbox history show`; `MAPBOX_LOG=1` or `=0` overrides it for a session. Needs `history` on: `config set log on` with history off fails with `history_required` | ### `mapbox config get` @@ -3209,7 +3217,7 @@ than failing, the same forgiving read the update-check cache itself uses. | Parameter | Effect | | --- | --- | -| `` | Which setting to read. Only `update-check` exists today. | +| `` | Which setting to read: `update-check`, `history` or `log`. | #### Examples @@ -3248,7 +3256,7 @@ without an environment variable. | Parameter | Effect | | --- | --- | -| `` | Which setting to change. Only `update-check` exists today. | +| `` | Which setting to change: `update-check`, `history` or `log`. | | `` | `on` or `off`. | #### Examples @@ -3305,6 +3313,8 @@ mapbox config list ``` update-check on +history on +log off ``` @@ -3314,6 +3324,14 @@ update-check on { "key": "update-check", "value": true + }, + { + "key": "history", + "value": true + }, + { + "key": "log", + "value": false } ] ``` @@ -3332,7 +3350,7 @@ default, a key explicitly set to the old default value does not. | Parameter | Effect | | --- | --- | -| `` | Which setting to clear. Only `update-check` exists today. | +| `` | Which setting to clear: `update-check`, `history` or `log`. | #### Examples @@ -3364,6 +3382,208 @@ update-check cleared, now on (default). --- +## History + +The runs [command history](../README.md#command-history) recorded on this +machine over the last 30 days, up to 10 MB: which command ran, how it ended, how long it +took and the request ids support can look up. Argument values are never +recorded, so a run shows as its command path — `mapbox search forward`, +not what was searched for. History is on by default; with it off +(`mapbox config set history off`), both commands find nothing and say why +on stderr. Neither makes a request or needs a token, and neither is itself +recorded — nor are `--help`, `--version`, `completion` or a run under +`sudo`. + +History is also the way in to [diagnostic logs](../README.md#diagnostic-logs): +there is no separate command for them. `history show` includes a run's log +when one was captured and is still kept. + +### `mapbox history list` + +The most recent runs, newest first: a short id, when it ran (UTC), its exit +code and its command path, with `[log]` after a run whose diagnostic log was +captured (`diagnosticsCaptured` in `json`). `json` gives each run's full +`id`, which `history show` also accepts shortened to any prefix that names +one run. + +#### Parameters + +| Parameter | Effect | +| --- | --- | +| `--limit ` | How many runs to list. Defaults to `20`; `0` lists every recorded run. | + +#### Examples + +```sh +mapbox history list + +mapbox history list --limit 0 +``` + +#### Outputs + + + + +
textjson
+ +``` +ID TIME EXIT COMMAND +49d6ec63 2026-09-28T11:26:38.569Z 2 mapbox styles +2c67e6a1 2026-09-28T11:26:38.515Z 1 mapbox styles list [log] +``` + + + +```json +[ + { + "command": [ + "styles" + ], + "durationMs": 42, + "errorCode": "usage", + "exitCode": 2, + "id": "49d6ec63-719d-4844-9005-a201fa9902c3", + "time": "2026-09-28T11:26:38.569Z" + }, + { + "command": [ + "styles", + "list" + ], + "diagnosticsCaptured": true, + "durationMs": 191, + "errorCode": "http_401", + "exitCode": 1, + "id": "2c67e6a1-0e32-4037-9c49-3fd21a62fab5", + "time": "2026-09-28T11:26:38.515Z" + } +] +``` + +
+ +### `mapbox history show` + +Everything recorded about one run — its command path, how it ended, its +error code, how many requests it made and the ids of the last five — and +what became of its diagnostic log, as `diagnostics.status` in `json`: + +| `status` | Meaning | +| --- | --- | +| `captured` | The log is in `diagnostics.log`: the command line with tokens redacted, which token was used, each request and the error message. | +| `not_captured` | Diagnostic logging was off for this run. | +| `unavailable` | A log was captured but has since expired or been removed to keep diagnostic logs under 100 MB. | + +An id that names no run fails with `history_not_found`; a prefix shared by +several fails with `history_ambiguous_id`; with nothing recorded yet, +`show` with no id fails with `history_empty`. + +#### Parameters + +| Parameter | Effect | +| --- | --- | +| `[id]` | The run's id, or any prefix of it that names one run. The newest run when left out. | + +#### Examples + +```sh +mapbox history show + +mapbox history show 2c67e6a1 +``` + +#### Outputs + +A run whose log was captured: + + + + +
textjson
+ +``` +Run 2c67e6a1-0e32-4037-9c49-3fd21a62fab5 +Time 2026-09-28T11:26:38.515Z (mapbox 0.3.0) +Command mapbox styles list +Exit 1 after 191 ms +Error http_401 +Requests 1 + request id Aa-RR5_S57xRecEYSj1rtfOCcwjDVNCnA8eUvLDFDf824mdVExRDDg== +Log mapbox styles list --username example --token + token flag, pk, account example + GET https://api.mapbox.com/styles/v1/example?access_token= -> 401 in 149 ms (request id Aa-RR5_S57xRecEYSj1rtfOCcwjDVNCnA8eUvLDFDf824mdVExRDDg==) + 0 bytes to stdout + error http_401: Not Authorized - Invalid Token +``` + + + +```json +{ + "command": [ + "styles", + "list" + ], + "diagnostics": { + "log": { + "argv": [ + "styles", + "list", + "--username", + "example", + "--token", + "" + ], + "auth": { + "account": "example", + "source": "flag", + "type": "pk" + }, + "error": { + "code": "http_401", + "message": "Not Authorized - Invalid Token" + }, + "requests": [ + { + "durationMs": 149, + "method": "GET", + "requestId": "Aa-RR5_S57xRecEYSj1rtfOCcwjDVNCnA8eUvLDFDf824mdVExRDDg==", + "status": 401, + "url": "https://api.mapbox.com/styles/v1/example?access_token=" + } + ], + "stdoutBytes": 0 + }, + "status": "captured" + }, + "durationMs": 191, + "errorCode": "http_401", + "exitCode": 1, + "id": "2c67e6a1-0e32-4037-9c49-3fd21a62fab5", + "invocation": "execute", + "requestCount": 1, + "requestIds": [ + "Aa-RR5_S57xRecEYSj1rtfOCcwjDVNCnA8eUvLDFDf824mdVExRDDg==" + ], + "time": "2026-09-28T11:26:38.515Z", + "version": "0.3.0" +} +``` + +
+ +Without a log, the last line of `text` says why, and `json` carries only +the status: + +``` +Log not captured: diagnostic logging was off for this run (`mapbox config set log on` captures the next ones) +Log no longer available: it expired or was removed to keep diagnostic logs under 100 MB +``` + +--- + ## Doctor ### `mapbox doctor` diff --git a/src/account_usage.rs b/src/account_usage.rs index 461c3b9..113ed42 100644 --- a/src/account_usage.rs +++ b/src/account_usage.rs @@ -508,7 +508,7 @@ fn days_from_civil(y: i64, m: u32, d: u32) -> i64 { } /// The inverse of [`days_from_civil`]. -fn civil_from_days(z: i64) -> (i64, u32, u32) { +pub(crate) fn civil_from_days(z: i64) -> (i64, u32, u32) { let z = z + 719468; let era = z.div_euclid(146097); let doe = z - era * 146097; // [0, 146096] @@ -599,12 +599,13 @@ fn fetch( eprintln!("[debug] GET {}", redacted_url(&url, &query)); } - let response = client - .get(&url) - .query(&query) - .timeout(http::budget(timeout, http::Payload::Bounded)) - .send() - .map_err(|e| executor::transport_failure("Request failed", e))?; + let response = http::send( + client + .get(&url) + .query(&query) + .timeout(http::budget(timeout, http::Payload::Bounded)), + ) + .map_err(|e| executor::transport_failure("Request failed", e))?; let status = response.status(); // Before `text()` consumes the response: a 5xx here is worth escalating, diff --git a/src/agent_skills.rs b/src/agent_skills.rs index 63b45a4..83d2340 100644 --- a/src/agent_skills.rs +++ b/src/agent_skills.rs @@ -224,9 +224,7 @@ fn fetch(base: &str, git_ref: &str, debug: bool) -> Result> { eprintln!("[debug] GET {url}"); } - let response = http::client()? - .get(&url) - .send() + let response = http::send(http::client()?.get(&url)) .map_err(|e| executor::transport_failure("Could not reach GitHub", e))?; let status = response.status(); diff --git a/src/auth.rs b/src/auth.rs index e8ae735..18d6369 100644 --- a/src/auth.rs +++ b/src/auth.rs @@ -743,10 +743,7 @@ fn refresh_credentials(creds: &mut Credentials, debug: bool) -> Result<()> { eprintln!("[debug] POST {} (grant_type=refresh_token)", TOKEN_ENDPOINT); } - let resp = client - .post(TOKEN_ENDPOINT) - .form(¶ms) - .send() + let resp = crate::http::send(client.post(TOKEN_ENDPOINT).form(¶ms)) .context("Token refresh request failed")?; if !resp.status().is_success() { @@ -781,8 +778,11 @@ pub fn force_refresh(debug: bool, profile: Option<&str>, mode: Mode) -> Result<( let mut creds = load_credentials(profile) .ok_or_else(|| anyhow!("Not currently logged in. Run `mapbox auth login` first."))?; + crate::run_record::set_auth_step("refresh"); refresh_credentials(&mut creds, debug)?; + crate::run_record::set_auth_step("save_credentials"); save_credentials(&creds, profile)?; + crate::run_record::set_auth_step("done"); let expires_at = token_expires_at(&creds.access_token); let text = match expires_at { @@ -985,8 +985,10 @@ pub fn logout(profile: Option<&str>, mode: Mode) -> Result<()> { let path = credentials_path(profile)?; let had_credentials = path.exists(); if had_credentials { + crate::run_record::set_auth_step("remove_credentials"); std::fs::remove_file(&path)?; } + crate::run_record::set_auth_step("done"); let text = if had_credentials { "Logged out successfully." @@ -1225,17 +1227,18 @@ fn verify_token(token: &str, debug: bool, timeout: Option) -> Result"); } - let response = crate::http::client()? - .get(VALIDATION_ENDPOINT) - .query(&[("access_token", token)]) - // The one request `auth` makes to a Mapbox API rather than to the - // authorization server, so it is the one `--timeout` has to reach. - // The other three — refresh, registration, code exchange — carry a - // few hundred bytes each and keep the client's own budget. - .timeout(crate::http::budget(timeout, crate::http::Payload::Bounded)) - .send() - // `reqwest::Error`'s `Display` appends the URL, and the token is in it. - .map_err(|e| crate::executor::transport_failure("Token check failed", e))?; + let response = crate::http::send( + crate::http::client()? + .get(VALIDATION_ENDPOINT) + .query(&[("access_token", token)]) + // The one request `auth` makes to a Mapbox API rather than to the + // authorization server, so it is the one `--timeout` has to reach. + // The other three — refresh, registration, code exchange — carry a + // few hundred bytes each and keep the client's own budget. + .timeout(crate::http::budget(timeout, crate::http::Payload::Bounded)), + ) + // `reqwest::Error`'s `Display` appends the URL, and the token is in it. + .map_err(|e| crate::executor::transport_failure("Token check failed", e))?; let status = response.status(); // Before `text()` consumes the response — see `executor::request_id`. @@ -1654,12 +1657,13 @@ fn register_client(redirect_uri: &str, debug: bool, scopes: &str) -> Result, mode: Mode) -> Result<()> { // Computed once: register_client's ceiling and the authorize scope must agree. let scopes = default_scopes(); + crate::run_record::set_auth_step("register_client"); output::progress("Registering OAuth client with Mapbox..."); let registration = register_client(&redirect_uri, debug, scopes)?; @@ -2140,6 +2142,7 @@ pub fn login(debug: bool, profile: Option<&str>, mode: Mode) -> Result<()> { // Not discarded: with stderr redirected this is the only thing carrying // the run, so its failure is the difference between refusing now and // stalling for five minutes. See `login_can_be_completed`. + crate::run_record::set_auth_step("open_browser"); let browser_opened = open::that(&auth_url).is_ok(); if !login_can_be_completed(std::io::stderr().is_terminal(), browser_opened) { return Err(login_has_no_way_to_show_the_url()); @@ -2148,8 +2151,10 @@ pub fn login(debug: bool, profile: Option<&str>, mode: Mode) -> Result<()> { output::progress(&format!( "Waiting for authorization (listening on port {port})..." )); + crate::run_record::set_auth_step("wait_for_callback"); let code = wait_for_callback(port, &state, CALLBACK_TIMEOUT)?; + crate::run_record::set_auth_step("exchange_code"); output::progress("Exchanging authorization code for access token..."); let mut creds = exchange_code_for_token( &code, @@ -2161,7 +2166,9 @@ pub fn login(debug: bool, profile: Option<&str>, mode: Mode) -> Result<()> { )?; creds.client_id = Some(registration.client_id.clone()); + crate::run_record::set_auth_step("save_credentials"); save_credentials(&creds, profile)?; + crate::run_record::set_auth_step("done"); let profile_note = match profile { Some(name) if name != "default" => format!(" (profile: {name})"), diff --git a/src/completion.rs b/src/completion.rs index 0a33158..ad94605 100644 --- a/src/completion.rs +++ b/src/completion.rs @@ -153,6 +153,7 @@ pub fn run(app: &Command, matches: &ArgMatches) -> Result<()> { // Straight to stdout rather than through `output::emit`: the script is // the result, and there is no rendering of it that is not itself. + crate::run_record::add_stdout_bytes(script.len()); let mut out = io::stdout().lock(); match out.write_all(&script).and_then(|()| out.flush()) { // A reader that stopped reading is `head`'s ordinary behavior, not a diff --git a/src/config.rs b/src/config.rs index af955ea..81fcaa7 100644 --- a/src/config.rs +++ b/src/config.rs @@ -6,9 +6,9 @@ //! file beside the credentials, written through the same //! [`crate::auth::write_private`] so it gets the same `0600` treatment. //! -//! One setting today — `update-check` — with room for more: `get`/`set`/ -//! `unset` take a `key`, restricted by clap to [`KEYS`], so adding a second -//! setting is a new key and a new match arm rather than a new subcommand. +//! `get`/`set`/`unset` take a `key`, restricted by clap to [`KEYS`], so +//! adding a setting is a new key and a new match arm rather than a new +//! subcommand. //! `list` needs no key at all: it walks [`KEYS`] and reports every setting's //! current value in one call, which `get` cannot — the whole reason it //! exists alongside `get`/`set` rather than waiting for a second setting to @@ -23,14 +23,17 @@ use serde::{Deserialize, Serialize}; use serde_json::{json, Value}; use crate::auth; -use crate::output::{self, Mode}; +use crate::output::{self, CliError, Mode}; +use crate::remedy::Remedy; pub const COMMAND: &str = "config"; const CONFIG_FILE: &str = "config.json"; const UPDATE_CHECK_KEY: &str = "update-check"; -const KEYS: &[&str] = &[UPDATE_CHECK_KEY]; +const HISTORY_KEY: &str = "history"; +const LOG_KEY: &str = "log"; +const KEYS: &[&str] = &[UPDATE_CHECK_KEY, HISTORY_KEY, LOG_KEY]; const ON: &str = "on"; const OFF: &str = "off"; @@ -43,6 +46,10 @@ const OFF: &str = "off"; struct Config { #[serde(default, skip_serializing_if = "Option::is_none")] update_check: Option, + #[serde(default, skip_serializing_if = "Option::is_none")] + history: Option, + #[serde(default, skip_serializing_if = "Option::is_none")] + log: Option, } fn config_path() -> Option { @@ -83,6 +90,18 @@ pub fn update_check_enabled() -> bool { update_check_setting(&read_config()) } +/// Whether [`crate::run_history`] records runs, per the persisted setting. +/// On unless turned off. +pub fn history_enabled() -> bool { + read_config().history.unwrap_or(true) +} + +/// Whether [`crate::run_log`] writes diagnostics, per the persisted setting. +/// Off unless turned on, and it has no effect while history is off. +pub fn log_enabled() -> bool { + read_config().log.unwrap_or(false) +} + fn on_off(enabled: bool) -> &'static str { if enabled { ON @@ -97,6 +116,8 @@ fn on_off(enabled: bool) -> &'static str { fn resolve(config: &Config, key: &str) -> bool { match key { UPDATE_CHECK_KEY => update_check_setting(config), + HISTORY_KEY => config.history.unwrap_or(true), + LOG_KEY => config.log.unwrap_or(false), _ => unreachable!("clap's value_parser restricts `key` to {KEYS:?}"), } } @@ -109,6 +130,8 @@ fn resolve(config: &Config, key: &str) -> bool { fn clear(config: &mut Config, key: &str) { match key { UPDATE_CHECK_KEY => config.update_check = None, + HISTORY_KEY => config.history = None, + LOG_KEY => config.log = None, _ => unreachable!("clap's value_parser restricts `key` to {KEYS:?}"), } } @@ -171,8 +194,26 @@ pub fn set(matches: &ArgMatches, mode: Mode) -> Result<()> { let enabled = value == ON; let mut config = read_config(); + // Diagnostics belong to history records, so they need history on. + // Refused rather than stored: a setting that reads `on` and does + // nothing would be worse than an error that says why. + if key == LOG_KEY && enabled && !resolve(&config, HISTORY_KEY) { + return Err(CliError::new( + "history_required", + "Diagnostic logging needs command history, which is off.", + ) + .with_remedy( + Remedy::default().with_action(Some("mapbox config set history on".to_string())), + ) + .into()); + } + if key == HISTORY_KEY && !enabled && resolve(&config, LOG_KEY) { + output::progress("Diagnostic logging (`log`) stays off while history is off."); + } match key.as_str() { UPDATE_CHECK_KEY => config.update_check = Some(enabled), + HISTORY_KEY => config.history = Some(enabled), + LOG_KEY => config.log = Some(enabled), _ => unreachable!("clap's value_parser restricts `key` to {KEYS:?}"), } write_config(&config)?; @@ -228,6 +269,7 @@ mod tests { fn the_config_round_trips_and_tolerates_an_empty_one() { let off = Config { update_check: Some(false), + ..Config::default() }; let text = serde_json::to_string(&off).expect("serialize"); assert_eq!(text, r#"{"update_check":false}"#); @@ -249,7 +291,10 @@ mod tests { #[test] fn resolve_matches_update_check_setting_at_every_state() { for update_check in [None, Some(true), Some(false)] { - let config = Config { update_check }; + let config = Config { + update_check, + ..Config::default() + }; assert_eq!( resolve(&config, UPDATE_CHECK_KEY), update_check_setting(&config) @@ -265,6 +310,7 @@ mod tests { fn clear_removes_the_key_rather_than_writing_the_default() { let mut explicit_default = Config { update_check: Some(true), + ..Config::default() }; clear(&mut explicit_default, UPDATE_CHECK_KEY); assert_eq!(explicit_default, Config::default()); @@ -272,6 +318,7 @@ mod tests { let mut explicit_off = Config { update_check: Some(false), + ..Config::default() }; clear(&mut explicit_off, UPDATE_CHECK_KEY); assert_eq!(explicit_off.update_check, None); diff --git a/src/dated_jsonl.rs b/src/dated_jsonl.rs new file mode 100644 index 0000000..397a274 --- /dev/null +++ b/src/dated_jsonl.rs @@ -0,0 +1,370 @@ +//! Private, append-only, one-file-per-UTC-day JSONL directories under the +//! config directory, pruned to a fixed number of days and held to a total +//! size, for the consumers of [`crate::run_record`] that keep records on +//! disk. The only files this deletes or replaces are ones named exactly +//! `YYYY-MM-DD.jsonl` inside the directory it was handed, and the scratch +//! file a trim writes beside one. + +use std::io::Write; +use std::path::{Path, PathBuf}; +use std::time::{SystemTime, UNIX_EPOCH}; + +use crate::auth; + +/// `/`, created `0700`, or `None`. +/// +/// A missing config directory is created `0700`; an existing one is left +/// as it is, since a record may come from a read-only command and hardening +/// it is `auth`'s job. A config path that isn't a directory is `auth`'s to +/// report. +pub(crate) fn private_dir(name: &str) -> Option { + let config = auth::config_dir_path()?; + if config.exists() && !config.is_dir() { + return None; + } + let dir = config.join(name); + let mut builder = std::fs::DirBuilder::new(); + builder.recursive(true); + #[cfg(unix)] + { + use std::os::unix::fs::{DirBuilderExt, PermissionsExt}; + builder.mode(0o700); + builder.create(&dir).ok()?; + // `mode` is filtered by the umask and skipped for a directory that + // already existed. + let _ = std::fs::set_permissions(&dir, std::fs::Permissions::from_mode(0o700)); + } + #[cfg(not(unix))] + builder.create(&dir).ok()?; + Some(dir) +} + +/// Appends `line` to the file in `dir` for `at`'s UTC day, and on the first +/// write of a day deletes files older than `keep_days` (that day included). +/// Best-effort. +pub(crate) fn append(dir: &Path, line: &str, at: SystemTime, keep_days: u64) { + let now = unix_secs(at); + let (today, _) = utc_date(now); + let path = dir.join(format!("{today}.jsonl")); + let is_new_day = !path.exists(); + // One `write` per line. `O_APPEND` places each one at the end, but a + // line past the platform's atomic-write size is not guaranteed to stay + // whole against a parallel run writing at the same moment. + if let Ok(mut file) = open_private(&path) { + let _ = file.write_all(format!("{line}\n").as_bytes()); + } + if is_new_day { + prune(dir, now, keep_days); + } +} + +/// Holds `dir`'s dated files, together, to `limit` bytes by dropping the +/// oldest lines first — whole days while a day is all that has to go, then +/// the oldest lines of the oldest day left. Sheds down to nine tenths of +/// `limit`, so the next run does not have to shed again. +pub(crate) fn shed(dir: &Path, limit: u64) { + let mut files: Vec<(String, u64)> = dated_names(dir) + .into_iter() + .filter_map(|name| Some((name.clone(), std::fs::metadata(dir.join(&name)).ok()?.len()))) + .collect(); + let total: u64 = files.iter().map(|(_, size)| size).sum(); + if total <= limit { + return; + } + let mut excess = total - limit / 10 * 9; + files.sort(); + for (name, size) in files { + if excess == 0 { + break; + } + let path = dir.join(&name); + if size <= excess { + let _ = std::fs::remove_file(&path); + excess -= size; + } else { + trim(&path, size - excess); + excess = 0; + } + } +} + +/// Deletes the dated files in `dir` whose date `keep` refuses. +pub(crate) fn prune_where(dir: &Path, keep: impl Fn(&str) -> bool) { + for name in dated_names(dir) { + if let Some(date) = dated_file(&name) { + if !keep(date) { + let _ = std::fs::remove_file(dir.join(&name)); + } + } + } +} + +/// The lines of `dir`'s file for `date` (`YYYY-MM-DD`), oldest first. +pub(crate) fn read_day(dir: &Path, date: &str) -> Vec { + let path = dir.join(format!("{date}.jsonl")); + std::fs::read_to_string(path) + .map(|text| { + text.lines() + .filter(|line| !line.is_empty()) + .map(str::to_string) + .collect() + }) + .unwrap_or_default() +} + +/// The oldest date kept by a window of `days` (today included), as of now. +pub(crate) fn oldest_kept(days: u64) -> String { + oldest_kept_at(unix_secs(SystemTime::now()), days) +} + +fn oldest_kept_at(now: u64, days: u64) -> String { + utc_date(now.saturating_sub(days.saturating_sub(1) * 86_400)).0 +} + +fn dated_names(dir: &Path) -> Vec { + let Ok(entries) = std::fs::read_dir(dir) else { + return vec![]; + }; + entries + .flatten() + .map(|entry| entry.file_name().to_string_lossy().into_owned()) + .filter(|name| dated_file(name).is_some()) + .collect() +} + +/// Every line in `dir`'s dated files, oldest first. A missing directory is +/// no lines. +pub(crate) fn read_all(dir: &Path) -> Vec { + let mut names = dated_names(dir); + names.sort(); + names + .iter() + .filter_map(|name| std::fs::read_to_string(dir.join(name)).ok()) + .flat_map(|text| { + text.lines() + .filter(|line| !line.is_empty()) + .map(str::to_string) + .collect::>() + }) + .collect() +} + +/// Opens `path` for appending, created `0600` if missing. +fn open_private(path: &Path) -> std::io::Result { + let mut options = std::fs::OpenOptions::new(); + options.append(true).create(true); + #[cfg(unix)] + { + use std::os::unix::fs::OpenOptionsExt; + options.mode(0o600); + } + options.open(path) +} + +/// Keeps the newest whole lines of `path` that fit in `limit` bytes. +/// +/// Written to a scratch file and renamed over the original. A parallel run +/// that appends between the read and the rename loses its line: these files +/// are best-effort, and a lock would make every run pay for a rare race. +fn trim(path: &Path, limit: u64) { + let Ok(text) = std::fs::read_to_string(path) else { + return; + }; + let kept = newest_lines(&text, limit as usize); + if kept.is_empty() { + let _ = std::fs::remove_file(path); + return; + } + let Some(name) = path.file_name() else { + return; + }; + let scratch = path.with_file_name(format!( + ".{}.trim-{}", + name.to_string_lossy(), + std::process::id() + )); + let written = create_private(&scratch) + .and_then(|mut file| file.write_all(kept.as_bytes())) + .and_then(|()| std::fs::rename(&scratch, path)); + if written.is_err() { + let _ = std::fs::remove_file(&scratch); + } +} + +/// The longest suffix of `text` made of whole lines and no longer than +/// `target` bytes. +fn newest_lines(text: &str, target: usize) -> &str { + if text.len() <= target { + return text; + } + let from = text.len() - target; + let bytes = text.as_bytes(); + // The first line that starts at or after `from`. Always just past a + // `\n`, so never inside a character. + let start = if bytes[from - 1] == b'\n' { + from + } else { + bytes[from..] + .iter() + .position(|&b| b == b'\n') + .map_or(text.len(), |p| from + p + 1) + }; + &text[start..] +} + +/// Creates `path` `0600`, failing if it exists. +fn create_private(path: &Path) -> std::io::Result { + let mut options = std::fs::OpenOptions::new(); + options.write(true).create_new(true); + #[cfg(unix)] + { + use std::os::unix::fs::OpenOptionsExt; + options.mode(0o600); + } + options.open(path) +} + +fn prune(dir: &Path, now: u64, keep_days: u64) { + let oldest_kept = oldest_kept_at(now, keep_days); + let Ok(entries) = std::fs::read_dir(dir) else { + return; + }; + for entry in entries.flatten() { + let name = entry.file_name().to_string_lossy().into_owned(); + if let Some(date) = dated_file(&name) { + if date < oldest_kept.as_str() { + let _ = std::fs::remove_file(dir.join(&name)); + } + } + } +} + +fn dated_file(name: &str) -> Option<&str> { + let date = name.strip_suffix(".jsonl")?; + let shape = date.len() == 10 + && date.char_indices().all(|(i, c)| match i { + 4 | 7 => c == '-', + _ => c.is_ascii_digit(), + }); + shape.then_some(date) +} + +/// `YYYY-MM-DD` and the seconds into that day, in UTC. +fn utc_date(unix_secs: u64) -> (String, u64) { + let days = (unix_secs / 86_400) as i64; + let (y, m, d) = crate::account_usage::civil_from_days(days); + (format!("{y:04}-{m:02}-{d:02}"), unix_secs % 86_400) +} + +/// RFC 3339 in UTC, to the millisecond. +pub(crate) fn timestamp(at: SystemTime) -> String { + let since = at.duration_since(UNIX_EPOCH).unwrap_or_default(); + let (date, secs) = utc_date(since.as_secs()); + format!( + "{date}T{:02}:{:02}:{:02}.{:03}Z", + secs / 3600, + secs % 3600 / 60, + secs % 60, + since.subsec_millis() + ) +} + +fn unix_secs(at: SystemTime) -> u64 { + at.duration_since(UNIX_EPOCH).map_or(0, |d| d.as_secs()) +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn only_dated_files_are_pruned() { + assert_eq!(dated_file("2026-09-24.jsonl"), Some("2026-09-24")); + for name in [ + "user-id", + "last-version", + "2026-09-24.json", + "notes.jsonl", + "2026-9-24.jsonl", + ] { + assert_eq!(dated_file(name), None, "{name}"); + } + } + + #[test] + fn prune_keeps_seven_days_and_nothing_else_is_touched() { + let dir = + std::env::temp_dir().join(format!("mapbox-dated-prune-{}", rand::random::())); + std::fs::create_dir_all(&dir).unwrap(); + for name in [ + "2026-09-17.jsonl", + "2026-09-18.jsonl", + "2026-09-24.jsonl", + "user-id", + "2026-09-01.txt", + ] { + std::fs::write(dir.join(name), "x").unwrap(); + } + // 2026-09-24T12:00:00Z: 09-18 through 09-24 is seven days. + prune(&dir, 1_790_251_200, 7); + let mut left: Vec = std::fs::read_dir(&dir) + .unwrap() + .map(|e| e.unwrap().file_name().to_string_lossy().into_owned()) + .collect(); + left.sort(); + std::fs::remove_dir_all(&dir).unwrap(); + assert_eq!( + left, + [ + "2026-09-01.txt", + "2026-09-18.jsonl", + "2026-09-24.jsonl", + "user-id" + ] + ); + } + + #[test] + fn a_trim_keeps_the_newest_whole_lines() { + let text = "aaaa\nbbbb\ncccc\n"; + assert_eq!(newest_lines(text, 100), text); + assert_eq!(newest_lines(text, 10), "bbbb\ncccc\n"); + assert_eq!(newest_lines(text, 9), "cccc\n"); + assert_eq!(newest_lines(text, 4), ""); + } + + #[test] + fn shedding_drops_the_oldest_days_then_the_oldest_lines() { + let dir = std::env::temp_dir().join(format!("mapbox-dated-shed-{}", rand::random::())); + std::fs::create_dir_all(&dir).unwrap(); + let day = |n: u32| format!("2026-09-{n:02}.jsonl"); + // Three days of ten 100-byte lines each. + for n in 1..=3 { + let text: String = (0..10).map(|i| format!("{n}-{i:<96}\n")).collect(); + std::fs::write(dir.join(day(n)), text).unwrap(); + } + let mine = dir.join("notes.txt"); + std::fs::write(&mine, "x".repeat(5000)).unwrap(); + + shed(&dir, 2000); + let left = read_all(&dir); + let total: usize = left.iter().map(|l| l.len() + 1).sum(); + let mine_kept = mine.exists(); + std::fs::remove_dir_all(&dir).unwrap(); + + assert!(mine_kept, "only dated files are shed"); + assert!(total <= 1800, "{total}"); + assert!( + left.iter().all(|l| !l.starts_with("1-")), + "the oldest day went first" + ); + assert!( + left.iter().any(|l| l.starts_with("2-")), + "only as much as needed" + ); + assert!( + left.last().unwrap().starts_with("3-9"), + "the newest line stays" + ); + } +} diff --git a/src/doctor.rs b/src/doctor.rs index 0350178..790a9f8 100644 --- a/src/doctor.rs +++ b/src/doctor.rs @@ -312,11 +312,7 @@ impl ConnectivityReport { /// of this crate uses `Option` for, and what the docs promise. fn check(debug: bool, host: &str, timeout: Duration) -> Self { let outcome = http::client().and_then(|client| { - client - .get(host) - .timeout(timeout) - .send() - .map_err(anyhow::Error::from) + http::send(client.get(host).timeout(timeout)).map_err(anyhow::Error::from) }); match outcome { diff --git a/src/executor.rs b/src/executor.rs index 7bdadff..54bb2b8 100644 --- a/src/executor.rs +++ b/src/executor.rs @@ -283,9 +283,7 @@ fn dispatch( req = attach_body(req, source)?; } - let response = req - .send() - .map_err(|e| transport_failure("Request failed", e))?; + let response = crate::http::send(req).map_err(|e| transport_failure("Request failed", e))?; let status = response.status(); // Must read headers before `bytes()` consumes the response — anything // not taken here is gone after. For a long time only `Content-Type` @@ -348,6 +346,9 @@ fn dispatch( .next_page .as_deref() .map(|next| NextPage::of(&op.query_params, next)); + if next_page.is_some() { + crate::run_record::set_more_pages(); + } match as_text { Some(text) => match serde_json::from_str::(&text) { @@ -574,6 +575,15 @@ fn with_page_context(err: anyhow::Error, next_page: Option<&NextPage>) -> anyhow } } +/// [`redacted_url`] for a request already built. +pub(crate) fn redacted_request_url(url: &reqwest::Url) -> String { + let mut base = url.clone(); + base.set_query(None); + base.set_fragment(None); + let query: Vec<(String, String)> = url.query_pairs().into_owned().collect(); + redacted_url(base.as_str(), &query) +} + /// The request line a reader may safely see: URL, query, token replaced. /// /// The access token rides in the query string, so every rendering of this @@ -1392,6 +1402,7 @@ fn write_binary(body: &[u8], content_type: &str) -> Result<()> { .into()); } + crate::run_record::add_stdout_bytes(body.len()); stdout .write_all(body) .and_then(|()| stdout.flush()) @@ -1882,12 +1893,13 @@ mod tests { let listener = std::net::TcpListener::bind("127.0.0.1:0").expect("a loopback port"); let addr = listener.local_addr().expect("the bound address"); - let failure = crate::http::client() - .expect("a client") - .get(format!("http://{addr}/")) - .timeout(std::time::Duration::from_millis(250)) - .send() - .expect_err("a server that never answers cannot have answered"); + let failure = crate::http::send( + crate::http::client() + .expect("a client") + .get(format!("http://{addr}/")) + .timeout(std::time::Duration::from_millis(250)), + ) + .expect_err("a server that never answers cannot have answered"); let reported = super::transport_failure("Request failed", failure); assert_eq!(reported.code, "request_timed_out"); diff --git a/src/history.rs b/src/history.rs new file mode 100644 index 0000000..b0cb9d8 --- /dev/null +++ b/src/history.rs @@ -0,0 +1,374 @@ +//! `mapbox history` — the runs [`crate::run_history`] recorded. +//! +//! `list` is one line per run, newest first; `show` is everything recorded +//! about one run, the newest when no id is given, with its diagnostic log +//! when one was captured and is still kept ([`crate::run_log`]). An id can +//! be shortened to any prefix that names one run, the way `list` prints +//! them. There is no separate command for the logs: history is the one way +//! in to both. +//! +//! Reads history and nothing else: no token, no request, and nothing +//! created on disk. It is not itself recorded. + +use anyhow::Result; +use clap::{value_parser, Arg, ArgMatches, Command}; +use serde_json::{json, Value}; + +use crate::output::{self, CliError, Mode}; +use crate::remedy::Remedy; +use crate::{run_history, run_log}; + +pub const COMMAND: &str = "history"; + +const DEFAULT_LIMIT: usize = 20; +/// How much of an id `list` prints: enough to tell runs apart, short enough +/// to type back into `show`. +const SHORT_ID: usize = 8; + +pub fn command() -> Command { + Command::new(COMMAND) + .about("List and show recent command runs") + .long_about( + "List and show recent command runs: which command ran, how it ended and \ + how long it took, kept for 30 days on this machine. Argument values are \ + never recorded. Turn it off with `mapbox config set history off`.", + ) + .subcommand_required(true) + .subcommand( + Command::new("list") + .about("List the most recent runs, newest first") + .arg( + Arg::new("limit") + .long("limit") + .value_parser(value_parser!(usize)) + .default_value(DEFAULT_LIMIT.to_string()) + .help("How many runs to list; 0 lists every run recorded"), + ), + ) + .subcommand( + Command::new("show") + .about("Show everything recorded about one run") + .arg( + Arg::new("id") + .help("The run's id, or a prefix of it; the newest run when left out"), + ), + ) +} + +pub fn list(matches: &ArgMatches, mode: Mode) -> Result<()> { + let limit = *matches.get_one::("limit").expect("has a default"); + let mut entries = run_history::entries(); + entries.reverse(); + if limit > 0 { + entries.truncate(limit); + } + if entries.is_empty() { + hint_when_off(); + } + + let rows = entries.iter().map(|entry| { + let mut line = format!( + "{:SHORT_ID$} {:24} {:>4} {}", + short_id(entry), + field(entry, "time"), + exit_code(entry), + command_line(entry) + ); + if captured(entry) { + line.push_str(" [log]"); + } + line + }); + let text = if entries.is_empty() { + String::new() + } else { + std::iter::once(format!( + "{:SHORT_ID$} {:24} {:>4} COMMAND", + "ID", "TIME", "EXIT" + )) + .chain(rows) + .collect::>() + .join("\n") + }; + let json = entries + .iter() + .map(|entry| { + let mut summary = serde_json::Map::new(); + for key in [ + "id", + "time", + "command", + "exitCode", + "errorCode", + "durationMs", + "diagnosticsCaptured", + ] { + if let Some(value) = entry.get(key) { + summary.insert(key.to_string(), value.clone()); + } + } + Value::Object(summary) + }) + .collect(); + + output::emit(mode, &text, Value::Array(json)) +} + +pub fn show(matches: &ArgMatches, mode: Mode) -> Result<()> { + let entries = run_history::entries(); + let entry = match matches.get_one::("id") { + None => entries.last().cloned().ok_or_else(|| { + hint_when_off(); + CliError::new("history_empty", "No runs have been recorded yet.") + })?, + Some(prefix) => find(&entries, prefix)?, + }; + let diagnostics = diagnostics(&entry); + let mut text = detail(&entry); + text.push('\n'); + text.push_str(&diagnostics_detail(&diagnostics)); + let mut json = entry; + if let Some(object) = json.as_object_mut() { + object.remove("diagnosticsCaptured"); + object.insert("diagnostics".to_string(), diagnostics.json()); + } + output::emit(mode, &text, json) +} + +/// What became of a run's diagnostic log. +enum Diagnostics { + /// Logging was off for the run. + NotCaptured, + /// Captured, then expired or dropped to stay under the size limit. + Unavailable, + Captured(Value), +} + +impl Diagnostics { + /// `status` is a machine-readable value: `not_captured`, `unavailable` + /// or `captured`. + fn json(&self) -> Value { + match self { + Diagnostics::NotCaptured => json!({ "status": "not_captured" }), + Diagnostics::Unavailable => json!({ "status": "unavailable" }), + Diagnostics::Captured(log) => json!({ "status": "captured", "log": log }), + } + } +} + +fn captured(entry: &Value) -> bool { + entry.get("diagnosticsCaptured").and_then(Value::as_bool) == Some(true) +} + +fn diagnostics(entry: &Value) -> Diagnostics { + if !captured(entry) { + return Diagnostics::NotCaptured; + } + match run_log::find(field(entry, "id"), field(entry, "time")) { + Some(mut log) => { + // Already in the record it belongs to. + if let Some(object) = log.as_object_mut() { + for key in ["id", "time"] { + object.remove(key); + } + } + Diagnostics::Captured(log) + } + None => Diagnostics::Unavailable, + } +} + +fn diagnostics_detail(diagnostics: &Diagnostics) -> String { + let log = match diagnostics { + Diagnostics::NotCaptured => { + return "Log not captured: diagnostic logging was off for this run \ + (`mapbox config set log on` captures the next ones)" + .to_string() + } + Diagnostics::Unavailable => { + return "Log no longer available: it expired or was removed to keep \ + diagnostic logs under 100 MB" + .to_string() + } + Diagnostics::Captured(log) => log, + }; + let argv: Vec<&str> = log["argv"] + .as_array() + .map(|args| args.iter().filter_map(Value::as_str).collect()) + .unwrap_or_default(); + let mut out = vec![format!("Log mapbox {}", argv.join(" "))]; + if let Some(auth) = log.get("auth") { + let mut line = format!(" token {}, {}", field(auth, "source"), field(auth, "type")); + if let Some(account) = auth.get("account").and_then(Value::as_str) { + line.push_str(&format!(", account {account}")); + } + out.push(line); + } + if let Some(step) = log.get("authStep").and_then(Value::as_str) { + out.push(format!(" auth step {step}")); + } + for request in log["requests"].as_array().into_iter().flatten() { + let outcome = match request.get("status").and_then(Value::as_u64) { + Some(status) => status.to_string(), + None => field(request, "error").to_string(), + }; + let mut line = format!( + " {} {} -> {} in {} ms", + field(request, "method"), + field(request, "url"), + outcome, + request["durationMs"].as_u64().unwrap_or(0) + ); + if let Some(id) = request.get("requestId").and_then(Value::as_str) { + line.push_str(&format!(" (request id {id})")); + } + out.push(line); + } + if let Some(n) = log.get("requestsNotListed").and_then(Value::as_u64) { + out.push(format!(" and {n} more requests not listed")); + } + if log.get("morePages").and_then(Value::as_bool) == Some(true) { + out.push(" stopped with pages left".to_string()); + } + out.push(format!( + " {} bytes to stdout", + log["stdoutBytes"].as_u64().unwrap_or(0) + )); + if let Some(version) = log.get("updateNotice").and_then(Value::as_str) { + out.push(format!(" update notice for {version}")); + } + if let Some(error) = log.get("error") { + out.push(format!( + " error {}: {}", + field(error, "code"), + field(error, "message") + )); + } + out.join("\n") +} + +/// The one run whose id starts with `prefix`. +fn find(entries: &[Value], prefix: &str) -> Result { + let matching: Vec<&Value> = entries + .iter() + .filter(|entry| !prefix.is_empty() && field(entry, "id").starts_with(prefix)) + .collect(); + match matching.as_slice() { + [one] => Ok((*one).clone()), + [] => Err(CliError::new( + "history_not_found", + format!("No recorded run has an id starting with `{prefix}`."), + ) + .with_remedy(Remedy::default().with_action(Some("mapbox history list".to_string()))) + .into()), + many => Err(CliError::new( + "history_ambiguous_id", + format!( + "`{prefix}` starts {} run ids; give more of the id.", + many.len() + ), + ) + .into()), + } +} + +/// A person-readable view of one run. JSON gets the line as it was recorded. +fn detail(entry: &Value) -> String { + let mut out = vec![ + format!("Run {}", field(entry, "id")), + format!( + "Time {} (mapbox {})", + field(entry, "time"), + field(entry, "version") + ), + format!("Command {}", command_line(entry)), + format!( + "Exit {} after {} ms", + exit_code(entry), + entry["durationMs"].as_u64().unwrap_or(0) + ), + ]; + if let Some(code) = entry.get("errorCode").and_then(Value::as_str) { + out.push(format!("Error {code}")); + } + if let Some(count) = entry.get("requestCount").and_then(Value::as_u64) { + out.push(format!("Requests {count}")); + } + for id in entry["requestIds"].as_array().into_iter().flatten() { + if let Some(id) = id.as_str() { + out.push(format!(" request id {id}")); + } + } + out.join("\n") +} + +/// Says why there is nothing to read, on stderr, when history is off. +fn hint_when_off() { + if !run_history::enabled() { + output::progress( + "History is off. Turn it on with `mapbox config set history on`, \ + or `MAPBOX_HISTORY=1` for this shell.", + ); + } +} + +fn field<'a>(value: &'a Value, key: &str) -> &'a str { + value.get(key).and_then(Value::as_str).unwrap_or("-") +} + +fn short_id(entry: &Value) -> String { + field(entry, "id").chars().take(SHORT_ID).collect() +} + +fn exit_code(entry: &Value) -> String { + entry + .get("exitCode") + .and_then(Value::as_u64) + .map_or_else(|| "-".to_string(), |code| code.to_string()) +} + +/// `mapbox` and the command path: what ran, never what was typed after it. +fn command_line(entry: &Value) -> String { + let path: Vec<&str> = entry["command"] + .as_array() + .map(|words| words.iter().filter_map(Value::as_str).collect()) + .unwrap_or_default(); + if path.is_empty() { + "mapbox".to_string() + } else { + format!("mapbox {}", path.join(" ")) + } +} + +#[cfg(test)] +mod tests { + use super::*; + + fn runs() -> Vec { + vec![ + json!({ "id": "abc12345-0000-4000-8000-000000000001" }), + json!({ "id": "abc19999-0000-4000-8000-000000000002" }), + json!({ "id": "def00000-0000-4000-8000-000000000003" }), + ] + } + + #[test] + fn a_prefix_that_names_one_run_finds_it() { + let found = find(&runs(), "abc1234").unwrap(); + assert_eq!(field(&found, "id"), "abc12345-0000-4000-8000-000000000001"); + } + + #[test] + fn a_prefix_that_names_several_or_none_is_an_error() { + let code = |prefix: &str| { + find(&runs(), prefix) + .unwrap_err() + .downcast::() + .unwrap() + .code + }; + assert_eq!(code("abc1"), "history_ambiguous_id"); + assert_eq!(code("fff"), "history_not_found"); + assert_eq!(code(""), "history_not_found"); + } +} diff --git a/src/http.rs b/src/http.rs index 26cd087..3c64eee 100644 --- a/src/http.rs +++ b/src/http.rs @@ -20,7 +20,7 @@ use std::time::Duration; use anyhow::{Context, Result}; use clap::ArgMatches; -use crate::telemetry; +use crate::{executor, run_record, telemetry}; /// The flag and the variable a caller moves the budget with. pub const TIMEOUT_ARG: &str = "timeout"; @@ -240,6 +240,76 @@ fn build(timeout: Duration, command_group: Option<&str>) -> Result reqwest::Result { + let (client, request) = request.build_split(); + let request = request?; + let method = request.method().to_string(); + let url = executor::redacted_request_url(request.url()); + let body_bytes = request + .body() + .and_then(|body| body.as_bytes()) + .map(|bytes| bytes.len() as u64); + let mapbox = request.url().host_str().is_some_and(is_mapbox_host); + + let started = std::time::Instant::now(); + let result = client.execute(request); + let elapsed = started.elapsed(); + + let (status, response_bytes, request_id, error) = match &result { + Ok(response) => ( + Some(response.status().as_u16()), + response.content_length(), + mapbox + .then(|| executor::request_id(response.headers())) + .flatten(), + None, + ), + Err(err) => (None, None, None, Some(failure(err))), + }; + run_record::add_request(run_record::Request { + method, + url, + status, + request_id, + request_body_bytes: body_bytes, + response_bytes, + elapsed, + error, + }); + result +} + +/// What went wrong with a request that got no response. Not `err`'s own +/// `Display`, which appends the URL — token and all. +fn failure(err: &reqwest::Error) -> String { + let kind = if err.is_timeout() { + "timed out" + } else if err.is_connect() { + "could not connect" + } else { + "failed" + }; + match std::error::Error::source(err) { + Some(source) => format!("{kind}: {source}"), + None => kind.to_string(), + } +} + +fn is_mapbox_host(host: &str) -> bool { + host == "mapbox.com" || host.ends_with(".mapbox.com") +} + #[cfg(test)] mod tests { use super::*; diff --git a/src/main.rs b/src/main.rs index a829eb8..49d4ebe 100644 --- a/src/main.rs +++ b/src/main.rs @@ -19,14 +19,19 @@ mod auth; mod completion; mod config; mod confirm; +mod dated_jsonl; mod deprecation; mod doctor; mod executor; mod generate_skills; +mod history; mod http; mod link; mod output; mod remedy; +mod run_history; +mod run_log; +mod run_record; mod schema; mod skill_dest; mod spec; @@ -608,6 +613,9 @@ fn build_app(specs: &[ServiceSpec]) -> Command { // machine, never the network. app = app.subcommand(config::command()); + // Beside `config`, which turns the history it reads on and off. + app = app.subcommand(history::command()); + // Reads what the other hand-written commands above also read — the // token store, the proxy environment, the config and telemetry // switches — so it belongs beside them rather than the API surface @@ -664,13 +672,14 @@ fn no_stored_credentials(profile: Option<&str>) -> anyhow::Error { } /// Answers `--schema`, from either of the two places it can be noticed. -fn emit_schema(app: &Command, specs: &[ServiceSpec], matches: &ArgMatches) -> ExitCode { +fn emit_schema(app: &Command, specs: &[ServiceSpec], matches: &ArgMatches) -> u8 { + run_record::set_parsed(app, specs, matches, run_record::Invocation::Schema); let mode = Mode::from_matches(matches); match schema::emit(mode, app, specs, matches) { - Ok(()) => ExitCode::SUCCESS, + Ok(()) => 0, Err(e) => { output::emit_error(mode, &e); - ExitCode::FAILURE + 1 } } } @@ -693,15 +702,21 @@ fn main() -> ExitCode { return update_check::run_refresh_child(); } + run_record::start(&std::env::args_os().collect::>()); let code = cli(); update_check::notify(); - code + // After the notice, which the run reports. + run_record::finish(Some(u32::from(code))); + ExitCode::from(code) } /// Every failure leaves through here, so that one `--output` decision covers /// results and errors alike. `run` does the work; `cli` only chooses how /// what comes back is rendered. -fn cli() -> ExitCode { +/// +/// The exit code is returned as a number rather than an `ExitCode`, which +/// cannot be read back, so `main` can record it. +fn cli() -> u8 { // Kept whole for the pre-parse fallback: `escape_passthrough_args` // rewrites the line for clap, and a failure needs to see what the caller // actually typed. @@ -713,7 +728,7 @@ fn cli() -> ExitCode { // cannot be until the specs it is parsed against exist. Err(e) => { output::emit_error(Mode::early(&raw_argv), &e); - return ExitCode::FAILURE; + return 1; } }; @@ -730,7 +745,10 @@ fn cli() -> ExitCode { // scan of argv — say whether `--schema` was really what was written. Err(e) => match schema::requested(&app, argv) { Some(matches) => return emit_schema(&app, &specs, &matches), - None => return report_parse_result(e, &raw_argv), + None => { + run_record::set_unparsed(&app, &raw_argv, e.kind()); + return report_parse_result(e, &raw_argv); + } }, }; @@ -741,12 +759,13 @@ fn cli() -> ExitCode { return emit_schema(&app, &specs, &matches); } + run_record::set_parsed(&app, &specs, &matches, run_record::Invocation::Execute); let mode = Mode::from_matches(&matches); match run(&app, &specs, &matches, mode) { - Ok(()) => ExitCode::SUCCESS, + Ok(()) => 0, Err(e) => { output::emit_error(mode, &e); - ExitCode::FAILURE + 1 } } } @@ -762,7 +781,7 @@ fn cli() -> ExitCode { /// The mode cannot come from the parse that just failed, so `Mode::early` /// reads `--output` off argv itself — an explicit choice has to survive the /// error that makes it matter most. -fn report_parse_result(err: clap::Error, raw_argv: &[std::ffi::OsString]) -> ExitCode { +fn report_parse_result(err: clap::Error, raw_argv: &[std::ffi::OsString]) -> u8 { let err = drop_subcommand_from_short_circuit_usage(err); // Clap uses 2 for a usage error and 0 for help/version; preserving that @@ -782,17 +801,6 @@ fn report_parse_result(err: clap::Error, raw_argv: &[std::ffi::OsString]) -> Exi | ErrorKind::DisplayHelpOnMissingArgumentOrSubcommand ); - // `MissingSubcommand` is exactly the case the code below already builds a - // short message and a `--help` suggestion for; that used to run only - // under `json`, so a bare `mapbox` in a terminal got clap's raw dump — - // the error paragraph, a repeated usage line, and a `--help` hint that - // says nothing the message above it didn't. Text mode deserves the same - // one-line-plus-suggestion treatment json already gets. - if is_help || (!mode.is_json() && err.kind() != ErrorKind::MissingSubcommand) { - let _ = err.print(); - return ExitCode::from(code); - } - // Clap's rendering is an error paragraph, then a blank line, then usage // and a hint that are help for a reader who is not going to be one here. // Take the whole paragraph, not just its first line: a missing-argument @@ -814,6 +822,25 @@ fn report_parse_result(err: clap::Error, raw_argv: &[std::ffi::OsString]) -> Exi message }; + // `MissingSubcommand` is exactly the case the code below already builds a + // short message and a `--help` suggestion for; that used to run only + // under `json`, so a bare `mapbox` in a terminal got clap's raw dump — + // the error paragraph, a repeated usage line, and a `--help` hint that + // says nothing the message above it didn't. Text mode deserves the same + // one-line-plus-suggestion treatment json already gets. + if is_help || (!mode.is_json() && err.kind() != ErrorKind::MissingSubcommand) { + if !is_help { + // Printed by clap rather than `emit_error`, which records the rest. + run_record::set_error("usage", message); + } + if !err.use_stderr() { + // Help and the version: clap writes these to stdout itself. + run_record::add_stdout_bytes(err.render().to_string().len()); + } + let _ = err.print(); + return code; + } + // Clap catches a missing subcommand before `run` ever sees it, so give it // the code `run`'s own guard uses. A caller that forgot the operation and // a caller that misspelled a flag want to react differently. @@ -840,7 +867,7 @@ fn report_parse_result(err: clap::Error, raw_argv: &[std::ffi::OsString]) -> Exi }); output::emit_error(mode, &error.into()); - ExitCode::from(code) + code } /// The `tip: …` line clap's own suggester renders for an unrecognized @@ -1016,6 +1043,19 @@ fn run(app: &Command, specs: &[ServiceSpec], matches: &ArgMatches, mode: Mode) - if use_login && token.is_none() { return Err(no_stored_credentials(profile)); } + match &token { + Some(tilesets_cli::ChildToken::Flag(t)) => { + run_record::set_token(auth::TokenSource::Flag, t) + } + Some(tilesets_cli::ChildToken::Stored(t)) => { + run_record::set_token(auth::TokenSource::Login, t) + } + None => { + if let Some((_, t)) = auth::environment_token() { + run_record::set_token(auth::TokenSource::Environment, &t); + } + } + } if token.is_none() { // Falling through to whatever the environment holds. If that // shadows a login for a different account, say so: the @@ -1075,6 +1115,13 @@ fn run(app: &Command, specs: &[ServiceSpec], matches: &ArgMatches, mode: Mode) - Some(("unset", unset_matches)) => config::unset(unset_matches, mode)?, _ => unreachable!("`config` sets subcommand_required(true)"), }, + // Ahead of the generic service arm too: it reads local history and + // makes no request. + Some((history::COMMAND, history_matches)) => match history_matches.subcommand() { + Some(("list", list_matches)) => history::list(list_matches, mode)?, + Some(("show", show_matches)) => history::show(show_matches, mode)?, + _ => unreachable!("`history` sets subcommand_required(true)"), + }, // Also ahead of the generic service arm: read-only except for the // opt-in `--verify` request, and needs no credential load of its own // — it reports what one would resolve to, not what a fresh one @@ -1096,6 +1143,9 @@ fn run(app: &Command, specs: &[ServiceSpec], matches: &ArgMatches, mode: Mode) - if use_login && token.is_none() { return Err(no_stored_credentials(profile)); } + if let Some(token) = &token { + run_record::set_resolved_token(matches, use_login, token); + } account_usage::run( usage_matches, @@ -1209,6 +1259,9 @@ fn run(app: &Command, specs: &[ServiceSpec], matches: &ArgMatches, mode: Mode) - if use_login && token.is_none() { return Err(no_stored_credentials(profile)); } + if let Some(token) = &token { + run_record::set_resolved_token(matches, use_login, token); + } let username: Option = matches .get_one::("username") .cloned() diff --git a/src/output.rs b/src/output.rs index b06a953..a46161b 100644 --- a/src/output.rs +++ b/src/output.rs @@ -1483,6 +1483,8 @@ fn error_payload(e: &CliError) -> Value { /// no `state` field: the streams already separate the two cases. pub fn emit_error(mode: Mode, err: &anyhow::Error) { let cli = err.downcast_ref::(); + let code = cli.map_or(GENERIC_CODE, |e| e.code.as_str()); + crate::run_record::set_error(code, &format!("{err:#}")); if mode.is_json() { let payload = match cli { @@ -1588,6 +1590,7 @@ fn adds_detail(body: &Value) -> bool { } fn write_stdout(line: &str) -> Result<()> { + crate::run_record::add_stdout_bytes(line.len() + 1); let mut out = std::io::stdout().lock(); writeln!(out, "{line}")?; out.flush()?; diff --git a/src/run_history.rs b/src/run_history.rs new file mode 100644 index 0000000..2d358d5 --- /dev/null +++ b/src/run_history.rs @@ -0,0 +1,184 @@ +//! Command history: one line of execution metadata per run in +//! `~/.mapbox/history/.jsonl` (or under `$MAPBOX_CONFIG_DIR`), +//! kept for [`RETENTION_DAYS`] days and at most [`LIMIT_BYTES`], oldest +//! first, and read back by `mapbox history`. +//! +//! On by default, so it keeps only what is safe to keep without anyone +//! having asked: the command path from the command tree (`search forward`, +//! never what was typed after it), how the run ended, how long it took and +//! the request ids support can look up. No argument values, URLs, error +//! messages or account — arguments carry search terms, file paths and ids. +//! +//! `mapbox config set history off` turns it off, `MAPBOX_HISTORY=0` or `=1` +//! for a session over the setting. Turned off, nothing is created on disk. +//! Turned on, the config directory is created if it is missing, so history +//! works the same for someone who only ever set `MAPBOX_ACCESS_TOKEN`. +//! +//! Not recorded: +//! - `--help` and `--version`, which answer a question rather than run a +//! command; +//! - `history` itself, which would push out what it was reading; +//! - a run under `sudo`, whose files would belong to root inside the +//! user's home and stop the user's own runs appending to them — the +//! failure AWS CLI shipped in 2.33.9 (aws/aws-cli#10031); +//! - `completion`, which [`crate::run_record`] already skips. + +use std::path::PathBuf; +use std::time::SystemTime; + +use serde::Serialize; + +use crate::run_record::{Invocation, Record}; +use crate::{auth, config, dated_jsonl, history, telemetry}; + +const DIR: &str = "history"; +const HISTORY_ENV: &str = "MAPBOX_HISTORY"; +pub(crate) const RETENTION_DAYS: u64 = 30; +/// Tens of thousands of runs: a script calling this in a loop must not fill +/// the disk before thirty days are up. +const LIMIT_BYTES: u64 = 10 * 1024 * 1024; +/// The last few are enough to hand to support; a paginated run can make +/// hundreds of requests. +const MAX_REQUEST_IDS: usize = 5; + +#[derive(Serialize)] +#[serde(rename_all = "camelCase")] +struct Line { + id: String, + time: String, + version: &'static str, + #[serde(skip_serializing_if = "Vec::is_empty")] + command: Vec, + #[serde(skip_serializing_if = "Option::is_none")] + invocation: Option<&'static str>, + #[serde(skip_serializing_if = "Option::is_none")] + exit_code: Option, + #[serde(skip_serializing_if = "Option::is_none")] + error_code: Option, + duration_ms: u64, + #[serde(skip_serializing_if = "is_zero")] + request_count: usize, + #[serde(skip_serializing_if = "Vec::is_empty")] + request_ids: Vec, + /// Whether a diagnostic log was written for this run. Kept with the + /// record so that detail dropped later reads as "no longer available", + /// not "never captured". + #[serde(skip_serializing_if = "std::ops::Not::not")] + diagnostics_captured: bool, +} + +fn is_zero(n: &usize) -> bool { + *n == 0 +} + +/// Whether this run gets a history line: history is on and the run is one +/// it records. +pub(crate) fn will_record(record: &Record) -> bool { + enabled() && recorded(record, std::env::var_os("SUDO_USER").is_some()) +} + +/// Appends the run's line. The caller has checked [`will_record`]; +/// `diagnostics` says whether a diagnostic log is written for it too. +pub(crate) fn write(record: &Record, diagnostics: bool, at: SystemTime) { + let Ok(text) = serde_json::to_string(&line(record, diagnostics, at)) else { + return; + }; + if let Some(dir) = dated_jsonl::private_dir(DIR) { + dated_jsonl::append(&dir, &text, at, RETENTION_DAYS); + dated_jsonl::shed(&dir, LIMIT_BYTES); + } +} + +/// Whether this run records history: `MAPBOX_HISTORY` when it is set, the +/// persisted setting otherwise. +pub(crate) fn enabled() -> bool { + telemetry::env_switch(HISTORY_ENV).unwrap_or_else(config::history_enabled) +} + +fn recorded(record: &Record, under_sudo: bool) -> bool { + !under_sudo + && !matches!( + record.invocation, + Some(Invocation::Help | Invocation::Version) + ) + && record.command.first().map(String::as_str) != Some(history::COMMAND) +} + +fn line(record: &Record, diagnostics: bool, at: SystemTime) -> Line { + let ids: Vec = record + .requests + .iter() + .filter_map(|request| request.request_id.clone()) + .collect(); + Line { + id: record.id.clone(), + time: dated_jsonl::timestamp(at), + version: env!("CARGO_PKG_VERSION"), + command: record.command.clone(), + invocation: record.invocation.map(Invocation::as_str), + exit_code: record.exit_code, + error_code: record.error.as_ref().map(|error| error.code.clone()), + duration_ms: record.duration.as_millis() as u64, + request_count: record.requests.len(), + request_ids: ids[ids.len().saturating_sub(MAX_REQUEST_IDS)..].to_vec(), + diagnostics_captured: diagnostics, + } +} + +/// Where history lives, without creating it. +fn dir_path() -> Option { + Some(auth::config_dir_path()?.join(DIR)) +} + +/// Whether history still has a file for `date` (`YYYY-MM-DD`). +pub(crate) fn has_day(date: &str) -> bool { + dir_path().is_some_and(|dir| dir.join(format!("{date}.jsonl")).is_file()) +} + +/// Every run in history, oldest first, skipping any line that doesn't parse. +pub(crate) fn entries() -> Vec { + let Some(dir) = dir_path() else { + return vec![]; + }; + dated_jsonl::read_all(&dir) + .iter() + .filter_map(|line| serde_json::from_str(line).ok()) + .collect() +} + +#[cfg(test)] +mod tests { + use super::*; + + fn record(command: &[&str], invocation: Invocation) -> Record { + let mut record = Record::default(); + record.command = command.iter().map(|c| c.to_string()).collect(); + record.invocation = Some(invocation); + record + } + + #[test] + fn help_version_history_and_sudo_are_not_recorded() { + let run = record(&["styles", "list"], Invocation::Execute); + assert!(recorded(&run, false)); + assert!(!recorded(&run, true), "under sudo"); + assert!(!recorded(&record(&["styles"], Invocation::Help), false)); + assert!(!recorded(&record(&[], Invocation::Version), false)); + assert!(!recorded( + &record(&["history", "list"], Invocation::Execute), + false + )); + } + + #[test] + fn a_line_keeps_the_command_path_and_no_argument() { + let mut run = record(&["search", "forward"], Invocation::Execute); + run.argv = ["search", "forward", "--q", "1600 Pennsylvania Ave"] + .iter() + .map(std::ffi::OsString::from) + .collect(); + let text = serde_json::to_string(&line(&run, false, SystemTime::now())).unwrap(); + assert!(text.contains(r#""command":["search","forward"]"#), "{text}"); + assert!(!text.contains("Pennsylvania"), "{text}"); + } +} diff --git a/src/run_log.rs b/src/run_log.rs new file mode 100644 index 0000000..56fd235 --- /dev/null +++ b/src/run_log.rs @@ -0,0 +1,280 @@ +//! Diagnostic logs: for a run that [`crate::run_history`] recorded, one +//! line of detail in `~/.mapbox/logs/.jsonl` (or under +//! `$MAPBOX_CONFIG_DIR`), linked to the history record by its `id` and +//! shown by `mapbox history show`. +//! +//! History keeps only what is safe without anyone having asked; this keeps +//! what answers "why did that command fail": the command line, each request +//! and the error message. So it is off unless turned on — `mapbox config +//! set log on`, or `MAPBOX_LOG=1` for a session (`=0` turns it off over the +//! setting) — and it requires history: with history off it never runs, +//! rather than writing detail that nothing could lead back to. +//! +//! Kept for [`RETENTION_DAYS`] days and at most [`LIMIT_BYTES`] in total, +//! the oldest dropped first. The history record stays when its detail is +//! dropped, and says it was captured, so `history show` can tell "not +//! captured" from "no longer available". A day of detail goes when that +//! day of history does. +//! +//! It still never records a token. The command line goes through the +//! redaction `--debug` applies to `tilesets-cli`'s arguments, URLs arrive +//! with the access token already redacted by [`crate::http::send`], and +//! every string is then scrubbed of token-shaped words, because an error +//! message can quote a URL that a module other than `executor` built. + +use std::path::PathBuf; +use std::time::SystemTime; + +use serde::Serialize; +use serde_json::Value; + +use crate::run_record::{self, Record}; +use crate::{auth, config, dated_jsonl, run_history, telemetry, tilesets_cli}; + +const DIR: &str = "logs"; +const LOG_ENV: &str = "MAPBOX_LOG"; +const RETENTION_DAYS: u64 = run_history::RETENTION_DAYS; +const LIMIT_BYTES: u64 = 100 * 1024 * 1024; + +/// A `--all` run can page hundreds of times; past this, requests are counted +/// rather than listed. +const MAX_REQUESTS: usize = 100; +/// Long enough for an error message or a URL, short enough that an inline +/// `--data` body does not make one line of the log most of the file. +const MAX_TEXT: usize = 2000; +const REDACTED: &str = ""; + +#[derive(Serialize)] +#[serde(rename_all = "camelCase")] +/// Only what the history record lacks, plus the `id` and `time` that find +/// that record. +struct Line { + id: String, + time: String, + argv: Vec, + #[serde(skip_serializing_if = "Option::is_none")] + auth: Option, + #[serde(skip_serializing_if = "Vec::is_empty")] + requests: Vec, + #[serde(skip_serializing_if = "is_zero")] + requests_not_listed: usize, + #[serde(skip_serializing_if = "std::ops::Not::not")] + more_pages: bool, + stdout_bytes: u64, + #[serde(skip_serializing_if = "Option::is_none")] + auth_step: Option<&'static str>, + #[serde(skip_serializing_if = "Option::is_none")] + update_notice: Option, + #[serde(skip_serializing_if = "Option::is_none")] + error: Option, +} + +#[derive(Serialize)] +struct Auth { + source: &'static str, + #[serde(rename = "type")] + kind: &'static str, + #[serde(skip_serializing_if = "Option::is_none")] + account: Option, +} + +#[derive(Serialize)] +#[serde(rename_all = "camelCase")] +struct Request { + method: String, + url: String, + #[serde(skip_serializing_if = "Option::is_none")] + status: Option, + #[serde(skip_serializing_if = "Option::is_none")] + request_id: Option, + duration_ms: u64, + #[serde(skip_serializing_if = "Option::is_none")] + error: Option, +} + +#[derive(Serialize)] +struct Failure { + code: String, + message: String, +} + +fn is_zero(n: &usize) -> bool { + *n == 0 +} + +/// Appends the run's line. The caller has checked [`enabled`] and that +/// history recorded the run at `at`. +pub(crate) fn write(record: &Record, at: SystemTime) { + let Ok(text) = serde_json::to_string(&line(record, at)) else { + return; + }; + if let Some(dir) = dated_jsonl::private_dir(DIR) { + dated_jsonl::append(&dir, &text, at, RETENTION_DAYS); + dated_jsonl::shed(&dir, LIMIT_BYTES); + } +} + +/// Whether this run writes diagnostics: never with history off, otherwise +/// `MAPBOX_LOG` when it is set and the persisted setting when it is not. +pub(crate) fn enabled() -> bool { + run_history::enabled() && telemetry::env_switch(LOG_ENV).unwrap_or_else(config::log_enabled) +} + +/// Where the logs live, without creating them. +fn dir_path() -> Option { + Some(auth::config_dir_path()?.join(DIR)) +} + +/// Deletes each day of detail whose day of history has expired or gone. +/// Run on every run that finishes, logging on or off, so detail never +/// outlives the record it belongs to. Creates nothing. +pub(crate) fn expire_with_history() { + let Some(dir) = dir_path().filter(|dir| dir.is_dir()) else { + return; + }; + let oldest = dated_jsonl::oldest_kept(RETENTION_DAYS); + dated_jsonl::prune_where(&dir, |date| { + date >= oldest.as_str() && run_history::has_day(date) + }); +} + +/// The detail logged for the run `id` that history recorded at `time`. +/// Only that day's file is read: both lines carry the same time. +pub(crate) fn find(id: &str, time: &str) -> Option { + let dir = dir_path()?; + dated_jsonl::read_day(&dir, time.get(..10)?) + .into_iter() + .filter_map(|line| serde_json::from_str::(&line).ok()) + .find(|entry| entry.get("id").and_then(Value::as_str) == Some(id)) +} + +fn line(record: &Record, at: SystemTime) -> Line { + Line { + id: record.id.clone(), + time: dated_jsonl::timestamp(at), + argv: tilesets_cli::redacted_argv(&record.argv) + .iter() + .map(|arg| clean(arg)) + .collect(), + auth: record.token.as_ref().map(|token| Auth { + source: token.source.as_str(), + kind: token.kind, + account: token.account.as_deref().map(clean), + }), + requests: record + .requests + .iter() + .take(MAX_REQUESTS) + .map(request) + .collect(), + requests_not_listed: record.requests.len().saturating_sub(MAX_REQUESTS), + more_pages: record.more_pages, + stdout_bytes: record.stdout_bytes, + auth_step: record.auth_step, + update_notice: record.update_notice.as_deref().map(clean), + error: record.error.as_ref().map(|failure| Failure { + code: clean(&failure.code), + message: clean(&failure.message), + }), + } +} + +fn request(request: &run_record::Request) -> Request { + Request { + method: request.method.clone(), + url: clean(&request.url), + status: request.status, + request_id: request.request_id.as_deref().map(clean), + duration_ms: request.elapsed.as_millis() as u64, + error: request.error.as_deref().map(clean), + } +} + +/// Scrubbed of token-shaped words, then clipped to [`MAX_TEXT`]. +fn clean(text: &str) -> String { + let scrubbed = scrub_tokens(text); + match scrubbed.char_indices().nth(MAX_TEXT) { + Some((end, _)) => format!("{}…", &scrubbed[..end]), + None => scrubbed, + } +} + +/// `text` with every word that looks like a Mapbox token replaced. A word +/// here is a run of the characters a token is made of, so a token inside a +/// URL, after `=`, or in quotes is still found. The token may start inside +/// the word, as after a percent-encoded `=` (`%3Dpk.`) or in a short-flag +/// cluster (`-ytpk.`); the word is redacted from there. +fn scrub_tokens(text: &str) -> String { + let is_token_char = |c: char| c.is_ascii_alphanumeric() || matches!(c, '.' | '_' | '-'); + let mut out = String::with_capacity(text.len()); + let mut rest = text; + while let Some(start) = rest.find(is_token_char) { + out.push_str(&rest[..start]); + let word_len = rest[start..] + .find(|c: char| !is_token_char(c)) + .unwrap_or(rest.len() - start); + let word = &rest[start..start + word_len]; + // Every token character is ASCII, so every index is a boundary. + match (0..word.len()).find(|&i| tilesets_cli::looks_like_a_token(&word[i..])) { + Some(at) => { + out.push_str(&word[..at]); + out.push_str(REDACTED); + } + None => out.push_str(word), + } + rest = &rest[start + word_len..]; + } + out.push_str(rest); + out +} + +#[cfg(test)] +mod tests { + use super::*; + + const TOKEN: &str = "pk.eyJ1IjoiZXhhbXBsZS11c2VyIiwiYSI6IngifQ.SIGNATURE-NOT-FOR-LOGS"; + + #[test] + fn tokens_are_scrubbed_wherever_they_sit() { + for (text, expected) in [ + ( + format!("GET https://api.mapbox.com/x?access_token={TOKEN}&a=1"), + "GET https://api.mapbox.com/x?access_token=&a=1".to_string(), + ), + ( + format!("token \"{TOKEN}\"."), + "token \"\".".to_string(), + ), + (TOKEN.to_string(), REDACTED.to_string()), + ( + format!("url-https%3A%2F%2Fh%2Fm.png%3Faccess_token%3D{TOKEN}"), + "url-https%3A%2F%2Fh%2Fm.png%3Faccess_token%3D".to_string(), + ), + (format!("-yt{TOKEN}"), "-yt".to_string()), + ] { + assert_eq!(scrub_tokens(&text), expected); + } + } + + #[test] + fn ordinary_text_is_left_alone() { + for text in [ + "", + "styles get my-style --username pk", + "pk.short", + "No such style: ckabc123.", + "héllo wörld", + ] { + assert_eq!(scrub_tokens(text), text); + } + } + + #[test] + fn long_text_is_clipped_on_a_character_boundary() { + let text = "é".repeat(MAX_TEXT + 10); + let clipped = clean(&text); + assert_eq!(clipped.chars().count(), MAX_TEXT + 1); + assert!(clipped.ends_with('…')); + assert_eq!(clean("short"), "short"); + } +} diff --git a/src/run_record.rs b/src/run_record.rs new file mode 100644 index 0000000..fbaa914 --- /dev/null +++ b/src/run_record.rs @@ -0,0 +1,566 @@ +//! What a run did, collected in one place for everything that reports on it. +//! +//! Modules report facts as they happen and `main` calls [`finish`] once on +//! the way out, so a consumer is built from the finished [`Record`] rather +//! than from call sites of its own. `set_*` overwrites, `add_*` accumulates. +//! +//! The record holds raw facts — the command line, URLs, error messages — and +//! never leaves this process. A consumer that sends anything off the machine +//! chooses field by field what it takes. Best-effort: nothing here can change +//! a command's output or exit code. + +// Some facts are read only by consumers not in this tree yet. +#![allow(dead_code)] + +use std::ffi::OsString; +use std::sync::{Mutex, OnceLock}; +use std::time::{Duration, Instant, SystemTime}; + +use clap::parser::ValueSource; +use clap::{ArgMatches, Command}; + +use crate::spec::ServiceSpec; +use crate::{ + auth, completion, confirm, executor, http, output, run_history, run_log, tilesets_cli, +}; + +const TILESETS: &str = tilesets_cli::COMMAND; + +/// How the command line was answered. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub(crate) enum Invocation { + Execute, + Schema, + Help, + Version, +} + +impl Invocation { + pub(crate) fn as_str(self) -> &'static str { + match self { + Invocation::Execute => "execute", + Invocation::Schema => "schema", + Invocation::Help => "help", + Invocation::Version => "version", + } + } +} + +/// One argument given on the command line or through its environment +/// variable, as clap parsed it. +#[derive(Debug, Clone, PartialEq)] +pub(crate) struct Arg { + /// clap's id, which is what option names like [`output::ARG`] are. + pub id: String, + /// The long name, or the id when there is none. + pub name: String, + pub values: Vec, + pub takes_values: bool, + /// Restricted to a fixed set of values. + pub enumerated: bool, + /// Typed as a number by the operation's spec. + pub numeric: bool, + /// Defined on the root command rather than the one that ran. + pub global: bool, +} + +/// The global options a parsed run carries. +#[derive(Debug, Clone, PartialEq)] +pub(crate) struct Options { + /// `auto`, `text` or `json`, as asked. + pub output: &'static str, + /// `flag`, `env` or `default`. + pub output_source: &'static str, + pub dry_run: bool, + pub debug: bool, + pub yes: bool, + pub profile: Option, + /// Only when `--timeout` was typed. + pub timeout: Option, +} + +#[derive(Debug, Clone, PartialEq)] +pub(crate) struct Token { + pub source: auth::TokenSource, + /// `pk`, `sk`, `tk` or `other`. + pub kind: &'static str, + pub account: Option, +} + +#[derive(Debug, Clone, PartialEq)] +pub(crate) struct Request { + pub method: String, + /// With the access token redacted. + pub url: String, + /// `None` when no response came back. + pub status: Option, + /// Only for a Mapbox host. + pub request_id: Option, + pub request_body_bytes: Option, + pub response_bytes: Option, + pub elapsed: Duration, + /// Why no response came back. + pub error: Option, +} + +#[derive(Debug, Clone, PartialEq)] +pub(crate) struct Failure { + pub code: String, + pub message: String, +} + +/// Everything the run reported. +#[derive(Debug, Default)] +pub(crate) struct Record { + /// A random id for this run, set at [`start`]. + pub id: String, + /// The command line, without the binary's own path. Raw: tokens are + /// still in it. + pub argv: Vec, + /// Command names from the command tree, never from argv. + pub command: Vec, + pub invocation: Option, + /// The first word forwarded to `tilesets`, as typed. + pub tilesets_word: Option, + /// clap's name for why it refused the command line. + pub usage_error: Option, + pub args: Vec, + pub options: Option, + pub token: Option, + pub requests: Vec, + pub more_pages: bool, + pub error: Option, + pub stdout_bytes: u64, + pub auth_step: Option<&'static str>, + pub update_notice: Option, + pub duration: Duration, + /// `None` for a `tilesets-cli` run that `exec`s, which never learns it. + pub exit_code: Option, + finished: bool, +} + +static RECORD: Mutex = Mutex::new(Record { + id: String::new(), + argv: Vec::new(), + command: Vec::new(), + invocation: None, + tilesets_word: None, + usage_error: None, + args: Vec::new(), + options: None, + token: None, + requests: Vec::new(), + more_pages: false, + error: None, + stdout_bytes: 0, + auth_step: None, + update_notice: None, + duration: Duration::ZERO, + exit_code: None, + finished: false, +}); +static STARTED: OnceLock = OnceLock::new(); + +/// A poisoned lock is a panic somewhere else; recording is not worth a +/// second one, so it is skipped. +fn with_record(f: impl FnOnce(&mut Record)) { + if let Ok(mut record) = RECORD.lock() { + f(&mut record); + } +} + +/// Marks the start of the run and keeps its command line. Installs the +/// panic hook that finishes the run as `panic`, exit code 101. +pub fn start(argv: &[OsString]) { + STARTED.get_or_init(Instant::now); + let argv = argv.get(1..).unwrap_or_default().to_vec(); + let id = uuid_v4(rand::random()); + with_record(|record| { + record.id = id; + record.argv = argv; + }); + + let previous = std::panic::take_hook(); + std::panic::set_hook(Box::new(move |info| { + previous(info); + // `try_lock`: the panic may have happened while this thread held + // the lock, and waiting for it would hang instead of exiting. + if let Ok(mut record) = RECORD.try_lock() { + record.error = Some(Failure { + code: "panic".to_string(), + message: info.to_string(), + }); + finish_locked(&mut record, Some(101)); + } + })); +} + +/// The command line clap parsed, for `invocation` `Execute` or `Schema`. +pub fn set_parsed( + app: &Command, + specs: &[ServiceSpec], + matches: &ArgMatches, + invocation: Invocation, +) { + let (path, leaf_command, leaf_matches) = leaf(app, matches); + // `completion` runs at every shell startup and is promised to touch + // nothing on disk (`it_needs_no_token_and_touches_no_credentials`). + if path.first().map(String::as_str) == Some(completion::COMMAND) { + with_record(|record| record.finished = true); + return; + } + let tilesets_word = (path.first().map(String::as_str) == Some(TILESETS)) + .then(|| { + matches + .subcommand_matches(TILESETS) + .map(tilesets_cli::forwarded_args) + .and_then(|args| { + args.iter() + .map(|arg| arg.to_string_lossy().into_owned()) + .find(|arg| !arg.starts_with('-')) + }) + }) + .flatten(); + let mut args = vec![]; + if path.first().map(String::as_str) != Some(TILESETS) { + let numeric = numeric_args(specs, &path); + args.extend(given_args(leaf_command, leaf_matches, &numeric, false)); + args.extend(given_args(app, matches, &[], true)); + } + let options = options(matches, leaf_matches); + with_record(|record| { + record.command = path; + record.invocation = Some(invocation); + record.tilesets_word = tilesets_word; + record.args = args; + record.options = Some(options); + }); +} + +/// A command line clap refused, or answered with help or the version. +/// Command names are recovered by walking the tree with argv's words, so +/// only names the tree already has can come out. +pub fn set_unparsed(app: &Command, argv: &[OsString], kind: clap::error::ErrorKind) { + use clap::error::ErrorKind; + let path = command_from_argv(app, argv); + with_record(|record| { + record.command = path; + match kind { + ErrorKind::DisplayHelp | ErrorKind::DisplayHelpOnMissingArgumentOrSubcommand => { + record.invocation = Some(Invocation::Help); + } + ErrorKind::DisplayVersion => record.invocation = Some(Invocation::Version), + other => { + record.invocation = Some(Invocation::Execute); + record.usage_error = Some(format!("{other:?}")); + } + } + }); +} + +/// The token a command resolved. Read for its prefix and its `u` claim; +/// the token itself is not kept. +pub fn set_token(source: auth::TokenSource, token: &str) { + let token = token_fact(source, token); + with_record(|record| record.token = Some(token)); +} + +fn token_fact(source: auth::TokenSource, token: &str) -> Token { + let kind = match token.split('.').next() { + Some("pk") => "pk", + Some("sk") => "sk", + Some("tk") => "tk", + _ => "other", + }; + Token { + source, + kind, + account: auth::token_account(token), + } +} + +/// [`set_token`] for the service arms' resolution: a typed `--token`, +/// then the environment unless `--use-login`, then the stored login. +pub fn set_resolved_token(matches: &ArgMatches, use_login: bool, token: &str) { + let source = if auth::typed_token(matches).is_some() { + auth::TokenSource::Flag + } else if !use_login && matches.get_one::("token").is_some() { + auth::TokenSource::Environment + } else { + auth::TokenSource::Login + }; + set_token(source, token); +} + +/// The error the run ended with, as it was reported to the user. +pub fn set_error(code: &str, message: &str) { + let failure = Failure { + code: code.to_string(), + message: message.to_string(), + }; + with_record(|record| record.error = Some(failure)); +} + +/// How far `auth login`, `logout` or `refresh` got. +pub fn set_auth_step(step: &'static str) { + with_record(|record| record.auth_step = Some(step)); +} + +/// The newer version the update notice named. +pub fn set_update_notice(version: &str) { + with_record(|record| record.update_notice = Some(version.to_string())); +} + +pub fn add_stdout_bytes(bytes: usize) { + with_record(|record| record.stdout_bytes = record.stdout_bytes.saturating_add(bytes as u64)); +} + +/// A paginated result stopped with pages left. +pub fn set_more_pages() { + with_record(|record| record.more_pages = true); +} + +/// One request, from [`http::send`]. +pub fn add_request(request: Request) { + with_record(|record| record.requests.push(request)); +} + +/// Hands the record to each consumer. Once per run; later calls do nothing. +pub fn finish(exit_code: Option) { + if let Ok(mut record) = RECORD.lock() { + finish_locked(&mut record, exit_code); + } +} + +fn finish_locked(record: &mut Record, exit_code: Option) { + if record.finished { + return; + } + record.finished = true; + record.duration = STARTED.get().map_or(Duration::ZERO, Instant::elapsed); + record.exit_code = exit_code; + // Diagnostics only for a run history records: detail with no record + // would be unreachable, and the record says whether detail exists. + let history = run_history::will_record(record); + let diagnostics = history && run_log::enabled(); + // One time for both lines, so they land in the same day's file even + // across midnight. + let at = SystemTime::now(); + if history { + run_history::write(record, diagnostics, at); + } + if diagnostics { + run_log::write(record, at); + } + run_log::expire_with_history(); +} + +fn uuid_v4(mut bytes: [u8; 16]) -> String { + bytes[6] = (bytes[6] & 0x0f) | 0x40; + bytes[8] = (bytes[8] & 0x3f) | 0x80; + let hex: String = bytes.iter().map(|b| format!("{b:02x}")).collect(); + format!( + "{}-{}-{}-{}-{}", + &hex[0..8], + &hex[8..12], + &hex[12..16], + &hex[16..20], + &hex[20..32] + ) +} + +/// The command path, the leaf `Command` and the leaf matches. +fn leaf<'a>( + app: &'a Command, + matches: &'a ArgMatches, +) -> (Vec, &'a Command, &'a ArgMatches) { + let mut path = vec![]; + let mut command = app; + let mut current = matches; + while let Some((name, sub)) = current.subcommand() { + path.push(name.to_string()); + if name == TILESETS && path.len() == 1 { + // Its forwarded words come back as subcommands of their own. + return (path, command.find_subcommand(name).unwrap_or(command), sub); + } + match command.find_subcommand(name) { + Some(found) => command = found, + None => break, + } + current = sub; + } + (path, command, current) +} + +fn command_from_argv(app: &Command, argv: &[OsString]) -> Vec { + tree_path( + app, + argv.iter() + .skip(1) + .map(|word| word.to_string_lossy().into_owned()), + ) +} + +/// Subcommand names from `words`, in order, for as long as each word names +/// a subcommand of the one before. Flags and their values are skipped; the +/// first word that is neither ends the walk. +fn tree_path(app: &Command, words: impl IntoIterator) -> Vec { + let mut path = vec![]; + let mut command = app; + for word in words { + if word.starts_with('-') { + continue; + } + match command.find_subcommand(&word) { + Some(found) => { + path.push(found.get_name().to_string()); + if found.get_name() == TILESETS { + break; + } + command = found; + } + None if path.is_empty() => continue, + None => break, + } + } + path +} + +fn options(matches: &ArgMatches, leaf_matches: &ArgMatches) -> Options { + let (output, output_source) = output_requested(matches); + let timeout = (matches.value_source(http::TIMEOUT_ARG) == Some(ValueSource::CommandLine)) + .then(|| matches.get_one::(http::TIMEOUT_ARG).copied()) + .flatten(); + Options { + output, + output_source, + dry_run: executor::wants_dry_run(leaf_matches), + debug: matches.get_flag("debug"), + yes: matches.get_flag(confirm::ARG), + profile: matches.get_one::("profile").cloned(), + timeout, + } +} + +/// `--output` as asked, in `Mode::from_matches`'s precedence, without its +/// warning — that has already been printed once by the time this runs. +fn output_requested(matches: &ArgMatches) -> (&'static str, &'static str) { + let known = |value: &str| { + [output::AUTO, output::TEXT, output::JSON] + .into_iter() + .find(|known| *known == value) + }; + if matches.value_source(output::ARG) == Some(ValueSource::CommandLine) { + let value = matches.get_one::(output::ARG).map(String::as_str); + return (value.and_then(known).unwrap_or(output::AUTO), "flag"); + } + match std::env::var(output::ENV) + .ok() + .map(|v| v.trim().to_string()) + { + Some(value) if !value.is_empty() => (known(&value).unwrap_or(output::AUTO), "env"), + _ => (output::AUTO, "default"), + } +} + +/// The spec parameters of the operation at `path` that are typed as numbers. +/// A free string that happens to be digits (a postcode) is not one. +fn numeric_args(specs: &[ServiceSpec], path: &[String]) -> Vec { + let Some((service, rest)) = path.split_first() else { + return vec![]; + }; + specs + .iter() + .filter(|spec| &spec.name == service) + .flat_map(|spec| &spec.operations) + .filter(|op| op.command_path == rest) + .flat_map(|op| op.path_params.iter().chain(&op.query_params)) + .filter(|param| param.numeric.is_some()) + .map(|param| param.arg_name.clone()) + .collect() +} + +/// `command`'s arguments that were given on the command line or through +/// their environment variable. A leaf `Command` does not list the globals it +/// inherits, so those are read separately from the root, as `global`. +/// +/// `--token` is left out: the record keeps what [`set_token`] reads from a +/// token, never the token. +fn given_args( + command: &Command, + matches: &ArgMatches, + numeric: &[String], + global: bool, +) -> Vec { + command + .get_arguments() + .filter(|arg| arg.get_id() != "token") + .filter_map(|arg| { + let id = arg.get_id().as_str(); + match matches.value_source(id) { + Some(ValueSource::CommandLine) | Some(ValueSource::EnvVariable) => {} + _ => return None, + } + let values = matches + .get_raw(id)? + .map(|v| v.to_string_lossy().into_owned()) + .collect(); + Some(Arg { + id: id.to_string(), + name: arg.get_long().unwrap_or(id).to_string(), + values, + takes_values: arg.get_action().takes_values(), + enumerated: !arg.get_possible_values().is_empty(), + numeric: numeric.iter().any(|n| n == id), + global, + }) + }) + .collect() +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn command_names_come_from_the_tree_not_from_argv() { + let app = Command::new("mapbox").subcommand( + Command::new("styles") + .subcommand(Command::new("draft").subcommand(Command::new("get"))), + ); + let argv = |words: &[&str]| words.iter().map(OsString::from).collect::>(); + assert_eq!( + command_from_argv( + &app, + &argv(&["mapbox", "-o", "json", "styles", "draft", "get", "my-style"]) + ), + ["styles", "draft", "get"] + ); + assert_eq!( + command_from_argv(&app, &argv(&["mapbox", "styles", "typo", "draft"])), + ["styles"] + ); + assert!(command_from_argv(&app, &argv(&["mapbox", "/secret/path"])).is_empty()); + } + + #[test] + fn a_token_is_read_for_its_prefix_and_account_only() { + let payload = base64::Engine::encode( + &base64::engine::general_purpose::URL_SAFE_NO_PAD, + br#"{"u":"example-user","a":"x"}"#, + ); + let token = format!("sk.{payload}.signature"); + let fact = token_fact(auth::TokenSource::Login, &token); + assert_eq!( + fact, + Token { + source: auth::TokenSource::Login, + kind: "sk", + account: Some("example-user".to_string()) + } + ); + assert!(!format!("{fact:?}").contains("signature"), "{fact:?}"); + + assert_eq!(token_fact(auth::TokenSource::Flag, "garbage").kind, "other"); + } +} diff --git a/src/schema.rs b/src/schema.rs index 27c5e57..31a3e8a 100644 --- a/src/schema.rs +++ b/src/schema.rs @@ -379,6 +379,14 @@ fn commands(app: &Command, specs: &[ServiceSpec], path: &[String]) -> Vec bool { - match std::env::var_os(MAPBOX_CLI_NO_TELEMETRY_ENV) { - None => true, - Some(value) => { - let value = value.to_string_lossy().trim().to_ascii_lowercase(); - value.is_empty() || NOT_AN_OPT_OUT.contains(&value.as_str()) - } + env_switch(MAPBOX_CLI_NO_TELEMETRY_ENV) != Some(true) +} + +/// A boolean environment variable by this CLI's convention: `None` when +/// unset or empty, `Some(false)` for one of [`NOT_AN_OPT_OUT`], `Some(true)` +/// for anything else. +pub(crate) fn env_switch(name: &str) -> Option { + let value = std::env::var_os(name)?; + let value = value.to_string_lossy().trim().to_ascii_lowercase(); + if value.is_empty() { + None + } else { + Some(!NOT_AN_OPT_OUT.contains(&value.as_str())) } } diff --git a/src/tilesets_cli.rs b/src/tilesets_cli.rs index d4e9058..dfebf28 100644 --- a/src/tilesets_cli.rs +++ b/src/tilesets_cli.rs @@ -379,7 +379,7 @@ const REDACTED: &str = ""; /// starts with one — and the length keeps a user literally named `pk` from /// having their account redacted out of a debug line. Real tokens run to /// eighty characters and more. -fn looks_like_a_token(text: &str) -> bool { +pub(crate) fn looks_like_a_token(text: &str) -> bool { const PREFIXES: [&str; 3] = ["pk.", "sk.", "tk."]; text.len() >= 40 && PREFIXES.iter().any(|prefix| text.starts_with(prefix)) } @@ -397,7 +397,7 @@ fn looks_like_a_token(text: &str) -> bool { /// Both halves are needed. The flag forms catch a value the child was told to /// use; the shape catches one written anywhere else, including after a `--` /// where nothing is a flag any more. -fn redacted_argv(args: &[OsString]) -> Vec { +pub(crate) fn redacted_argv(args: &[OsString]) -> Vec { let mut rendered: Vec = Vec::with_capacity(args.len()); let mut value_is_a_token = false; @@ -494,15 +494,38 @@ pub fn run(args: &[OsString], token: Option, debug: bool) -> Result< #[cfg(unix)] fn handoff(mut cmd: std::process::Command) -> std::io::Error { use std::os::unix::process::CommandExt; + // Now or never: after `exec` this process is the child, and `main` never + // gets to finish the run, so it goes without an exit code. Only when + // the binary resolves — a missing `tilesets` is a failure `main` + // reports, and the run should carry it. + if resolves(std::path::Path::new(cmd.get_program())) { + crate::run_record::finish(None); + } cmd.exec() } +/// Whether `exec` would find `program`: as given if it has a directory in +/// it, otherwise on `PATH`. +#[cfg(unix)] +fn resolves(program: &std::path::Path) -> bool { + if program.components().count() > 1 { + return program.is_file(); + } + std::env::var_os("PATH") + .is_some_and(|path| std::env::split_paths(&path).any(|dir| dir.join(program).is_file())) +} + #[cfg(not(unix))] fn handoff(mut cmd: std::process::Command) -> std::io::Error { match cmd.status() { // 130 is the conventional "killed by SIGINT" code; on Windows a // `None` code means the child was terminated rather than exiting. - Ok(status) => std::process::exit(status.code().unwrap_or(130)), + Ok(status) => { + let code = status.code().unwrap_or(130); + // `exit` skips `main`'s way out, where the run is finished. + crate::run_record::finish(u32::try_from(code).ok()); + std::process::exit(code) + } Err(err) => err, } } diff --git a/src/update_check.rs b/src/update_check.rs index a515d4f..649c92e 100644 --- a/src/update_check.rs +++ b/src/update_check.rs @@ -392,12 +392,7 @@ pub fn run_refresh_child() -> ExitCode { /// The channel manifest documents the shape; `version` is the only field /// this reads, and it carries no leading `v`. fn fetch_latest(url: &str) -> Option { - let response = http::client() - .ok()? - .get(url) - .timeout(FETCH_TIMEOUT) - .send() - .ok()?; + let response = http::send(http::client().ok()?.get(url).timeout(FETCH_TIMEOUT)).ok()?; if !response.status().is_success() { return None; } @@ -432,6 +427,7 @@ pub fn notify() { // it had, rather than racing a child that may finish first. if let Some(latest) = should_notify(cache.as_ref(), CURRENT, now) { output::progress(¬ice(latest, CURRENT, cfg!(windows))); + crate::run_record::set_update_notice(latest); let mut updated = cache.clone().unwrap_or_default(); updated.notified_at = now; write_cache(&updated); diff --git a/tests/auth_profiles.rs b/tests/auth_profiles.rs index 2b970dc..fbc70eb 100644 --- a/tests/auth_profiles.rs +++ b/tests/auth_profiles.rs @@ -49,6 +49,10 @@ fn command(home: &Path) -> Command { .env_remove("MapboxAccessToken") .env_remove("MAPBOX_USERNAME") .env_remove("MAPBOX_OUTPUT") + // Off: these tests hold a run to leaving nothing on disk; what + // history leaves is `tests/history.rs`'s to check. + .env("MAPBOX_HISTORY", "0") + .env_remove("MAPBOX_LOG") .env("HOME", home) .env("XDG_CONFIG_HOME", home.join(".config")) .env("MAPBOX_CONFIG_DIR", config_dir(home)); diff --git a/tests/completion.rs b/tests/completion.rs index 2c5dc1f..2e9fb56 100644 --- a/tests/completion.rs +++ b/tests/completion.rs @@ -45,6 +45,10 @@ fn command() -> Command { .env_remove("MapboxAccessToken") .env_remove("MAPBOX_USERNAME") .env_remove("MAPBOX_OUTPUT") + // Off: these tests hold a run to leaving nothing on disk; what + // history leaves is `tests/history.rs`'s to check. + .env("MAPBOX_HISTORY", "0") + .env_remove("MAPBOX_LOG") .env("HOME", &home) .env("XDG_CONFIG_HOME", home.join(".config")) .env("MAPBOX_CONFIG_DIR", home.join(".mapbox")); diff --git a/tests/config.rs b/tests/config.rs index c6e2558..471da92 100644 --- a/tests/config.rs +++ b/tests/config.rs @@ -127,13 +127,16 @@ fn an_unknown_key_or_value_is_a_usage_error_not_a_panic() { fn list_reports_every_setting_including_an_unset_one() { let home = scratch("list"); - // Nothing set yet: list still names the one known key, at its default. + // Nothing set yet: list still names every known key, at its default. let empty = command(&home) .args(["-o", "json", "config", "list"]) .output() .expect("run mapbox config list"); assert!(empty.status.success()); - assert_eq!(stdout(&empty), r#"[{"key":"update-check","value":true}]"#); + assert_eq!( + stdout(&empty), + r#"[{"key":"update-check","value":true},{"key":"history","value":true},{"key":"log","value":false}]"# + ); let set = command(&home) .args(["config", "set", "update-check", "off"]) @@ -146,14 +149,17 @@ fn list_reports_every_setting_including_an_unset_one() { .output() .expect("run mapbox config list"); assert!(after.status.success()); - assert_eq!(stdout(&after), r#"[{"key":"update-check","value":false}]"#); + assert_eq!( + stdout(&after), + r#"[{"key":"update-check","value":false},{"key":"history","value":true},{"key":"log","value":false}]"# + ); let text = command(&home) .args(["-o", "text", "config", "list"]) .output() .expect("run mapbox config list"); assert!(text.status.success()); - assert_eq!(stdout(&text), "update-check\toff"); + assert_eq!(stdout(&text), "update-check\toff\nhistory\ton\nlog\toff"); } #[test] diff --git a/tests/diagnostic_log.rs b/tests/diagnostic_log.rs new file mode 100644 index 0000000..16d54f4 --- /dev/null +++ b/tests/diagnostic_log.rs @@ -0,0 +1,296 @@ +//! End-to-end tests for diagnostic logs and what `mapbox history show` says +//! about them. +//! +//! The unit tests in `src/run_log.rs` and `src/dated_jsonl.rs` cover the +//! pure parts — scrubbing a token out of a string, which lines a trim or a +//! shed keeps. What they cannot show is the contract across two stores: a +//! log only for a run history recorded, never with history off, dropped +//! without taking its history record along, and gone when its record is. +//! +//! Nothing here reaches the network. The one request a test makes goes to a +//! proxy on a loopback port nobody is listening on, so it fails at once and +//! is still a request `http::send` saw. + +use std::net::TcpListener; +use std::path::{Path, PathBuf}; +use std::process::{Command, Output}; + +use serde_json::Value; + +/// A token-shaped fake. The signature is what must never reach the disk. +const TOKEN: &str = "pk.eyJ1IjoiZXhhbXBsZS11c2VyIiwiYSI6IngifQ.SIGNATURE-NOT-FOR-LOGS"; + +fn scratch(name: &str) -> PathBuf { + let home = PathBuf::from(env!("CARGO_TARGET_TMPDIR")).join(format!("diagnostic-{name}")); + let _ = std::fs::remove_dir_all(&home); + std::fs::create_dir_all(&home).expect("create the scratch home"); + home +} + +fn config_dir(home: &Path) -> PathBuf { + home.join(".mapbox") +} + +fn log_dir(home: &Path) -> PathBuf { + config_dir(home).join("logs") +} + +fn history_dir(home: &Path) -> PathBuf { + config_dir(home).join("history") +} + +fn command(home: &Path) -> Command { + let mut cmd = Command::new(env!("CARGO_BIN_EXE_mapbox")); + cmd.env_remove("MAPBOX_ACCESS_TOKEN") + .env_remove("MapboxAccessToken") + .env_remove("MAPBOX_USERNAME") + .env_remove("MAPBOX_OUTPUT") + .env_remove("MAPBOX_HISTORY") + .env_remove("MAPBOX_LOG") + .env_remove("SUDO_USER") + .env_remove("NO_PROXY") + .env_remove("no_proxy") + .env("MAPBOX_NO_UPDATE_CHECK", "1") + .env("HOME", home) + .env("XDG_CONFIG_HOME", home.join(".config")) + .env("MAPBOX_CONFIG_DIR", config_dir(home)); + cmd +} + +fn run(home: &Path, args: &[&str]) -> Output { + command(home).args(args).output().expect("run mapbox") +} + +fn logged(home: &Path, args: &[&str]) -> Output { + command(home) + .env("MAPBOX_LOG", "1") + .args(args) + .output() + .expect("run mapbox") +} + +/// Every file's text under `dir`, concatenated in date order. +fn raw(dir: &Path) -> String { + let Ok(entries) = std::fs::read_dir(dir) else { + return String::new(); + }; + let mut files: Vec = entries.map(|e| e.expect("an entry").path()).collect(); + files.sort(); + files + .iter() + .map(|f| std::fs::read_to_string(f).unwrap_or_default()) + .collect() +} + +/// A request that fails before it leaves the machine: through a proxy on a +/// loopback port with nothing listening. +fn a_refused_request(home: &Path) -> Output { + let port = { + let listener = TcpListener::bind("127.0.0.1:0").expect("a loopback port"); + listener.local_addr().expect("the bound address").port() + }; + command(home) + .env("MAPBOX_LOG", "1") + .env("HTTPS_PROXY", format!("http://127.0.0.1:{port}")) + .args(["styles", "list", "--username", "example", "--token", TOKEN]) + .output() + .expect("run mapbox") +} + +fn show(home: &Path, id: Option<&str>) -> Value { + let mut args = vec!["-o", "json", "history", "show"]; + args.extend(id); + let out = run(home, &args); + assert!( + out.status.success(), + "{}", + String::from_utf8_lossy(&out.stderr) + ); + serde_json::from_slice(&out.stdout).expect("a JSON run") +} + +/// Today's UTC date, as the files the binary just wrote are named. +fn today(home: &Path) -> String { + std::fs::read_dir(history_dir(home)) + .expect("the history directory") + .map(|e| { + e.expect("an entry") + .file_name() + .to_string_lossy() + .into_owned() + }) + .filter_map(|name| name.strip_suffix(".jsonl").map(str::to_string)) + .max() + .expect("today's history file") +} + +/// The day before `date`, without a calendar crate. +fn day_before(date: &str) -> String { + let (mut y, mut m, mut d): (u32, u32, u32) = ( + date[0..4].parse().unwrap(), + date[5..7].parse().unwrap(), + date[8..10].parse().unwrap(), + ); + if d > 1 { + d -= 1; + } else { + if m > 1 { + m -= 1; + } else { + m = 12; + y -= 1; + } + let leap = y % 4 == 0 && (y % 100 != 0 || y % 400 == 0); + d = match m { + 2 if leap => 29, + 2 => 28, + 4 | 6 | 9 | 11 => 30, + _ => 31, + }; + } + format!("{y:04}-{m:02}-{d:02}") +} + +#[test] +fn nothing_is_logged_unless_logging_was_turned_on() { + let home = scratch("off"); + run(&home, &["styles", "lsit"]); + assert!(!log_dir(&home).exists(), "logging off created logs/"); + assert_eq!( + show(&home, None)["diagnostics"], + serde_json::json!({ "status": "not_captured" }) + ); +} + +#[test] +fn a_logged_run_is_shown_with_its_record_and_keeps_no_token() { + let home = scratch("captured"); + assert!(!a_refused_request(&home).status.success()); + + let shown = show(&home, None); + assert_eq!(shown["command"], serde_json::json!(["styles", "list"])); + let diagnostics = &shown["diagnostics"]; + assert_eq!(diagnostics["status"], "captured", "{shown}"); + let log = &diagnostics["log"]; + assert_eq!(log["auth"]["source"], "flag"); + assert_eq!(log["auth"]["account"], "example-user"); + assert!(log["argv"].to_string().contains(""), "{log}"); + let request = &log["requests"][0]; + assert!(request["status"].is_null(), "{request}"); + assert!( + request["url"] + .as_str() + .unwrap() + .contains("access_token="), + "{request}" + ); + + let on_disk = raw(&log_dir(&home)) + &raw(&history_dir(&home)); + assert!(!on_disk.contains("SIGNATURE-NOT-FOR-LOGS"), "{on_disk}"); + assert!(!on_disk.contains(TOKEN), "{on_disk}"); +} + +#[test] +fn logging_needs_history() { + let home = scratch("needs-history"); + let out = command(&home) + .env("MAPBOX_HISTORY", "0") + .env("MAPBOX_LOG", "1") + .args(["styles", "lsit"]) + .output() + .expect("run mapbox"); + assert!(!out.status.success()); + assert!(!config_dir(&home).exists(), "logging ran with history off"); + + assert!(run(&home, &["config", "set", "history", "off"]) + .status + .success()); + let refused = run(&home, &["-o", "json", "config", "set", "log", "on"]); + assert!(!refused.status.success()); + assert!( + String::from_utf8_lossy(&refused.stderr).contains(r#""code":"history_required""#), + "{}", + String::from_utf8_lossy(&refused.stderr) + ); + let get = run(&home, &["-o", "text", "config", "get", "log"]); + assert_eq!(String::from_utf8_lossy(&get.stdout).trim(), "off"); +} + +#[test] +fn a_log_that_is_gone_is_no_longer_available_and_its_record_stays() { + let home = scratch("gone"); + logged(&home, &["styles", "lsit"]); + let id = show(&home, None)["id"].as_str().unwrap().to_string(); + for entry in std::fs::read_dir(log_dir(&home)).expect("logs/") { + std::fs::remove_file(entry.expect("an entry").path()).expect("remove a log file"); + } + let shown = show(&home, Some(&id[..8])); + assert_eq!(shown["id"], id.as_str(), "the record stays"); + assert_eq!( + shown["diagnostics"], + serde_json::json!({ "status": "unavailable" }) + ); +} + +#[test] +fn past_the_size_limit_the_oldest_logs_go_and_their_records_stay() { + let home = scratch("limit"); + logged(&home, &["styles", "lsit"]); + let yesterday = day_before(&today(&home)); + + // A run from yesterday, with a log large enough to cross 100 MB alone. + // Sparse: the size is in the metadata, which is all the limit reads. + let old_id = "0ld00000-0000-4000-8000-000000000001"; + std::fs::write( + history_dir(&home).join(format!("{yesterday}.jsonl")), + format!( + "{{\"id\":\"{old_id}\",\"time\":\"{yesterday}T12:00:00.000Z\",\"diagnosticsCaptured\":true}}\n" + ), + ) + .expect("yesterday's history"); + let big = std::fs::File::create(log_dir(&home).join(format!("{yesterday}.jsonl"))) + .expect("yesterday's log"); + big.set_len(101 * 1024 * 1024) + .expect("a sparse 101 MB file"); + + assert!(!logged(&home, &["styles", "lsit"]).status.success()); + let total: u64 = std::fs::read_dir(log_dir(&home)) + .expect("logs/") + .map(|e| e.expect("an entry").metadata().expect("its size").len()) + .sum(); + assert!(total <= 100 * 1024 * 1024, "{total} bytes of logs"); + let old = show(&home, Some(old_id)); + assert_eq!(old["id"], old_id, "its history record stays"); + assert_eq!(old["diagnostics"]["status"], "unavailable"); + assert_eq!( + show(&home, None)["diagnostics"]["status"], + "captured", + "the newest log stays" + ); +} + +#[test] +fn a_log_goes_when_its_history_does() { + let home = scratch("linked"); + logged(&home, &["styles", "lsit"]); + let yesterday = day_before(&today(&home)); + + // Detail for a day history no longer has, and a day past the window. + let orphan = log_dir(&home).join(format!("{yesterday}.jsonl")); + std::fs::write(&orphan, "{}\n").expect("an orphaned log"); + let expired_log = log_dir(&home).join("2000-01-01.jsonl"); + std::fs::write(history_dir(&home).join("2000-01-01.jsonl"), "{}\n").expect("expired history"); + std::fs::write(&expired_log, "{}\n").expect("an expired log"); + + // With logging off, so the cleanup is not a side effect of writing. + // History prunes itself only on the first run of a day, so the expired + // history file may still be there; its log goes regardless. + run(&home, &["styles", "lsit"]); + assert!(!orphan.exists(), "a log outlived its history"); + assert!(!expired_log.exists(), "a log outlived 30 days"); + assert_eq!( + show(&home, None)["diagnostics"]["status"], + "not_captured", + "the newest run, with logging off" + ); +} diff --git a/tests/history.rs b/tests/history.rs new file mode 100644 index 0000000..bc3ff80 --- /dev/null +++ b/tests/history.rs @@ -0,0 +1,253 @@ +//! End-to-end tests for command history and `mapbox history`. +//! +//! The unit tests in `src/run_history.rs` and `src/history.rs` cover the +//! pure parts — which runs are recorded, what a line keeps, how an id prefix +//! resolves. What they cannot show is what a real run leaves on disk: a line +//! by default, none of what was typed after the command path, nothing at all +//! with history off, and `history` reading back what the runs before it +//! recorded. +//! +//! Nothing here reaches the network. The one request a test makes goes to a +//! proxy on a loopback port nobody is listening on, so it fails at once and +//! is still a request `http::send` saw. + +use std::net::TcpListener; +use std::path::{Path, PathBuf}; +use std::process::{Command, Output}; + +use serde_json::Value; + +/// A token-shaped fake. Nothing of it may reach history. +const TOKEN: &str = "pk.eyJ1IjoiZXhhbXBsZS11c2VyIiwiYSI6IngifQ.SIGNATURE-NOT-FOR-HISTORY"; +const SEARCH: &str = "1600 Pennsylvania Ave"; + +fn scratch(name: &str) -> PathBuf { + let home = PathBuf::from(env!("CARGO_TARGET_TMPDIR")).join(format!("history-{name}")); + let _ = std::fs::remove_dir_all(&home); + std::fs::create_dir_all(&home).expect("create the scratch home"); + home +} + +fn config_dir(home: &Path) -> PathBuf { + home.join(".mapbox") +} + +fn history_dir(home: &Path) -> PathBuf { + config_dir(home).join("history") +} + +fn command(home: &Path) -> Command { + let mut cmd = Command::new(env!("CARGO_BIN_EXE_mapbox")); + cmd.env_remove("MAPBOX_ACCESS_TOKEN") + .env_remove("MapboxAccessToken") + .env_remove("MAPBOX_USERNAME") + .env_remove("MAPBOX_OUTPUT") + .env_remove("MAPBOX_HISTORY") + .env_remove("MAPBOX_LOG") + .env_remove("SUDO_USER") + .env_remove("NO_PROXY") + .env_remove("no_proxy") + .env("MAPBOX_NO_UPDATE_CHECK", "1") + .env("HOME", home) + .env("XDG_CONFIG_HOME", home.join(".config")) + .env("MAPBOX_CONFIG_DIR", config_dir(home)); + cmd +} + +fn run(home: &Path, args: &[&str]) -> Output { + command(home).args(args).output().expect("run mapbox") +} + +/// Every recorded line, oldest first, and the raw bytes they came from. +fn lines(home: &Path) -> (Vec, String) { + let Ok(entries) = std::fs::read_dir(history_dir(home)) else { + return (vec![], String::new()); + }; + let mut files: Vec = entries.map(|e| e.expect("an entry").path()).collect(); + files.sort(); + let raw: String = files + .iter() + .map(|f| std::fs::read_to_string(f).expect("read a history file")) + .collect(); + let parsed = raw + .lines() + .map(|l| serde_json::from_str(l).expect("a history line is JSON")) + .collect(); + (parsed, raw) +} + +/// A request that fails before it leaves the machine: through a proxy on a +/// loopback port with nothing listening. +fn a_refused_search(home: &Path) -> Output { + let port = { + let listener = TcpListener::bind("127.0.0.1:0").expect("a loopback port"); + listener.local_addr().expect("the bound address").port() + }; + command(home) + .env("HTTPS_PROXY", format!("http://127.0.0.1:{port}")) + .args(["search", "forward", "--q", SEARCH, "--token", TOKEN]) + .output() + .expect("run mapbox") +} + +#[test] +fn a_run_is_recorded_by_default_with_its_command_path_only() { + let home = scratch("default"); + let out = a_refused_search(&home); + assert!(!out.status.success(), "the request cannot have succeeded"); + + let (lines, raw) = lines(&home); + assert_eq!(lines.len(), 1, "{raw}"); + let line = &lines[0]; + assert_eq!(line["command"], serde_json::json!(["search", "forward"])); + assert_eq!(line["exitCode"], 1); + assert_eq!(line["requestCount"], 1); + assert!(line["errorCode"].is_string(), "{line}"); + assert!( + line["id"].as_str().is_some_and(|id| id.len() == 36), + "{line}" + ); + + for typed in [SEARCH, "Pennsylvania", TOKEN, "SIGNATURE", "example-user"] { + assert!(!raw.contains(typed), "history kept {typed:?}: {raw}"); + } +} + +#[test] +fn a_run_leaves_only_history_and_with_it_off_nothing() { + let home = scratch("on"); + run(&home, &["styles", "lsit"]); + let created: Vec<_> = std::fs::read_dir(config_dir(&home)) + .expect("the config directory") + .map(|e| e.expect("an entry").file_name()) + .collect(); + assert_eq!(created, ["history"]); + + let home = scratch("off"); + let out = command(&home) + .env("MAPBOX_HISTORY", "0") + .args(["styles", "lsit"]) + .output() + .expect("run mapbox"); + assert!(!out.status.success()); + assert!( + !config_dir(&home).exists(), + "a run with history off created {}", + config_dir(&home).display() + ); +} + +#[test] +fn the_setting_turns_it_off_and_the_variable_overrides_the_setting() { + let home = scratch("switches"); + assert!(run(&home, &["config", "set", "history", "off"]) + .status + .success()); + run(&home, &["styles", "lsit"]); + assert_eq!(lines(&home).0.len(), 0, "off by the setting"); + + command(&home) + .env("MAPBOX_HISTORY", "1") + .args(["styles", "lsit"]) + .output() + .expect("run mapbox"); + assert_eq!( + lines(&home).0.len(), + 1, + "`MAPBOX_HISTORY=1` wins over the setting" + ); +} + +#[test] +fn help_version_completion_history_and_sudo_are_not_recorded() { + let home = scratch("skipped"); + for args in [ + &["--help"][..], + &["--version"], + &["styles", "--help"], + &["completion", "zsh"], + &["history", "list"], + ] { + assert!(run(&home, args).status.success(), "{args:?}"); + } + command(&home) + .env("SUDO_USER", "someone") + .args(["styles", "lsit"]) + .output() + .expect("run mapbox"); + assert!( + !config_dir(&home).exists(), + "a run history skips created {}", + config_dir(&home).display() + ); +} + +#[test] +fn history_reads_back_the_runs() { + let home = scratch("read-back"); + a_refused_search(&home); + run(&home, &["styles", "lsit"]); + + let list = run(&home, &["-o", "json", "history", "list"]); + assert!(list.status.success()); + let listed: Value = serde_json::from_slice(&list.stdout).expect("a JSON list"); + let listed = listed.as_array().expect("an array"); + assert_eq!(listed.len(), 2); + assert_eq!( + listed[0]["command"], + serde_json::json!(["styles"]), + "newest first" + ); + let older = listed[1]["id"].as_str().expect("an id"); + + let show = run(&home, &["-o", "json", "history", "show", &older[..8]]); + assert!(show.status.success()); + let shown: Value = serde_json::from_slice(&show.stdout).expect("a JSON run"); + assert_eq!(shown["id"], older); + assert_eq!(shown["command"], serde_json::json!(["search", "forward"])); + + let text = run(&home, &["-o", "text", "history", "list"]); + let text = String::from_utf8_lossy(&text.stdout); + assert!(text.starts_with("ID "), "a header row first: {text}"); + assert!(text.contains("mapbox search forward"), "{text}"); + assert!(!text.contains(SEARCH), "{text}"); + + let missing = run(&home, &["-o", "json", "history", "show", "zzzz"]); + assert!(!missing.status.success()); + assert!( + String::from_utf8_lossy(&missing.stderr).contains(r#""code":"history_not_found""#), + "{}", + String::from_utf8_lossy(&missing.stderr) + ); +} + +#[test] +fn history_with_history_off_says_so_on_stderr() { + let home = scratch("read-off"); + let out = command(&home) + .env("MAPBOX_HISTORY", "0") + .args(["-o", "json", "history", "list"]) + .output() + .expect("run mapbox"); + assert!(out.status.success()); + assert_eq!(String::from_utf8_lossy(&out.stdout).trim(), "[]"); + assert!( + String::from_utf8_lossy(&out.stderr).contains("mapbox config set history on"), + "{}", + String::from_utf8_lossy(&out.stderr) + ); +} + +#[test] +fn days_past_the_thirty_day_window_are_removed() { + let home = scratch("retention"); + std::fs::create_dir_all(history_dir(&home)).expect("the history directory"); + let old = history_dir(&home).join("2000-01-01.jsonl"); + std::fs::write(&old, "{}\n").expect("an old file"); + let not_history = history_dir(&home).join("notes.txt"); + std::fs::write(¬_history, "mine").expect("an unrelated file"); + + run(&home, &["styles", "lsit"]); + assert!(!old.exists(), "a file from 2000 outlived a 30-day window"); + assert!(not_history.exists(), "only dated history files are removed"); +} diff --git a/tests/non_interactive.rs b/tests/non_interactive.rs index bdb02f6..a5475dd 100644 --- a/tests/non_interactive.rs +++ b/tests/non_interactive.rs @@ -37,8 +37,12 @@ fn command(home: &Path) -> Command { .env_remove("MapboxAccessToken") .env_remove("MAPBOX_USERNAME") .env_remove("MAPBOX_OUTPUT") + // Off: these tests hold a run to leaving nothing on disk; what + // history leaves is `tests/history.rs`'s to check. + .env("MAPBOX_HISTORY", "0") .env_remove("MAPBOX_YES") .env_remove("MAPBOX_CONFIG_DIR") + .env_remove("MAPBOX_LOG") .env("HOME", home); cmd } diff --git a/tests/source_guards.rs b/tests/source_guards.rs index 0be47ea..3526c4c 100644 --- a/tests/source_guards.rs +++ b/tests/source_guards.rs @@ -43,6 +43,10 @@ fn sources() -> Vec<(String, String)> { /// - `agent_skills` — the staging directory it renames skills out of, and the /// skill directory `install --force` replaces. /// - `auth` — `logout`, and the scratch file `write_private` renames from. +/// - `dated_jsonl` — its own dated files past the retention window or the +/// size limit, matched by exact `YYYY-MM-DD.jsonl` names inside the +/// directory it writes to, and the scratch file a trim leaves when its +/// rename fails. /// - `executor` — nothing durable; the temp file a `--file` upload streams. /// - `generate_skills` — the staged skill directory it renames into place. /// - `skill_dest` — a test scratch directory. @@ -50,6 +54,7 @@ fn sources() -> Vec<(String, String)> { const MAY_DELETE: &[&str] = &[ "agent_skills.rs", "auth.rs", + "dated_jsonl.rs", "executor.rs", "generate_skills.rs", "skill_dest.rs", @@ -171,6 +176,30 @@ fn only_output_completion_and_binary_responses_write_to_stdout() { ); } +/// Every request goes through `http::send`, which is what adds it to the +/// run's record. +/// +/// A `reqwest` client has no response hook, so a request sent with +/// `RequestBuilder::send` anywhere else is one the record never holds — +/// silently, since nothing fails. `http.rs` is exempt: it is where `send` is +/// defined, and its own tests call the builder directly. +#[test] +fn only_http_sends_requests() { + let unexpected: Vec = sources() + .into_iter() + .filter(|(name, source)| name != "http.rs" && source.contains(".send()")) + .map(|(name, _)| format!("src/{name}")) + .collect(); + + assert!( + unexpected.is_empty(), + "these modules call `.send()` directly:\n {}\n\n\ + Wrap the request builder in `http::send(...)` instead, so the request is \ + in the run's record.", + unexpected.join("\n ") + ); +} + /// Modules that turn a Mapbox API failure into a `CliError::http`, and so /// must carry the response's `X-Request-Id` into it. const CARRIES_A_REQUEST_ID: &[&str] = &["account_usage.rs", "auth.rs", "executor.rs"];