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 ee5c106..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] 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/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/main.rs b/src/main.rs index 41ce04b..49d4ebe 100644 --- a/src/main.rs +++ b/src/main.rs @@ -19,14 +19,18 @@ 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; @@ -609,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 @@ -1108,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 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 index 06ec9b6..fbaa914 100644 --- a/src/run_record.rs +++ b/src/run_record.rs @@ -9,18 +9,20 @@ //! chooses field by field what it takes. Best-effort: nothing here can change //! a command's output or exit code. -// Nothing in this tree reads the record yet. +// 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}; +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, tilesets_cli}; +use crate::{ + auth, completion, confirm, executor, http, output, run_history, run_log, tilesets_cli, +}; const TILESETS: &str = tilesets_cli::COMMAND; @@ -110,6 +112,8 @@ pub(crate) struct Failure { /// 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, @@ -136,6 +140,7 @@ pub(crate) struct Record { } static RECORD: Mutex = Mutex::new(Record { + id: String::new(), argv: Vec::new(), command: Vec::new(), invocation: None, @@ -169,7 +174,11 @@ fn with_record(f: impl FnOnce(&mut Record)) { pub fn start(argv: &[OsString]) { STARTED.get_or_init(Instant::now); let argv = argv.get(1..).unwrap_or_default().to_vec(); - with_record(|record| record.argv = argv); + 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| { @@ -330,6 +339,34 @@ fn finish_locked(record: &mut Record, exit_code: Option) { 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. 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 238624c..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; 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 6a7f6b8..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",