runner_manager_platform/logging.rs
1// owner: d1-platform-core
2
3//! The structured log sink, and the redaction that is not optional.
4//!
5//! `07-security.md`'s threat table, on *"Logs disclose repository secrets"*:
6//! **"Structured allowlist logging with unconditional redaction of tokens,
7//! headers, JIT blobs, and paths."** Its security gate is a *secret-injection
8//! log scan*, and its release gate is that *"the user access token and the
9//! encoded JIT configuration are absent from logs, databases, snapshots, crash
10//! reports, and CLI output"*.
11//!
12//! # Allowlist, not denylist — and why that is the whole design
13//!
14//! A denylist redacts the fields somebody remembered to name. It is correct on
15//! the day it is written and wrong on the day a later task adds a field, which
16//! is the day it matters. So this sink inverts the default: **a field whose
17//! name is not in [`ALLOWED_FIELDS`] has its value replaced outright.** A task
18//! that adds `runner_token` to a log call gets `[redacted]` with no review, no
19//! ceremony, and no leak. Adding a field to the allowlist is a deliberate edit
20//! to this file that shows up in a diff.
21//!
22//! The field name itself is kept. Knowing that an event carried a
23//! `runner_token` field is useful, and the name is not the secret.
24//!
25//! # Two layers, because one is not enough
26//!
27//! The allowlist protects *fields*. It cannot protect the message body, which
28//! has to be allowed or the logs say nothing — and a message body is exactly
29//! where a secret ends up when somebody writes
30//! `info!("failed with {authorization}")`. So every string that survives the
31//! allowlist is then scrubbed by value shape ([`redact`]): GitHub token
32//! prefixes, credential header names, long opaque runs such as an encoded JIT
33//! configuration, and filesystem paths.
34//!
35//! Scrubbing by shape over-redacts, deliberately. Some of that is worth knowing
36//! about before it surprises somebody:
37//!
38//! - A slash-rooted word is treated as a filesystem path, and a URL *path* on
39//! its own looks exactly like one. Log a full URL — `https://api.github.com/…`
40//! — and it survives intact; log a bare `/repos/owner/repo` and it becomes
41//! `[path]`.
42//! - Any unbroken run of 40 or more base64, base64url, or hex characters is
43//! treated as an opaque secret. There is exactly one carve-out: a value that
44//! is precisely 64 lowercase hex characters is a SHA-256 digest, and renders
45//! as a labelled 12-character prefix rather than disappearing. A digest is
46//! not a secret, and `07-security.md` makes checksum verification a security
47//! gate whose most useful diagnostic is expected-versus-actual.
48//! - A JSON Web Token is redacted whole. Its `.` separators split it into runs
49//! the opaque-run rule is too short-sighted to catch, so it is recognised by
50//! shape instead: two or three base64url segments whose header begins `eyJ`.
51//! - A URL keeps its scheme, host and path and loses everything that
52//! authenticates it: the `user:password@` userinfo, the query string, and the
53//! fragment. The userinfo matters more than it looks — a
54//! token-authenticated git remote is
55//! `https://x-access-token:ghu_…@github.com/owner/repo.git`, so it is the
56//! shape a clone or fetch failure arrives in. The path stays diagnosable but
57//! is not exempt: each segment goes through the same shape rules on its own,
58//! because a token in `…/raw/ghu_…/f` is a token, and the alternative was the
59//! one place the belt never ran. A 40-character git object name is opaque
60//! enough to go with it.
61//! - A word ending in `:` or `=` whose stem is a credential header name causes
62//! the next two words to be redacted, so `Authorization: Bearer ghu_…` loses
63//! both the scheme and the token.
64//!
65//! A word is cut on structural punctuation — `,`, `;`, `{`, `}`, `[`, `]`,
66//! `<`, `>` and `&` — before any of that runs, and each fragment is then judged
67//! the way a whole word is: unwrapped, judged on its core, and re-emitted with
68//! its punctuation put back. Without that cut only the *first* key/value pair
69//! in a compact structure is ever examined, and redaction becomes a function of
70//! field order: `{"encoded_jit_config":"…"}` was caught and
71//! `{"runner_id":42,"encoded_jit_config":"…"}` was not, while
72//! `serde_json::to_string` is what decides which of the two an error body is.
73//! Nesting, a form-encoded body, a `;`-separated connection string and a plist
74//! element are all that same defect in different punctuation. So is an array
75//! element, one step further down — a fragment judged *with* its quote still
76//! attached matches no shape rule at all, and an array element is the one
77//! fragment that has no key of its own to give it away.
78//!
79//! Because the cut is flat, a credential's value does not have to be in the
80//! same fragment as the key that names it — `{"password":["hunter2"]}`,
81//! `{"password":{"v":"hunter2"}}` and a plist's
82//! `<key>password</key><string>hunter2</string>` all put it one or more
83//! fragments away — so a *carry* is threaded along the fragments to say that a
84//! key is still waiting for its value, or that a quoted value was cut before
85//! its closing quote. It steps over element names, because markup is not the
86//! value a key named, and it stops at the punctuation that visibly closes the
87//! value, because a redaction reported where no secret was is a false signal in
88//! the one log a reader consults to find out whether anything leaked.
89//!
90//! A URL is cut out of the text around it rather than being allowed to own the
91//! rest of the word. Its scheme is the run of scheme characters immediately
92//! before the `://`, and it ends at the first character that cannot appear in a
93//! URL — plus, *ahead of its query string only*, at a `;` or an `&`, which are
94//! structural characters everywhere else and are query syntax after the `?`.
95//! Everything on either side goes back through the rules. So
96//! `{"documentation_url":"https://…","token":"ghu_…"}` — which is what a GitHub
97//! REST error body looks like — keeps the URL and redacts the token, rather
98//! than the URL swallowing the token, and
99//! `Server=https://vault.local/api;Password=…` keeps the URL and redacts the
100//! password rather than the URL swallowing the `;` that separates them.
101//!
102//! **The text after a URL is iterated over, not recursed into.** That is a
103//! memory-safety property, not a style: recursing there made stack depth linear
104//! in the length of the message, and ~86 KB of URL-carrying JSON exited
105//! `STATUS_STACK_OVERFLOW`. A stack overflow is not catchable and takes the
106//! process with it, so an attacker-influenceable error body could kill the
107//! agent from inside its own log sink — and a sink that is not running redacts
108//! nothing at all. For the same reason every search in `split_url` is bounded
109//! by the URL's own end: a pass that never returns is as effective a denial as
110//! one that overflows.
111//!
112//! A key is also trimmed of backslashes, which a value never is: `Debug` on a
113//! `String` escapes the quotes inside it, so a body reached through
114//! `error!(reason = ?err)` spells its keys `\"password\"`. The `trim_key`
115//! function documents why the same trim must not be applied to a value; it is
116//! named rather than linked because it is private and this module's
117//! documentation is not.
118//!
119//! Every one of those is a case where being wrong costs a slightly less
120//! readable log line, against a case where being wrong the other way costs a
121//! disclosed credential.
122//!
123//! # What this does not do
124//!
125//! It does not stop a caller printing to standard output, and it does not
126//! redact a `Debug` derive somewhere else in the program. Those are held by
127//! different controls: `secrecy::SecretString` for the two values that matter
128//! (`07-security.md`'s credential inventory), and
129//! [`crate::process::SpawnSpec::spawn_with_handoff`] for the command line.
130
131use std::fmt;
132use std::io::Write;
133use std::path::{Path, PathBuf};
134
135use serde_json::{Map, Value};
136use tracing::field::{Field, Visit};
137use tracing::{Event, Subscriber};
138use tracing_subscriber::layer::{Context, Layer};
139use tracing_subscriber::registry::LookupSpan;
140
141/// What replaces a value this sink will not emit.
142pub const REDACTION: &str = "[redacted]";
143
144/// What replaces something that was recognisably a filesystem path. Distinct
145/// from [`REDACTION`] so a reader can tell "a path was here" from "a secret was
146/// here" without either being disclosed.
147pub const PATH_REDACTION: &str = "[path]";
148
149/// The field names this sink emits verbatim. Everything else is replaced with
150/// [`REDACTION`].
151///
152/// ---
153///
154/// **Read this before adding a name.** A field on this list still passes
155/// through [`redact`], so adding one does not switch redaction off — but it
156/// does mean the field's value reaches the scrubber instead of being discarded,
157/// and the scrubber only recognises shapes it was taught. Add a name only when
158/// the value is structurally incapable of carrying a credential: an
159/// identifier, an enumerated state, a count, a duration. Never add a name whose
160/// value is free text supplied by GitHub or by a workflow.
161///
162/// Kept sorted, and a test enforces that, so an addition is one line in a diff
163/// rather than a name buried in the middle of a list.
164pub const ALLOWED_FIELDS: &[&str] = &[
165 "arch",
166 "attempt",
167 "attempt_id",
168 "attempt_state",
169 "capacity",
170 "count",
171 "demand",
172 "desired",
173 "duration_ms",
174 "elapsed_ms",
175 "error_kind",
176 "event",
177 "exit_code",
178 "headroom",
179 "host_id",
180 "http_status",
181 "installation_id",
182 "job_id",
183 "label",
184 "lock",
185 "lock_wait_ms",
186 "materialize_ms",
187 "message",
188 "mode",
189 "os",
190 "outcome",
191 "pid",
192 "policy_id",
193 "policy_state",
194 "reason",
195 "register_ms",
196 "retry_in_ms",
197 "runner_id",
198 "scope",
199 "spawn_ms",
200 "start_mode",
201 "state",
202 "target",
203 "version",
204];
205
206/// Header and parameter names whose value is a credential.
207///
208/// Compared case-insensitively with `-` and `_` treated as the same character,
209/// because the same header arrives as `Authorization`, `authorization`, and
210/// `x_api_key` depending on who wrote the line.
211const CREDENTIAL_KEYS: &[&str] = &[
212 "access.token",
213 "api.key",
214 "apikey",
215 "auth",
216 "authorization",
217 "client.secret",
218 "cookie",
219 "credential",
220 "encoded.jit.config",
221 "jit",
222 "jit.config",
223 "jitconfig",
224 "password",
225 "private.token",
226 "proxy.authorization",
227 "refresh.token",
228 "secret",
229 "set.cookie",
230 "token",
231 "www.authenticate",
232 "x.api.key",
233 "x.auth.token",
234 "x.github.token",
235 "x.hub.signature",
236 "x.hub.signature.256",
237];
238
239/// Authentication scheme words. Whatever follows one of these is the
240/// credential.
241const SCHEME_WORDS: &[&str] = &["basic", "bearer", "digest", "negotiate", "token"];
242
243/// Prefixes GitHub gives its credentials. Present as a belt on top of the
244/// opaque-run rule below, because a short-lived or truncated token can be under
245/// the length threshold while still being a live credential.
246const TOKEN_PREFIXES: &[&str] = &["ghp_", "gho_", "ghu_", "ghs_", "ghr_", "github_pat_", "gh_"];
247
248/// How long an unbroken run of opaque characters has to be before it is assumed
249/// to be a secret.
250///
251/// 40 rather than something shorter so that ordinary identifiers, hyphenated
252/// words, and UUIDs (36 characters, and not secret) survive; short enough that
253/// every GitHub credential format and every encoded JIT configuration is well
254/// past it.
255const OPAQUE_RUN_THRESHOLD: usize = 40;
256
257/// Characters that make up base64, base64url, and hex.
258fn is_opaque_char(c: char) -> bool {
259 c.is_ascii_alphanumeric() || matches!(c, '+' | '/' | '=' | '_' | '-')
260}
261
262/// Punctuation that may wrap a value without being part of it.
263const WRAPPERS: &[char] = &[
264 '"', '\'', '`', '(', ')', '[', ']', '{', '}', '<', '>', ',', ';', '.', '!', '?',
265];
266
267/// Punctuation that separates one key/value pair from the next *inside* a
268/// single whitespace-delimited word.
269///
270/// [`redact_core`] judges a fragment by splitting it once, on the first `=` or
271/// `:` it finds. That is enough for `key=value` and for a one-field object,
272/// and it is why every shape this module was tested against put the credential
273/// in the first pair. It is not enough for anything `serde_json::to_string`
274/// actually emits: a struct with two fields becomes
275/// `{"runner_id":42,"encoded_jit_config":"…"}`, where the only pair ever
276/// examined is `runner_id`. Nesting is the same defect one level down, and a
277/// form-encoded body is the same defect spelled with `&`.
278///
279/// So a word is cut on these before any of that runs, and each fragment is
280/// judged on its own, by [`redact_fragment`]. The separators go back verbatim,
281/// because the structure around a redaction is what keeps the line diagnosable.
282///
283/// `;` is here for the reason `&` is: it separates the pairs of a Windows
284/// connection string (`Server=host;Database=x;Password=…`), of a credential
285/// string, and of a cookie header written without a space after the separator.
286/// It was already in [`WRAPPERS`] — recognised as punctuation, and so never
287/// used to cut — which left `Set-Cookie: theme=dark; session=…` safe only
288/// because of the space. `d2` logs keychain, DPAPI and libsecret failures, and
289/// that is the shape they arrive in.
290///
291/// `<` and `>` are here because [`split_wrappers`] strips only the *outermost*
292/// pair, so `<string>ghu_…</string>` reached the rules as
293/// `string>ghu_…</string`, which is on no list and matches no shape. `d3`'s
294/// installers handle launchd plists, which is where that shape comes from.
295const STRUCTURAL: &[char] = &[',', ';', '{', '}', '[', ']', '<', '>', '&'];
296
297/// Whether this sink will emit a field's value rather than replacing it.
298#[must_use]
299pub fn is_field_allowed(name: &str) -> bool {
300 ALLOWED_FIELDS.binary_search(&name).is_ok()
301}
302
303/// Trims the punctuation a *key* can arrive wrapped in: [`WRAPPERS`], plus the
304/// backslash.
305///
306/// The backslash is here rather than in [`WRAPPERS`] on purpose, and the
307/// distinction is load-bearing in both directions.
308///
309/// It has to be trimmed somewhere. `tracing::error!(reason = ?err)` reaches
310/// this module through `record_debug` and `format!("{:?}")`, and `Debug` on a
311/// `String` escapes the quotes inside it — so an error whose `Debug` embeds an
312/// HTTP body arrives with its keys spelled `\"password\"`. Trimming only
313/// [`WRAPPERS`] leaves the backslash welded on, and `\"password\` is on no
314/// list. That is `d2`'s shape: a secret-store failure carrying the body it was
315/// handed.
316///
317/// It must not be trimmed unconditionally. [`split_wrappers`] runs before
318/// [`looks_like_path`], so a `\` in [`WRAPPERS`] would strip the leading
319/// `\\` that UNC detection keys on, and `\\server\share` would stop being
320/// recognised as a path. A key is the one place a backslash can never be part
321/// of the value, so it is the one place the trim is unconditional;
322/// [`trim_start_wrappers`] takes the same backslash off a *value* only when it
323/// is escaping punctuation.
324fn trim_key(key: &str) -> &str {
325 key.trim()
326 .trim_matches(|c: char| c == '\\' || WRAPPERS.contains(&c))
327}
328
329fn normalise_key(key: &str) -> String {
330 trim_key(key).to_ascii_lowercase().replace(['-', '_'], ".")
331}
332
333fn is_credential_key(key: &str) -> bool {
334 let key = normalise_key(key);
335 CREDENTIAL_KEYS.contains(&key.as_str())
336}
337
338fn is_scheme_word(word: &str) -> bool {
339 SCHEME_WORDS.contains(&word.to_ascii_lowercase().as_str())
340}
341
342/// Scrubs a string of anything that looks like a credential, an encoded JIT
343/// configuration, or a filesystem path.
344///
345/// Applied to every string this sink emits, including the ones whose field name
346/// is on [`ALLOWED_FIELDS`]. Also public so that the TUI and the CLI can put a
347/// value through the same rules before showing it, rather than inventing a
348/// second, differently wrong set.
349#[must_use]
350pub fn redact(text: &str) -> String {
351 let mut out = String::with_capacity(text.len());
352 // How many upcoming words to replace outright, because a credential key or
353 // an authentication scheme word said the value comes next.
354 let mut pending: u32 = 0;
355
356 for chunk in text.split_inclusive(char::is_whitespace) {
357 let (word, whitespace) = split_trailing_whitespace(chunk);
358
359 if word.is_empty() {
360 out.push_str(whitespace);
361 continue;
362 }
363
364 if pending > 0 {
365 pending -= 1;
366 out.push_str(REDACTION);
367 out.push_str(whitespace);
368 // A header value ends at a comma or semicolon; anything after that
369 // is the next header's name and is not a secret.
370 if word.ends_with([',', ';']) {
371 pending = 0;
372 }
373 continue;
374 }
375
376 let (rendered, follow_on) = redact_word(word);
377 out.push_str(&rendered);
378 out.push_str(whitespace);
379 pending = follow_on;
380 }
381
382 out
383}
384
385/// Splits a chunk produced by `split_inclusive` into its word and the single
386/// whitespace character that terminated it, if any.
387fn split_trailing_whitespace(chunk: &str) -> (&str, &str) {
388 match chunk.char_indices().next_back() {
389 Some((index, last)) if last.is_whitespace() => chunk.split_at(index),
390 _ => (chunk, ""),
391 }
392}
393
394/// Splits a fragment into its leading wrapping punctuation, its core, and its
395/// trailing wrapping punctuation.
396///
397/// Shared by [`redact_word`] and [`redact_core`], because both have to judge a
398/// fragment on its core while emitting it with its punctuation intact.
399///
400/// [`WRAPPERS`], and an *escaped* quote as well. Escaped text is exactly what
401/// a `Debug` rendering of a string is, and in it every quote arrives with a
402/// backslash welded on — so a value spelled `\"ghu_…\"` is wrapped in the
403/// same way `"ghu_…"` is, and none of the shape rules can see the token until
404/// the wrapper comes off. Trimming the key alone is not enough: `runner_token`
405/// is deliberately *not* on [`CREDENTIAL_KEYS`], because a name is not what
406/// makes a value a secret, so that pair is caught by the token-prefix rule
407/// reading its value or it is not caught at all.
408fn split_wrappers(fragment: &str) -> (&str, &str, &str) {
409 let leading = fragment.len() - trim_start_wrappers(fragment).len();
410 let (prefix, rest) = fragment.split_at(leading);
411 let core_len = trim_end_wrappers(rest).len();
412 let (core, suffix) = rest.split_at(core_len);
413 (prefix, core, suffix)
414}
415
416/// Trims wrapping punctuation from the front of a fragment.
417///
418/// A backslash counts as punctuation **only when it escapes punctuation**, and
419/// that restriction is the whole of what keeps this safe. `\"value` is a
420/// quoted value spelled the way an escaped rendering spells it, and the
421/// backslash is not part of the value. `\\server\share` is a UNC path whose
422/// leading backslashes escape nothing and *are* the value — trimming them is
423/// exactly what would stop [`looks_like_path`] recognising it, and this runs
424/// before [`looks_like_path`] does. `\\` is not a backslash-escaping-a-
425/// wrapper, so the two cases separate cleanly.
426fn trim_start_wrappers(fragment: &str) -> &str {
427 let mut rest = fragment;
428 loop {
429 let trimmed = rest.trim_start_matches(WRAPPERS);
430 let trimmed = match trimmed.strip_prefix('\\') {
431 Some(after) if after.starts_with(WRAPPERS) => after,
432 _ => trimmed,
433 };
434 if trimmed.len() == rest.len() {
435 return rest;
436 }
437 rest = trimmed;
438 }
439}
440
441/// Trims wrapping punctuation from the end of a fragment.
442///
443/// A trailing backslash goes with it, and needs no adjacency test: trimming
444/// runs right to left, so a backslash that has reached the end is one whose
445/// quote has already been taken off. A path that ends in a separator is still
446/// a path without it.
447fn trim_end_wrappers(fragment: &str) -> &str {
448 let mut rest = fragment;
449 loop {
450 let trimmed = rest.trim_end_matches(WRAPPERS).trim_end_matches('\\');
451 if trimmed.len() == rest.len() {
452 return rest;
453 }
454 rest = trimmed;
455 }
456}
457
458/// What a credential key left outstanding at the end of the text that named it.
459///
460/// The structural cut is flat and a credential's value does not have to be in
461/// the same fragment as the key that names it, so something has to carry the
462/// key across the cut. Nothing did, which is [`redact_core`]'s empty-value
463/// case: the comment there claimed the value would be reached "in the next
464/// fragment, where the structural cut reaches it", and no such thing happened.
465///
466/// The two variants are not the same claim, and collapsing them over-redacts:
467///
468/// - [`Carry::Expecting`] is *"a key named a value that has not appeared yet"*.
469/// It has to step over markup, because `<key>password</key><string>…</string>`
470/// puts `/key` and `string` between the key and its value.
471/// - [`Carry::Unclosed`] is *"a quoted value was redacted and its closing quote
472/// is not in this fragment"*, so the value continues past the cut. Inside an
473/// open quote `<` and `>` are literal text rather than markup, so this one
474/// must *not* step over anything.
475#[derive(Clone, Copy, PartialEq, Eq, Debug)]
476enum Carry {
477 /// Nothing outstanding.
478 None,
479 /// A credential key supplied no value of its own.
480 Expecting,
481 /// A redacted credential value was cut before its closing quote.
482 Unclosed,
483}
484
485/// Whether wrapping punctuation closes the value it followed.
486///
487/// A quote closes a string and a bracket closes a structure, so either one
488/// means the credential value ended here and a carry must stop. `,` and `;` are
489/// on the list for the reason [`redact`] already stops its word-level follow-on
490/// at them: they end a header value, and what comes after is the next header's
491/// name.
492///
493/// `>` is deliberately absent. It closes a *tag*, not a value —
494/// `<key>password</key>` ends in one with the credential's value still to come
495/// — and treating it as a terminator is what would leave the multi-word plist
496/// spelling leaking.
497fn closes_a_value(wrappers: &str) -> bool {
498 wrappers.contains(['"', '\'', '`', ',', ';', ']', '}', ')'])
499}
500
501/// Whether a value opened a quote that its own fragment did not close.
502fn opens_an_unclosed_quote(lead: &str, trail: &str) -> bool {
503 const QUOTES: [char; 3] = ['"', '\'', '`'];
504 lead.contains(QUOTES) && !trail.contains(QUOTES)
505}
506
507/// Whether a fragment sits where an element *name* goes rather than where its
508/// content does.
509///
510/// `<` and `>` are in [`STRUCTURAL`] because `<string>ghu_…</string>` reached
511/// the rules as `string>ghu_…</string` and matched nothing. Having cut on them,
512/// the loop knows which side of a tag it is on, and a [`Carry::Expecting`] must
513/// not be spent on `/key` or `string` when the value it is waiting for is the
514/// element's content. A tag name is still judged by every other rule — this
515/// says only that it is not the value a credential key named.
516fn is_tag_name(preceding: Option<char>, following: Option<char>) -> bool {
517 preceding == Some('<') && following == Some('>')
518}
519
520/// Redacts one whitespace-delimited word, and says how many following words the
521/// word implicates.
522fn redact_word(word: &str) -> (String, u32) {
523 // Wrapping punctuation is kept so that JSON-ish and prose context survives
524 // — `("ghu_…")` should become `("[redacted]")`, not `[redacted]`.
525 let (prefix, core, suffix) = split_wrappers(word);
526
527 if core.is_empty() {
528 return (word.to_string(), 0);
529 }
530
531 // A bare credential key or scheme word: the value is the next word.
532 //
533 // The stem is unwrapped before it is judged: spaced JSON writes the key as
534 // `"password":`, which leaves `password"` welded to a quote, and that is on
535 // no list. A long value survived this anyway by way of the opaque-run rule,
536 // so the gap only ever showed on a short one.
537 let stem = core.trim_end_matches([':', '=']);
538 if stem.len() < core.len() && is_credential_key(stem) {
539 // Two, so that `Authorization: Bearer <token>` loses the scheme and the
540 // token rather than only the scheme.
541 return (word.to_string(), 2);
542 }
543 if is_scheme_word(core) {
544 return (word.to_string(), 1);
545 }
546
547 let (rendered, carry) = redact_core(core, suffix);
548
549 // A value the word did not finish is the *next* word's problem, which is
550 // the follow-on rule the word level already has, reached from one level
551 // down. A pretty-printed plist is why it is needed: `<key>password</key>`
552 // and `<string>hunter2</string>` are on separate lines, so the key and its
553 // value are not even in the same word.
554 //
555 // The two carries ask for different amounts, for the same reason the stem
556 // rule above asks for two words and not one:
557 //
558 // - [`Carry::Expecting`] means the value has not been seen *at all*, so it
559 // may be introduced by a word of its own — `<string>correct` and then
560 // `horse</string>`. Two, exactly as `Authorization: Bearer <token>` needs
561 // two.
562 // - [`Carry::Unclosed`] means the value has already started and was cut, so
563 // only its remainder is outstanding. One.
564 //
565 // Trailing punctuation that closes the value withdraws the claim, for the
566 // same reason pass one declines an empty value: `{"password":""}` names a
567 // credential and supplies nothing, and redacting the next word there would
568 // report a secret where none was.
569 let follow_on = if closes_a_value(suffix) {
570 0
571 } else {
572 match carry {
573 Carry::None => 0,
574 Carry::Unclosed => 1,
575 Carry::Expecting => 2,
576 }
577 };
578 (format!("{prefix}{rendered}{suffix}"), follow_on)
579}
580
581/// Redacts one fragment of a cut-up word, judging it on its core.
582///
583/// [`redact_core`] used to recurse on the *raw* fragment, and its terminal
584/// fallback then handed that fragment to [`redact_value`] with its wrapping
585/// punctuation still attached. A fragment carrying no `:` or `=` of its own —
586/// which is exactly what an array element is — therefore reached the shape
587/// rules as `"ghu_…`, where `starts_with("ghu_")` fails, [`is_opaque_char`]
588/// fails on the quote, the `eyJ` test fails, and [`looks_like_path`] never gets
589/// a clean look at `"C:\Users\…`.
590///
591/// That is the defect the structural cut was written to close, one step further
592/// down: *"only the first key/value pair is ever examined"* became *"a value
593/// with no key of its own is never examined"*. It survived a round because the
594/// secret-injection scan had no array among its shapes, which is the same
595/// lesson in a different place — a check that cannot fail proves nothing.
596///
597/// So a fragment is treated the way [`redact_word`] treats a word: split,
598/// judge the core, put the punctuation back.
599///
600/// The *word-level* follow-on rule is still not repeated here, and the reason
601/// stands: *"the value is the next word"* is a statement about whitespace, and
602/// there is no next word inside a fragment. What that argument does not cover —
603/// and what an earlier spelling of it wrongly took itself to have settled — is
604/// the *fragment-level* claim: **the value is the next fragment**. That one is
605/// a statement about the structural cut, it is true, and nothing implemented
606/// it, which is why `{"password":["hunter2"]}` and
607/// `<key>password</key><string>hunter2</string>` went out whole. [`Carry`] is
608/// that claim, threaded through the loop in [`redact_core`].
609///
610/// `trailing` says this is the last fragment of its core, and it is what keeps
611/// the carry from escaping a word it has already been spent inside: consuming
612/// a claim in the middle of a core settles it, while consuming it at the end
613/// leaves open the possibility that the value runs on into the next word.
614fn redact_fragment(
615 fragment: &str,
616 carry: Carry,
617 tag_name: bool,
618 trailing: bool,
619) -> (String, Carry) {
620 let (prefix, core, suffix) = split_wrappers(fragment);
621 if core.is_empty() {
622 return (fragment.to_string(), carry);
623 }
624
625 let claimed = match carry {
626 Carry::None => false,
627 // Markup is not the value a credential key named.
628 Carry::Expecting => !tag_name,
629 // Inside an open quote there is no markup, only text.
630 Carry::Unclosed => true,
631 };
632
633 if claimed {
634 // Two different reasons to think the value has more to come, and one
635 // answer: it is `Unclosed` from here, never the `Expecting` it may have
636 // arrived as, because the value has now started.
637 //
638 // - `carry == Unclosed` — still inside an open quote, so the value runs
639 // into the next fragment as well.
640 // - `trailing` — a claim spent on the *last* fragment of a core is one
641 // whose value reached the end of the word with nothing closing it, so
642 // it may continue into the next word.
643 // `<key>password</key><string>` + `correct horse</string>` is that
644 // shape.
645 //
646 // Anything else was spent in the middle of a core, where the value was
647 // and is done — and punctuation that closes a string or a structure
648 // settles it either way.
649 let next = if !closes_a_value(suffix) && (carry == Carry::Unclosed || trailing) {
650 Carry::Unclosed
651 } else {
652 Carry::None
653 };
654 return (format!("{prefix}{REDACTION}{suffix}"), next);
655 }
656
657 let (rendered, next) = redact_core(core, suffix);
658 let next = if closes_a_value(suffix) {
659 Carry::None
660 } else if next == Carry::None {
661 // **An unclaimed fragment preserves the claim rather than clearing
662 // it.** This is the whole of what lets a plist work: `/key` and
663 // `string` sit between `<key>password</key>` and the `<string>` content
664 // that is the value, they are tag names so they do not spend the claim,
665 // and a fragment that neither spends nor arms one must leave it exactly
666 // as it found it. Overwriting with this fragment's own (empty) result
667 // is how `<key>password</key><string>hunter2</string>` kept leaking
668 // after the carry existed.
669 carry
670 } else {
671 next
672 };
673 (format!("{prefix}{rendered}{suffix}"), next)
674}
675
676/// Redacts one word with its wrapping punctuation already removed, and reports
677/// what it left outstanding for whatever follows it.
678///
679/// `closing` is the wrapping punctuation the caller stripped off the end of
680/// this core. It is not emitted here — the caller puts it back — but the loop
681/// below has to see it, because the character that follows the *last* fragment
682/// is what says whether that fragment is an element name or an element's
683/// content.
684fn redact_core(core: &str, closing: &str) -> (String, Carry) {
685 // A URL survives, minus everything on it that carries a credential. The
686 // scheme, host and path are what makes a log line diagnosable.
687 //
688 // The URL is *cut out* of the text around it rather than being allowed to
689 // own the rest of the fragment, and both sides of the cut come back through
690 // here. [`split_url`] documents what the old unbounded `split_once("://")`
691 // cost. This still runs ahead of the structural cut, because a query string
692 // is `redact_url`'s to own: `?` and `#` are not structural characters, and
693 // an OAuth implicit-flow response puts the token after one of them.
694 //
695 // **The tail is iterated, not recursed into, and that is a memory-safety
696 // property rather than a matter of taste.** An earlier spelling called
697 // `redact_core` on the remainder, and argued only that the recursion
698 // *terminates*: every call is on a strictly shorter slice, which is true
699 // and is not enough. Termination says nothing about **depth**, and depth
700 // was linear in the length of the input — one frame per URL. A message of
701 // ~2000 `{"url":"https://…"},` items, about 86 KB, exited
702 // `0xc00000fd STATUS_STACK_OVERFLOW`.
703 //
704 // A stack overflow is not a `panic`: it is not catchable, it does not
705 // unwind, and it takes the process with it. A large HTTP error body is
706 // content an attacker can influence, so that was a way to kill the agent
707 // from inside its own log sink — and a sink that is not running redacts
708 // nothing at all, which is worse than any single leak.
709 //
710 // With the loop, every remaining re-entry is depth-bounded by construction
711 // rather than by argument:
712 //
713 // - `prefix` holds everything before the *first* `://`, so it contains no
714 // `://` and cannot reach this branch again.
715 // - `rest` is what is left when the loop finds no further `://`, for the
716 // same reason.
717 // - the structural branch below calls [`redact_fragment`], whose fragments
718 // contain no structural character by construction and so cannot reach it
719 // again either.
720 //
721 // Three levels, whatever the input is. Anything added here that recurses on
722 // a slice whose length is not bounded by a constant re-opens this.
723 if let Some((prefix, scheme, url, remainder)) = split_url(core) {
724 let mut out = String::with_capacity(core.len());
725 if !prefix.is_empty() {
726 out.push_str(&redact_core(prefix, "").0);
727 }
728 out.push_str(&redact_url(scheme, url));
729
730 let mut rest = remainder;
731 while let Some((prefix, scheme, url, remainder)) = split_url(rest) {
732 if !prefix.is_empty() {
733 out.push_str(&redact_core(prefix, "").0);
734 }
735 out.push_str(&redact_url(scheme, url));
736 rest = remainder;
737 }
738 if !rest.is_empty() {
739 out.push_str(&redact_core(rest, "").0);
740 }
741
742 // A URL is a complete value: it carries its own credentials in its own
743 // places, and `redact_url` has already dealt with them. Nothing is
744 // outstanding, which is also what keeps `{"token":"https://…"}` from
745 // arming a claim against whatever follows the URL.
746 return (out, Carry::None);
747 }
748
749 // A Windows drive path is `key:value`-shaped by accident, and
750 // `looks_like_path` only recognises the drive letter at position zero.
751 // Splitting such a path on its colon would hand the tail to a rule that
752 // matches nothing, so it has to be judged whole, before the separators
753 // get at it.
754 if looks_like_path(core) {
755 return (PATH_REDACTION.to_string(), Carry::None);
756 }
757
758 // A compact structure holds more than one key/value pair, and the rules
759 // below examine exactly one of them: `split_once` stops at the first
760 // separator it finds. So `{"encoded_jit_config":"…"}` was caught and
761 // `{"runner_id":42,"encoded_jit_config":"…"}` was not — the two differ by
762 // field order and by nothing else, and `serde_json::to_string` is what
763 // chooses the order. Nesting was the same defect: the value recursion
764 // below ends at `redact_value`, which is a leaf and never comes back
765 // here, so an object inside an object went out whole. A form-encoded body
766 // was the same defect again, with `&` as a separator nothing knew.
767 //
768 // Cutting on [`STRUCTURAL`] first turns all three into the shape the rules
769 // already handle, and does it at any depth: the cut is flat, so
770 // `{"a":{"b":{"token":"…"}}}` yields the same fragments a one-level object
771 // would.
772 //
773 // Each fragment goes through [`redact_fragment`] rather than straight back
774 // in here, because a fragment carries its own wrapping punctuation and a
775 // value judged with its quote attached matches nothing at all.
776 //
777 // The recursion terminates *and is depth-bounded*: a fragment contains no
778 // structural character by construction, so `redact_fragment` cannot reach
779 // this branch again, and the URL branch above iterates over its tail rather
780 // than recursing into it. The loop here is a loop for the same reason — a
781 // fragment per separator, at whatever length the input has.
782 //
783 // A [`Carry`] is threaded along it because the cut is flat and a
784 // credential's value need not be in the same fragment as its key. Without
785 // it the empty-value skip in pass one was a promise nothing kept: the value
786 // was said to be reachable "in the next fragment", and no next fragment
787 // ever heard about the key.
788 if core.contains(STRUCTURAL) {
789 let mut out = String::with_capacity(core.len());
790 let mut carry = Carry::None;
791 let mut rest = core;
792 // The separator on each side of a fragment is what says whether it is
793 // an element name or an element's content.
794 let mut preceding: Option<char> = None;
795 while let Some(index) = rest.find(STRUCTURAL) {
796 let (fragment, tail) = rest.split_at(index);
797 // Every character in `STRUCTURAL` is ASCII, so the separator is
798 // one byte, this cannot split a code point, and the byte is the
799 // whole character.
800 let separator = char::from(tail.as_bytes()[0]);
801 if !fragment.is_empty() {
802 let (rendered, next) = redact_fragment(
803 fragment,
804 carry,
805 is_tag_name(preceding, Some(separator)),
806 false,
807 );
808 out.push_str(&rendered);
809 carry = next;
810 }
811 out.push_str(&tail[..1]);
812 preceding = Some(separator);
813 rest = &tail[1..];
814 }
815 if !rest.is_empty() {
816 // The last fragment's *following* character is the caller's closing
817 // punctuation: in `<key>password</key>` the final `/key` is a tag
818 // name only because the `>` that ends it was stripped as a wrapper
819 // before this ran.
820 let following = closing.chars().next();
821 let (rendered, next) =
822 redact_fragment(rest, carry, is_tag_name(preceding, following), true);
823 out.push_str(&rendered);
824 carry = next;
825 }
826 return (out, carry);
827 }
828
829 // `key=value` and `key:value` in a single fragment.
830 //
831 // Pass one asks only whether either separator names a credential, and it
832 // runs to completion before any value is inspected, because the *first*
833 // separator in a fragment is not necessarily the one that names the key.
834 //
835 // The witness is a webhook signature header in its compact-JSON spelling,
836 // `{"x-hub-signature-256":"sha256=<hmac>"}`, and
837 // `a_credential_header_loses_its_scheme_and_its_value` holds it. The `=`
838 // comes first and names nothing, but what follows it is a whole HMAC —
839 // *non-empty*, so a merged pass inspects that value, renders it as a
840 // digest prefix, and returns without ever reaching the `:` that names
841 // `x-hub-signature-256`. `{"password":"a=b"}` is the same witness with
842 // nothing else going on: merged, it comes out whole.
843 //
844 // Two earlier spellings of this comment named
845 // `{"encoded_jit_config":"eyJ…In0="}` and then
846 // `{"encoded_jit_config":"eyJ…In0=","runner_id":42}`, and neither
847 // demonstrates the invariant: base64 padding is trailing-only, so the `=`
848 // split yields a value that `split_wrappers` trims to empty, and the
849 // `value.is_empty()` guard in pass two falls through to the `:` anyway. A
850 // comment naming a case that does not demonstrate its own invariant is how
851 // the invariant gets deleted by the next person, so the witness above is
852 // one that reds a named test when the two passes are merged.
853 //
854 // Both halves are judged through `trim_key`: compact JSON welds a quote to
855 // each, so the key arrives as `encoded_jit_config"`, and a `Debug`
856 // rendering welds a backslash as well.
857 // Whether pass one saw a credential key and was given nothing to redact.
858 let mut names_a_credential = false;
859
860 for separator in ['=', ':'] {
861 if let Some((key, raw_value)) = core.split_once(separator)
862 && is_credential_key(key)
863 {
864 // The value's own wrapping punctuation goes back, exactly as pass
865 // two puts it back. Dropping it emitted `{"password":[redacted]"}`
866 // — an unbalanced quote in a line this module argues, correctly,
867 // has to stay diagnosable, and a reader who cannot parse the line
868 // cannot tell a redaction from a truncation.
869 let (lead, value, trail) = split_wrappers(raw_value);
870
871 // An empty value is nothing to redact, and pass two declines one
872 // for the same reason. Claiming `[redacted]` here says a secret was
873 // somewhere none was, which is a false signal in the one log a
874 // reader consults to find out whether anything leaked.
875 //
876 // It is also load-bearing for the URL branch above, which sends
877 // the text before a URL back through here: `{"token":"https://…"}`
878 // leaves this pass a key of `token` and a value of nothing, and
879 // redacting that emitted `token":"[redacted]https://…` — the URL
880 // still standing behind the redaction meant to have replaced it.
881 //
882 // **What it is not is a reason to forget the key.** An earlier
883 // spelling of this comment said the value would be found "in the
884 // next fragment or the next word, where the structural cut and the
885 // follow-on rule reach it", and half of that was false: the
886 // follow-on rule does reach the next *word*, and nothing whatever
887 // reached the next *fragment*, because `redact_fragment`
888 // deliberately carries no follow-on. So `{"password":["hunter2"]}`,
889 // `{"password":{"v":"hunter2"}}` and `Password=;hunter2` — a
890 // credential key with its value one fragment away, which is what an
891 // array, a nested object and an empty pair all are — went out
892 // whole, with the key sitting in plain sight next to them.
893 //
894 // That is the failure this module warns about two comments down: a
895 // comment naming a case that does not demonstrate its own
896 // invariant. The claim is now true because [`Carry::Expecting`]
897 // implements it, and `the_fragment_carry_stops_where_the_value_does`
898 // holds both halves — that the claim is made, and that it is
899 // withdrawn where the value visibly ended.
900 if value.is_empty() {
901 names_a_credential = true;
902 continue;
903 }
904
905 // A quoted value whose closing quote is not in this fragment is a
906 // value the cut ran through the middle of: `{"password":"p&ss"}`
907 // reaches here as `password":"p`, and `ss` is the rest of the
908 // secret. Adding `;`, `<` and `>` to `STRUCTURAL` this round made
909 // three more characters able to do that, and punctuated passwords
910 // are ordinary.
911 let carry = if opens_an_unclosed_quote(lead, trail) {
912 Carry::Unclosed
913 } else {
914 Carry::None
915 };
916 return (format!("{key}{separator}{lead}{REDACTION}{trail}"), carry);
917 }
918 }
919
920 // Pass two: not a credential key, but the value may still be a path or a
921 // token: `runtime=/var/lib/runner-manager/…`. Applied to `:` as well as
922 // to `=`, because `:` is what compact JSON and a bare `key:value` use,
923 // and recursing for `=` alone is what let an encoded JIT configuration
924 // and a `runner_token:ghu_…` pair through verbatim.
925 for separator in ['=', ':'] {
926 if let Some((key, raw_value)) = core.split_once(separator) {
927 let (lead, value, trail) = split_wrappers(raw_value);
928 if value.is_empty() {
929 continue;
930 }
931 let redacted = redact_value(value);
932 // `as_sha256_digest` re-attaches its own `sha256:` label, so an
933 // already-labelled digest would come back doubled as
934 // `sha256:sha256:9f86d081884c…`. Dropping the redundant label
935 // keeps the caller's own key and separator, and leaves the digest
936 // truncated -- which the unrecursed `:` path never did, and which
937 // is worth having, because an HMAC-SHA256 signature has exactly a
938 // digest's shape and was previously printed in full.
939 if trim_key(key).eq_ignore_ascii_case("sha256")
940 && let Some(bare) = redacted.strip_prefix("sha256:")
941 {
942 return (format!("{key}{separator}{lead}{bare}{trail}"), Carry::None);
943 }
944 return (
945 format!("{key}{separator}{lead}{redacted}{trail}"),
946 Carry::None,
947 );
948 }
949 }
950
951 // A credential key with no value at all — either `password:` with nothing
952 // after it, or a bare `password` between a plist's tags. Both name a value
953 // that is somewhere else, and the caller is the only one who can see where.
954 let carry = if names_a_credential || is_credential_key(core) {
955 Carry::Expecting
956 } else {
957 Carry::None
958 };
959 (redact_value(core), carry)
960}
961
962/// Characters a URL scheme is made of: RFC 3986 allows a letter followed by
963/// letters, digits, `+`, `-` and `.`.
964fn is_scheme_byte(byte: u8) -> bool {
965 byte.is_ascii_alphanumeric() || matches!(byte, b'+' | b'-' | b'.')
966}
967
968/// Characters that cannot appear inside a URL, and therefore end one.
969///
970/// `\` is deliberately absent, even though it cannot appear in a URL either.
971/// The shape it would have been there for is a `Debug`-escaped body, which
972/// spells its quotes `\"` — and the quote already ends the URL. Making the
973/// backslash a terminator as well costs a real redaction: a Windows path used
974/// as a URL password, `https://x-access-token:C:\Users\…@github.com/o/r.git`,
975/// would then end its URL at the first `\`, which puts the `@` that identifies
976/// the userinfo *outside* the span, and [`redact_url`] echoes what it is given.
977/// Measured: with `\` a terminator, that line emits the path verbatim; without
978/// it, the userinfo is replaced as it should be.
979fn is_url_terminator(c: char) -> bool {
980 c.is_whitespace() || matches!(c, '"' | ',' | '{' | '}' | '[' | ']' | '<' | '>')
981}
982
983/// The same, plus the two [`STRUCTURAL`] characters that end a URL only *ahead
984/// of its query string*.
985///
986/// [`STRUCTURAL`] has nine characters and [`is_url_terminator`] recognises seven
987/// of them; `;` and `&` were missing. Because the URL branch runs ahead of the
988/// structural cut, a URL earlier in a word made [`split_url`] swallow
989/// everything to the next terminator — including the separator that would have
990/// cut the word — and [`redact_url`]'s terminal arm echoes what it is given. So
991/// `Server=https://vault.local/api;Password=hunter2` and
992/// `cb=https://a.com/x&access_token=ghu_…` went out whole: the fix that bounds
993/// a URL and the fix that cuts on `;` and `&` each worked alone and did not
994/// compose.
995///
996/// **Adding them to [`is_url_terminator`] outright is the obvious fix and the
997/// wrong one**, which is why there are two predicates rather than one extended
998/// list. `&` is what separates the parameters *inside* a query string, and
999/// [`redact_url`] replaces a query wholesale precisely because a token can be
1000/// in any parameter and this module does not guess which. Measured:
1001/// `https://a.com/cb?code=1&state=hunter2` goes from `?[redacted]` to
1002/// `?[redacted]&state=hunter2`. `;` is the same story — it is a legal query
1003/// separator too.
1004///
1005/// Ahead of the `?` there is no such conflict: a `;` or an `&` in an authority
1006/// or a path is not URL syntax this module needs to keep, and something else in
1007/// the word is much the likelier reading.
1008fn is_url_head_terminator(c: char) -> bool {
1009 is_url_terminator(c) || matches!(c, ';' | '&')
1010}
1011
1012/// Finds the first URL in a fragment and cuts it out of the text around it.
1013///
1014/// Returns the text before the URL, its scheme, the URL itself with the `://`
1015/// removed, and the text after it — or `None` when the fragment holds no URL.
1016///
1017/// **Both bounds are the point.** `split_once("://")` treated *everything*
1018/// before the separator as the scheme and everything after it as the URL, and
1019/// the terminal arm of [`redact_url`] echoes both verbatim — so a single URL
1020/// anywhere in a word put the whole of the rest of that word beyond every rule
1021/// below it. `documentation_url` is in essentially every GitHub REST error
1022/// body, so that was *any* such body logged alongside a credential:
1023///
1024/// ```text
1025/// {"documentation_url":"https://docs.github.com/rest","token":"ghu_…"}
1026/// ```
1027///
1028/// came out intact. The reverse order leaked for the mirror reason —
1029/// everything before the `://` became the "scheme" — and a nested object behind
1030/// a URL was missed even when the URL's own userinfo was caught, because the
1031/// miss and the catch happened in the same call. The only thing that saved the
1032/// shape at all was a `?` or `#` *inside* the URL, which made [`redact_url`]
1033/// replace the tail.
1034///
1035/// An empty scheme run means the `://` is not introducing a URL, and the
1036/// fragment is left to the rules below rather than handed over as a URL with no
1037/// scheme.
1038fn split_url(fragment: &str) -> Option<(&str, &str, &str, &str)> {
1039 let separator = fragment.find("://")?;
1040 let before = &fragment[..separator];
1041
1042 // Scheme characters are ASCII, so a byte count is a character boundary.
1043 let scheme_len = before
1044 .bytes()
1045 .rev()
1046 .take_while(|byte| is_scheme_byte(*byte))
1047 .count();
1048 if scheme_len == 0 {
1049 return None;
1050 }
1051 let (prefix, scheme) = before.split_at(before.len() - scheme_len);
1052
1053 let after = &fragment[separator + "://".len()..];
1054
1055 // Where the URL ends no matter what, and **the bound every other search
1056 // here is taken inside**. Searching the rest of the fragment first is a
1057 // correct answer computed quadratically: a body of *n* URLs would scan the
1058 // whole remaining text once per URL looking for a `?` that is not there,
1059 // which on the 860 KB regression case in
1060 // `a_large_message_does_not_overflow_the_stack` is 17 billion character
1061 // comparisons. That test is a guard against this module taking the process
1062 // down, and a redaction pass that never returns takes it down just as
1063 // effectively as an overflow does.
1064 let end = after.find(is_url_terminator).unwrap_or(after.len());
1065 let url = &after[..end];
1066
1067 // The head is the authority and path — everything ahead of the first `?` or
1068 // `#`. Only there do `;` and `&` end the URL; inside a query string they
1069 // are query syntax, and the query is `redact_url`'s to replace wholesale.
1070 let query = url.find(['?', '#']).unwrap_or(url.len());
1071 let end = url[..query].find(is_url_head_terminator).unwrap_or(end);
1072 let (url, remainder) = after.split_at(end);
1073
1074 Some((prefix, scheme, url, remainder))
1075}
1076
1077/// Redacts the three places a URL can carry a credential, keeping the rest.
1078///
1079/// `scheme` is everything before `://` and `rest` everything after it.
1080///
1081/// The **userinfo** is the one this module used to miss, and it is not an
1082/// exotic shape: `https://x-access-token:ghu_…@github.com/owner/repo.git` is
1083/// the canonical token-authenticated git remote, so it is what `e2` and `e3`
1084/// will have in hand when a clone or a download fails and they log the error
1085/// they were given. The old `://` branch returned before the token-prefix and
1086/// opaque-run rules could run, so that URL came out intact.
1087///
1088/// A **fragment** is stripped for the same reason a query string is: an OAuth
1089/// implicit-flow response puts the token after the `#`, and the fragment is
1090/// never load-bearing for diagnosing an HTTP call.
1091fn redact_url(scheme: &str, rest: &str) -> String {
1092 // The authority runs to the first `/`, `?` or `#`.
1093 let authority_end = rest.find(['/', '?', '#']).unwrap_or(rest.len());
1094 let (authority, tail) = rest.split_at(authority_end);
1095
1096 // `rsplit_once`, not `split_once`: a password may itself contain an `@`,
1097 // and the host is what follows the *last* one.
1098 let host = match authority.rsplit_once('@') {
1099 // Replaced rather than deleted. That the request carried credentials at
1100 // all is diagnostic — it is often the answer to "why did this 401?" —
1101 // and it is the credential, not its existence, that must not be here.
1102 Some((_userinfo, host)) => format!("{REDACTION}@{host}"),
1103 None => authority.to_string(),
1104 };
1105
1106 // Whichever of `?` and `#` comes first ends the diagnosable part; anything
1107 // after it is replaced wholesale rather than parsed, because a token can be
1108 // in any parameter and this module does not guess which.
1109 match tail.find(['?', '#']) {
1110 Some(cut) => {
1111 let (path, query) = tail.split_at(cut);
1112 let separator = &query[..1];
1113 format!(
1114 "{scheme}://{host}{}{separator}{REDACTION}",
1115 redact_path(path)
1116 )
1117 }
1118 None => format!("{scheme}://{host}{}", redact_path(tail)),
1119 }
1120}
1121
1122/// Applies the shape rules to a URL path, one segment at a time.
1123///
1124/// The path is the diagnosable part of a URL and stays that way: a segment is
1125/// judged on its own, and an ordinary one — `repos`, `owner`, `actions-runner-
1126/// linux-x64-2.330.0.tar.gz` — is not a secret and is not touched. What this
1127/// closes is that [`redact_url`] previously applied *no* rule to a path at all,
1128/// so `https://github.com/o/r/raw/ghu_…/f` was echoed whole while the identical
1129/// token one character to the left of the `/` would have been replaced. The
1130/// token-prefix rule is documented as a belt that catches a credential
1131/// *anywhere*, and a path was the one place it never ran.
1132///
1133/// Segment at a time rather than whole, because [`redact_value`] would
1134/// otherwise see the `/` and hand the whole path to [`looks_like_path`], which
1135/// is exactly the over-redaction the module documentation promises a full URL
1136/// escapes.
1137///
1138/// Worth knowing: [`OPAQUE_RUN_THRESHOLD`] is 40, and a git object name written
1139/// as hex is exactly 40 characters, so a `…/raw/<sha1>/f` URL loses its commit
1140/// to `[redacted]`. That is the module's standing trade — a less readable line
1141/// against a disclosed credential — and it is called out here because a commit
1142/// SHA is the one path segment somebody may miss.
1143fn redact_path(path: &str) -> String {
1144 let mut out = String::with_capacity(path.len());
1145 for (index, segment) in path.split('/').enumerate() {
1146 if index > 0 {
1147 out.push('/');
1148 }
1149 if !segment.is_empty() {
1150 out.push_str(&redact_value(segment));
1151 }
1152 }
1153 out
1154}
1155
1156/// The shape rules, applied to a bare value.
1157fn redact_value(value: &str) -> String {
1158 let lower = value.to_ascii_lowercase();
1159 if TOKEN_PREFIXES
1160 .iter()
1161 .any(|prefix| lower.starts_with(prefix))
1162 {
1163 return REDACTION.to_string();
1164 }
1165
1166 if looks_like_path(value) {
1167 return PATH_REDACTION.to_string();
1168 }
1169
1170 // A digest is not a secret, and `07-security.md` makes checksum
1171 // verification a security gate. The most useful thing `e2` can write when
1172 // that gate fails is expected-versus-actual, and until this carve-out
1173 // existed both sides came out as `[redacted]` — a gate that reports it
1174 // failed and refuses to say how.
1175 if let Some(digest) = as_sha256_digest(value) {
1176 return digest;
1177 }
1178
1179 if looks_like_jwt(value) {
1180 return REDACTION.to_string();
1181 }
1182
1183 if value.len() >= OPAQUE_RUN_THRESHOLD && value.chars().all(is_opaque_char) {
1184 return REDACTION.to_string();
1185 }
1186
1187 value.to_string()
1188}
1189
1190/// The length of a SHA-256 digest written as lowercase hex.
1191const SHA256_HEX_LEN: usize = 64;
1192
1193/// How much of a digest is shown.
1194///
1195/// 12 is the short-digest convention git and the OCI tooling use: 48 bits, far
1196/// more than enough to tell an expected digest from the one that was actually
1197/// computed, which is the only comparison a checksum failure needs. Truncating
1198/// is also what makes this carve-out safe to have at all — a 64-character
1199/// lowercase hex run is *usually* a digest, but an HMAC-SHA256 signature has
1200/// the same shape, and 12 of its 64 characters are of no use to anybody.
1201const DIGEST_PREFIX_LEN: usize = 12;
1202
1203/// Renders a value that is exactly a lowercase SHA-256 digest as a labelled
1204/// prefix, or `None` when it is not one.
1205///
1206/// Deliberately strict: exactly 64 characters, and lowercase only. An uppercase
1207/// or mixed-case run falls through to the opaque-run rule and is redacted,
1208/// because the narrower this exception is, the less there is to reason about.
1209fn as_sha256_digest(value: &str) -> Option<String> {
1210 let is_digest = value.len() == SHA256_HEX_LEN
1211 && value
1212 .chars()
1213 .all(|c| c.is_ascii_digit() || c.is_ascii_lowercase() && c.is_ascii_hexdigit());
1214
1215 is_digest.then(|| format!("sha256:{}…", &value[..DIGEST_PREFIX_LEN]))
1216}
1217
1218/// The most `.`-separated segments a JSON Web Token has: header, payload,
1219/// signature.
1220const JWT_SEGMENTS: usize = 3;
1221
1222/// Whether a value is a JSON Web Token.
1223///
1224/// The opaque-run rule cannot see one. [`is_opaque_char`] excludes `.`, and a
1225/// JWT is base64url runs joined by two of them, so a 100-character credential
1226/// arrives as three runs that are each under the threshold and prints
1227/// verbatim. `Authorization: Bearer <jwt>` is caught by the scheme-word rule
1228/// and a credential-keyed one by the key rule, so this only ever bit a token
1229/// logged bare or under a name nobody listed — which is what a GitHub App
1230/// installation assertion is when it reaches a log at all.
1231///
1232/// Narrow deliberately, because the obvious fix is the wrong one: adding `.`
1233/// to [`is_opaque_char`] would swallow every long dotted word there is —
1234/// package names, dated filenames, dotted identifiers. A JWT header is
1235/// base64url of `{"alg":…`, which always begins `eyJ`, and that is a
1236/// discriminator ordinary text does not have.
1237fn looks_like_jwt(value: &str) -> bool {
1238 if value.len() < OPAQUE_RUN_THRESHOLD || !value.starts_with("eyJ") {
1239 return false;
1240 }
1241
1242 let mut segments = 0usize;
1243 for segment in value.split('.') {
1244 segments += 1;
1245 if !segment.chars().all(is_opaque_char) {
1246 return false;
1247 }
1248 }
1249
1250 // Two segments as well as three: an unsigned token has an empty signature,
1251 // and the trailing `.` that would have made the third is trimmed as
1252 // wrapping punctuation before this is reached.
1253 (2..=JWT_SEGMENTS).contains(&segments)
1254}
1255
1256fn looks_like_path(value: &str) -> bool {
1257 let bytes = value.as_bytes();
1258
1259 // `C:\Users\…` and `C:/Users/…`.
1260 if bytes.len() >= 3
1261 && bytes[0].is_ascii_alphabetic()
1262 && bytes[1] == b':'
1263 && (bytes[2] == b'\\' || bytes[2] == b'/')
1264 {
1265 return true;
1266 }
1267
1268 // `\\server\share\…`.
1269 if value.starts_with("\\\\") {
1270 return true;
1271 }
1272
1273 // `~/…`.
1274 if value.starts_with("~/") || value.starts_with("~\\") {
1275 return true;
1276 }
1277
1278 // `/var/lib/…`. Two segments required, so a lone `/` and a bare `/tmp`
1279 // stay readable; see the module documentation for why a URL path is caught
1280 // by this too.
1281 if let Some(rest) = value.strip_prefix('/') {
1282 return rest.contains('/') && !rest.is_empty();
1283 }
1284
1285 false
1286}
1287
1288// ---------------------------------------------------------------------------
1289// The tracing layer
1290// ---------------------------------------------------------------------------
1291
1292/// The redacted fields recorded on a span, stashed in the span's extensions so
1293/// that an event inside the span can carry them.
1294#[derive(Debug, Clone)]
1295struct SpanFields(Map<String, Value>);
1296
1297/// Collects a `tracing` record into JSON, applying the allowlist and the
1298/// scrubber as it goes.
1299#[derive(Debug, Default)]
1300struct RedactingVisitor {
1301 fields: Map<String, Value>,
1302}
1303
1304impl RedactingVisitor {
1305 fn put_str(&mut self, name: &str, value: &str) {
1306 let rendered = if is_field_allowed(name) {
1307 redact(value)
1308 } else {
1309 REDACTION.to_string()
1310 };
1311 self.fields
1312 .insert(name.to_string(), Value::String(rendered));
1313 }
1314
1315 fn put_value(&mut self, name: &str, value: Value) {
1316 if is_field_allowed(name) {
1317 self.fields.insert(name.to_string(), value);
1318 } else {
1319 // Numbers and booleans go the same way as strings. A credential is
1320 // never an `i64`, but the rule that makes this sink trustworthy is
1321 // that it has *no* exception for a name nobody listed.
1322 self.fields
1323 .insert(name.to_string(), Value::String(REDACTION.to_string()));
1324 }
1325 }
1326}
1327
1328impl Visit for RedactingVisitor {
1329 fn record_str(&mut self, field: &Field, value: &str) {
1330 self.put_str(field.name(), value);
1331 }
1332
1333 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
1334 // The event message arrives here, as `format_args!` output.
1335 self.put_str(field.name(), &format!("{value:?}"));
1336 }
1337
1338 fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) {
1339 self.put_str(field.name(), &value.to_string());
1340 }
1341
1342 fn record_bool(&mut self, field: &Field, value: bool) {
1343 self.put_value(field.name(), Value::Bool(value));
1344 }
1345
1346 fn record_i64(&mut self, field: &Field, value: i64) {
1347 self.put_value(field.name(), Value::from(value));
1348 }
1349
1350 fn record_u64(&mut self, field: &Field, value: u64) {
1351 self.put_value(field.name(), Value::from(value));
1352 }
1353
1354 fn record_f64(&mut self, field: &Field, value: f64) {
1355 self.put_value(field.name(), Value::from(value));
1356 }
1357
1358 fn record_i128(&mut self, field: &Field, value: i128) {
1359 self.put_str(field.name(), &value.to_string());
1360 }
1361
1362 fn record_u128(&mut self, field: &Field, value: u128) {
1363 self.put_str(field.name(), &value.to_string());
1364 }
1365}
1366
1367/// A `tracing` layer that writes one redacted JSON object per event.
1368///
1369/// Written here rather than assembled from `tracing_subscriber::fmt` because
1370/// redaction has to happen *before* formatting, and a `tracing::Event`'s fields
1371/// cannot be rewritten for a downstream formatter to pick up. Owning the
1372/// formatting is what makes "unconditional" true: there is no path from an
1373/// event to the output that does not go through
1374/// [`RedactingVisitor`].
1375#[derive(Debug, Clone)]
1376pub struct RedactingLayer<W> {
1377 writer: W,
1378}
1379
1380impl<W> RedactingLayer<W> {
1381 /// Wraps a writer factory — a file appender, a capture buffer, or
1382 /// `std::io::stderr`.
1383 pub const fn new(writer: W) -> Self {
1384 Self { writer }
1385 }
1386}
1387
1388impl<S, W> Layer<S> for RedactingLayer<W>
1389where
1390 S: Subscriber + for<'a> LookupSpan<'a>,
1391 W: for<'a> tracing_subscriber::fmt::MakeWriter<'a> + 'static,
1392{
1393 fn on_new_span(
1394 &self,
1395 attrs: &tracing::span::Attributes<'_>,
1396 id: &tracing::span::Id,
1397 ctx: Context<'_, S>,
1398 ) {
1399 let mut visitor = RedactingVisitor::default();
1400 attrs.record(&mut visitor);
1401 if let Some(span) = ctx.span(id) {
1402 span.extensions_mut().insert(SpanFields(visitor.fields));
1403 }
1404 }
1405
1406 fn on_record(
1407 &self,
1408 id: &tracing::span::Id,
1409 values: &tracing::span::Record<'_>,
1410 ctx: Context<'_, S>,
1411 ) {
1412 let mut visitor = RedactingVisitor::default();
1413 values.record(&mut visitor);
1414 if let Some(span) = ctx.span(id) {
1415 let mut extensions = span.extensions_mut();
1416 if let Some(existing) = extensions.get_mut::<SpanFields>() {
1417 existing.0.extend(visitor.fields);
1418 } else {
1419 extensions.insert(SpanFields(visitor.fields));
1420 }
1421 }
1422 }
1423
1424 fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
1425 let mut visitor = RedactingVisitor::default();
1426 event.record(&mut visitor);
1427
1428 let mut record = Map::new();
1429 record.insert(
1430 "timestamp".to_string(),
1431 Value::String(chrono::Utc::now().to_rfc3339()),
1432 );
1433 record.insert(
1434 "level".to_string(),
1435 Value::String(event.metadata().level().to_string()),
1436 );
1437 // Named `logger` and not `target`: `target` is also a domain field —
1438 // the repository or organization a policy points at — and two different
1439 // things under one key is how a diagnostic becomes a puzzle.
1440 record.insert(
1441 "logger".to_string(),
1442 Value::String(event.metadata().target().to_string()),
1443 );
1444 record.insert("fields".to_string(), Value::Object(visitor.fields));
1445
1446 let spans: Vec<Value> = ctx
1447 .event_scope(event)
1448 .into_iter()
1449 .flat_map(tracing_subscriber::registry::Scope::from_root)
1450 .map(|span| {
1451 let mut entry = Map::new();
1452 entry.insert("name".to_string(), Value::String(span.name().to_string()));
1453 if let Some(fields) = span.extensions().get::<SpanFields>() {
1454 entry.insert("fields".to_string(), Value::Object(fields.0.clone()));
1455 }
1456 Value::Object(entry)
1457 })
1458 .collect();
1459 if !spans.is_empty() {
1460 record.insert("spans".to_string(), Value::Array(spans));
1461 }
1462
1463 let mut line = serde_json::to_string(&Value::Object(record)).unwrap_or_else(|_| {
1464 String::from(
1465 r#"{"level":"ERROR","fields":{"message":"a log record could not be encoded"}}"#,
1466 )
1467 });
1468 line.push('\n');
1469
1470 // A failed write to the diagnostics file must not take the agent down,
1471 // and must not be reported through `tracing` either — that would
1472 // recurse straight back into this method.
1473 let mut writer = self.writer.make_writer();
1474 let _ = writer.write_all(line.as_bytes());
1475 let _ = writer.flush();
1476 }
1477}
1478
1479// ---------------------------------------------------------------------------
1480// Installing the sink
1481// ---------------------------------------------------------------------------
1482
1483/// Whose diagnostics these are, and therefore which file they go in.
1484///
1485/// # Why the daemon does not share the operator's file
1486///
1487/// On the two Unixes a boot-mode registration runs the daemon as `root` while
1488/// the four application-data directories stay in the operator's profile —
1489/// `05-infrastructure.md` puts them there and `service install` records those
1490/// paths into the plist. So two accounts write into one `logs/` directory, and
1491/// the appender creates its file with the umask default, `0644`. Whichever
1492/// account opened today's file first owns it, and if that was `root` the
1493/// operator's own `runner-manager status` can no longer append to it.
1494///
1495/// That was not a degraded log. `tracing_appender::rolling::daily` **panics**
1496/// when it cannot open the file, so every CLI command on such a host died with
1497/// a backtrace before it did anything — reported on 0.1.17, on a host whose
1498/// daemon had rolled the file over at midnight as `root`:
1499///
1500/// ```text
1501/// thread 'main' panicked at rolling.rs:156:14:
1502/// initializing rolling file appender failed: InitError { context: "failed to
1503/// create log file", source: Os { code: 13, kind: PermissionDenied } }
1504/// ```
1505///
1506/// [`install`] no longer panics — see there — but not panicking would only have
1507/// turned a crash into an operator who never gets diagnostics again. The two
1508/// writers are separated instead, so neither can take the other's file: the
1509/// account that runs the daemon owns [`SERVICE_LOG_STEM`] and the operator owns
1510/// [`OPERATOR_LOG_STEM`], for as long as the registration lives.
1511#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]
1512pub enum LogRole {
1513 /// A command the operator ran, or a daemon they started in the foreground.
1514 Operator,
1515 /// The daemon a service manager started, which on a boot-mode host is a
1516 /// different account from the operator's.
1517 Service,
1518}
1519
1520/// The file stem [`LogRole::Operator`] writes.
1521pub const OPERATOR_LOG_STEM: &str = "runner-manager.log";
1522/// The file stem [`LogRole::Service`] writes, and what `service status`
1523/// reports as the daemon's log.
1524pub const SERVICE_LOG_STEM: &str = "runner-manager.service.log";
1525
1526impl LogRole {
1527 /// The file stem this role writes, before the appender's date suffix.
1528 #[must_use]
1529 pub const fn file_stem(self) -> &'static str {
1530 match self {
1531 Self::Operator => OPERATOR_LOG_STEM,
1532 Self::Service => SERVICE_LOG_STEM,
1533 }
1534 }
1535}
1536
1537impl fmt::Display for LogRole {
1538 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1539 f.write_str(match self {
1540 Self::Operator => "operator",
1541 Self::Service => "service",
1542 })
1543 }
1544}
1545
1546/// The sink could not be installed.
1547#[derive(Debug, thiserror::Error)]
1548pub enum LoggingError {
1549 /// The application-data directories could not be created.
1550 ///
1551 /// Carries a [`crate::paths::PathsError`] rather than a bare
1552 /// [`std::io::Error`] because [`install`] creates `logs/` through
1553 /// [`crate::paths::AppPaths::create_all`], which is what applies the `0700`
1554 /// restriction; the source therefore names whichever of the four
1555 /// directories actually failed, and that need not be `logs/`.
1556 #[error("cannot create the log directory {}: {source}", directory.display())]
1557 Directory {
1558 /// The diagnostics directory [`install`] was asked to write into.
1559 directory: PathBuf,
1560 /// The underlying error.
1561 #[source]
1562 source: crate::paths::PathsError,
1563 },
1564
1565 /// No diagnostics file in `logs/` could be opened for appending.
1566 ///
1567 /// Both stems are named because [`install`] tries two — the role's own, and
1568 /// then one qualified by the account — and an operator who is told only
1569 /// about the second would go looking for a file this process never reached
1570 /// for first.
1571 ///
1572 /// The two attempts are composed into one string rather than carried as
1573 /// four fields. As four this variant reached 128 bytes on Windows — where
1574 /// `PathBuf` is wider than on the Unixes — and tripped
1575 /// `clippy::result_large_err`, which is a lint about every *success* path
1576 /// paying for the size of a failure. The message is the same either way,
1577 /// and only this error is ever built.
1578 #[error("cannot open a diagnostics file in {}: {attempts}", directory.display())]
1579 Appender {
1580 /// The diagnostics directory.
1581 directory: PathBuf,
1582 /// Both stems that were tried, and why each was refused.
1583 attempts: String,
1584 },
1585
1586 /// A global subscriber was already installed.
1587 #[error("a tracing subscriber is already installed for this process: {message}")]
1588 AlreadyInstalled {
1589 /// What `tracing_subscriber` said.
1590 message: String,
1591 },
1592}
1593
1594/// Keeps the background log-writing thread alive.
1595///
1596/// Dropping it flushes and stops that thread, so the value must be held for as
1597/// long as the program expects its diagnostics to be written. Losing it is a
1598/// silent, total loss of logs, which is why it is `#[must_use]`.
1599#[must_use = "dropping the guard stops the log writer and silently discards later diagnostics"]
1600#[derive(Debug)]
1601pub struct LoggingGuard {
1602 _worker: tracing_appender::non_blocking::WorkerGuard,
1603}
1604
1605/// Installs the redacting sink as this process's global subscriber, writing
1606/// daily-rotating files into `logs/`.
1607///
1608/// `role` decides the file, for the reason [`LogRole`] gives. `default_filter`
1609/// applies when `RUST_LOG` is unset or unparseable.
1610///
1611/// # Errors
1612///
1613/// [`LoggingError::Directory`], [`LoggingError::Appender`] and
1614/// [`LoggingError::AlreadyInstalled`]. **None of them is fatal to the caller**,
1615/// and the CLI treats all three as a warning: a `host show` that refused to
1616/// print a capacity because a log file could not be opened would be a worse
1617/// failure than the one it was reporting.
1618pub fn install(
1619 paths: &crate::paths::AppPaths,
1620 role: LogRole,
1621 default_filter: &str,
1622) -> Result<LoggingGuard, LoggingError> {
1623 use tracing_subscriber::layer::SubscriberExt as _;
1624 use tracing_subscriber::util::SubscriberInitExt as _;
1625
1626 // `AppPaths::create_all`, not `create_dir_all`. The claim `create_all`
1627 // documents — that a diagnostics file is not readable by other local
1628 // accounts — is only true if `logs/` is created at `0700`, and this is the
1629 // path a running daemon actually takes. Creating the directory here with a
1630 // bare `create_dir_all` left it at the umask default whenever `install`
1631 // won the race to create it, and `tracing_appender` then wrote 0644 files
1632 // into it: the invariant held in the test that asserts it and nowhere else.
1633 let directory = paths.logs_dir().to_path_buf();
1634 paths
1635 .create_all()
1636 .map_err(|source| LoggingError::Directory {
1637 directory: directory.clone(),
1638 source,
1639 })?;
1640
1641 let appender = open_appender(&directory, role)?;
1642 let (writer, worker) = tracing_appender::non_blocking(appender);
1643
1644 let filter = tracing_subscriber::EnvFilter::try_from_default_env()
1645 .unwrap_or_else(|_| tracing_subscriber::EnvFilter::new(default_filter));
1646
1647 tracing_subscriber::registry()
1648 .with(filter)
1649 .with(RedactingLayer::new(writer))
1650 .try_init()
1651 .map_err(|error| LoggingError::AlreadyInstalled {
1652 message: error.to_string(),
1653 })?;
1654
1655 Ok(LoggingGuard { _worker: worker })
1656}
1657
1658/// Opens today's diagnostics file, falling back to one only this account can
1659/// have created.
1660///
1661/// # Why there is a second attempt at all
1662///
1663/// [`LogRole`] keeps the daemon and the operator apart, which is enough on a
1664/// host where nothing else ever writes here. Two things still put a file the
1665/// caller cannot append to under the stem it wants:
1666///
1667/// 1. **A privileged command.** Signing in to the machine-scoped store is
1668/// `sudo runner-manager auth login`, and that run writes the *operator's*
1669/// stem as `root`. Every unprivileged command for the rest of that day then
1670/// finds a `root`-owned file under it.
1671/// 2. **A host upgraded into this change.** Files written before the roles were
1672/// split are all under [`OPERATOR_LOG_STEM`], and on a boot-mode host the
1673/// ones from the last few days belong to `root`.
1674///
1675/// Neither is worth losing diagnostics over, and neither can be repaired from
1676/// inside an unprivileged process — it may not chown the file, may not change
1677/// its mode, and must not delete an existing log. So it writes beside it, under
1678/// a stem carrying this account's identity, which no other account will choose.
1679///
1680/// The fallback is deliberately *not* the first choice. A file named after
1681/// whoever happened to open it first is a file an operator has to go looking
1682/// for; the plain stem stays the plain stem, and the qualified one appears only
1683/// on a host that has the collision.
1684fn open_appender(
1685 directory: &Path,
1686 role: LogRole,
1687) -> Result<tracing_appender::rolling::RollingFileAppender, LoggingError> {
1688 let stem = role.file_stem();
1689 let first = match build_appender(directory, stem) {
1690 Ok(appender) => return Ok(appender),
1691 Err(error) => error,
1692 };
1693
1694 let qualified = account_qualified_stem(stem);
1695 match build_appender(directory, &qualified) {
1696 Ok(appender) => Ok(appender),
1697 // Both stems are named. An operator told only about the second would go
1698 // looking for a file this process never reached for first.
1699 Err(second) => Err(LoggingError::Appender {
1700 directory: directory.to_path_buf(),
1701 attempts: format!(
1702 "neither {stem}.<date> ({first}) nor {qualified}.<date> ({second}) could be \
1703 appended to"
1704 ),
1705 }),
1706 }
1707}
1708
1709/// One attempt, through the constructor that **returns** its failure.
1710///
1711/// `tracing_appender::rolling::daily` is the same thing with an `.expect` on
1712/// the end, and that `.expect` is a panic in the middle of an operator's `status`
1713/// command. The whole reason this function exists is that the builder hands the
1714/// error back instead.
1715fn build_appender(
1716 directory: &Path,
1717 stem: &str,
1718) -> Result<tracing_appender::rolling::RollingFileAppender, String> {
1719 tracing_appender::rolling::RollingFileAppender::builder()
1720 .rotation(tracing_appender::rolling::Rotation::DAILY)
1721 .filename_prefix(stem)
1722 .build(directory)
1723 .map_err(|error| error.to_string())
1724}
1725
1726/// `runner-manager.log` becomes `runner-manager.<account>.log`.
1727///
1728/// The stem carries its own `.log`, so the account goes before it rather than
1729/// after: the appender appends `.<date>`, and `runner-manager.log.uid-501` would
1730/// read as a rotated file rather than as another account's.
1731fn account_qualified_stem(stem: &str) -> String {
1732 let account = account_tag();
1733 match stem.rsplit_once('.') {
1734 Some((head, tail)) => format!("{head}.{account}.{tail}"),
1735 None => format!("{stem}.{account}"),
1736 }
1737}
1738
1739/// Something stable, filename-safe, and different for every local account.
1740///
1741/// The numeric effective user id rather than a name: it needs no lookup, cannot
1742/// contain a path separator, and is the identity the filesystem actually
1743/// compared when it refused the open.
1744#[cfg(unix)]
1745fn account_tag() -> String {
1746 // SAFETY: `geteuid` takes no argument, touches no memory this process owns,
1747 // and is documented never to fail.
1748 let uid = unsafe { libc::geteuid() };
1749 format!("uid-{uid}")
1750}
1751
1752/// As the Unix half, from the one identity Windows exposes without a lookup.
1753///
1754/// Sanitized rather than trusted: this becomes a file name, and `USERNAME` is
1755/// an ordinary environment variable that a caller may set to anything at all,
1756/// including something holding a path separator.
1757#[cfg(windows)]
1758fn account_tag() -> String {
1759 let raw = std::env::var("USERNAME").unwrap_or_default();
1760 let safe: String = raw
1761 .chars()
1762 .filter(|c| c.is_ascii_alphanumeric() || *c == '-' || *c == '_')
1763 .take(32)
1764 .collect();
1765 if safe.is_empty() {
1766 "other-account".to_string()
1767 } else {
1768 format!("user-{safe}")
1769 }
1770}
1771
1772#[cfg(test)]
1773mod tests {
1774 use super::*;
1775
1776 use std::sync::{Arc, Mutex};
1777
1778 use tracing_subscriber::layer::SubscriberExt as _;
1779
1780 // -----------------------------------------------------------------------
1781 // Capturing what the sink actually wrote
1782 // -----------------------------------------------------------------------
1783
1784 #[derive(Clone, Default)]
1785 struct Capture(Arc<Mutex<Vec<u8>>>);
1786
1787 impl Capture {
1788 fn text(&self) -> String {
1789 String::from_utf8_lossy(&self.0.lock().expect("not poisoned")).into_owned()
1790 }
1791 }
1792
1793 struct CaptureWriter(Arc<Mutex<Vec<u8>>>);
1794
1795 impl Write for CaptureWriter {
1796 fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
1797 self.0.lock().expect("not poisoned").extend_from_slice(buf);
1798 Ok(buf.len())
1799 }
1800
1801 fn flush(&mut self) -> std::io::Result<()> {
1802 Ok(())
1803 }
1804 }
1805
1806 impl<'a> tracing_subscriber::fmt::MakeWriter<'a> for Capture {
1807 type Writer = CaptureWriter;
1808
1809 fn make_writer(&'a self) -> Self::Writer {
1810 CaptureWriter(Arc::clone(&self.0))
1811 }
1812 }
1813
1814 /// A sink with the same plumbing and no redaction at all.
1815 ///
1816 /// Exists so that `the_scan_catches_a_sink_that_does_not_redact` can prove
1817 /// the secret-injection scan below is capable of failing. Without it, a scan
1818 /// that found nothing would be indistinguishable from a scan that looked
1819 /// nowhere.
1820 #[derive(Debug, Clone)]
1821 struct PassthroughLayer<W>(W);
1822
1823 #[derive(Default)]
1824 struct PassthroughVisitor(Map<String, Value>);
1825
1826 impl Visit for PassthroughVisitor {
1827 fn record_str(&mut self, field: &Field, value: &str) {
1828 self.0
1829 .insert(field.name().to_string(), Value::String(value.to_string()));
1830 }
1831
1832 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
1833 self.0.insert(
1834 field.name().to_string(),
1835 Value::String(format!("{value:?}")),
1836 );
1837 }
1838 }
1839
1840 impl<S, W> Layer<S> for PassthroughLayer<W>
1841 where
1842 S: Subscriber + for<'a> LookupSpan<'a>,
1843 W: for<'a> tracing_subscriber::fmt::MakeWriter<'a> + 'static,
1844 {
1845 fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
1846 let mut visitor = PassthroughVisitor::default();
1847 event.record(&mut visitor);
1848 let mut line = serde_json::to_string(&Value::Object(visitor.0)).unwrap_or_default();
1849 line.push('\n');
1850 let _ = self.0.make_writer().write_all(line.as_bytes());
1851 }
1852 }
1853
1854 // -----------------------------------------------------------------------
1855 // The secret-injection log scan (`07-security.md`, security gate)
1856 // -----------------------------------------------------------------------
1857
1858 /// A user access token, in GitHub's user-to-server format.
1859 const USER_TOKEN: &str = "ghu_16C7e42F292c6912E7710c838347Ae178B4a";
1860 /// An installation-style token, to prove the prefix rule is not one-off.
1861 const SERVER_TOKEN: &str = "ghs_1CGGYnBAtn5ov3M0aTHhP7l3ZKuMhIB3pnPd";
1862 /// A fine-grained personal access token.
1863 const FINE_GRAINED: &str =
1864 "github_pat_11ABCDEFG0abcdefghijkl_ZYXWVUTSRQPONMLKJIHGFEDCBA9876543210zyxwv";
1865 /// Stands in for an encoded JIT configuration: base64, and long.
1866 const JIT_BLOB: &str = "eyJhZ2VudE5hbWUiOiJydW5uZXItbWFuYWdlciIsImVuY29kZWQiOiJhYmNkZWZnaGlqa2xtbm9wcXJzdHV2d3h5ejAxMjM0NTY3ODkrLz09In0=";
1867 /// A workspace path, which `07-security.md` also requires redacted.
1868 const WORKSPACE: &str = "/var/lib/runner-manager/runtime/9f2c/attempt-1";
1869 /// The same, on the platform the persona is least likely to be using but
1870 /// the CI matrix definitely is.
1871 const WINDOWS_WORKSPACE: &str = r"C:\Users\operator\AppData\Local\runner-manager\runtime\9f2c";
1872 /// A GitHub App installation assertion: a JSON Web Token.
1873 ///
1874 /// Its two `.` separators are the point. `is_opaque_char` excludes `.`, so
1875 /// the opaque-run rule sees three short runs rather than one long one, and
1876 /// every other secret here is caught by that rule when it stands alone.
1877 const JWT: &str = "eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.\
1878 eyJpc3MiOiIxMjM0NTYiLCJpYXQiOjE3MDAwMDAwMDAsImV4cCI6MTcwMDAwMDYwMH0.\
1879 c2lnbmF0dXJlLXRoYXQtaXMtb3BhcXVlLWFuZC1sb25nLWVub3VnaC10by1tYXR0ZXI";
1880
1881 /// An error whose `Debug` carries the HTTP body it was given.
1882 ///
1883 /// This is the shape `d2`'s secret store and `d3`'s installer will hand to
1884 /// `tracing::error!(reason = ?err)`, and it is not the same shape as any of
1885 /// the JSON above: `Debug` on a `String` escapes the quotes inside it, so
1886 /// the keys arrive spelled `\"password\"` rather than `"password"`.
1887 #[derive(Debug)]
1888 struct StoreError {
1889 body: String,
1890 }
1891
1892 fn secrets() -> Vec<&'static str> {
1893 vec![
1894 USER_TOKEN,
1895 SERVER_TOKEN,
1896 FINE_GRAINED,
1897 JIT_BLOB,
1898 JWT,
1899 WORKSPACE,
1900 WINDOWS_WORKSPACE,
1901 ]
1902 }
1903
1904 /// Routes every secret through `sink` in every shape a caller might use,
1905 /// and reports the first one that came out the other side.
1906 ///
1907 /// A helper returning `Result` rather than a test body, because the same
1908 /// injection has to be run against a deliberately non-redacting sink to
1909 /// show that it is capable of finding anything at all.
1910 fn scan_for_leaks<L>(layer: L, capture: &Capture) -> Result<String, String>
1911 where
1912 L: Layer<tracing_subscriber::Registry> + Send + Sync + 'static,
1913 {
1914 let subscriber = tracing_subscriber::registry().with(layer);
1915
1916 tracing::subscriber::with_default(subscriber, || {
1917 for secret in secrets() {
1918 // 1. In the message body, which is the one field that must be
1919 // allowed and therefore cannot be protected by the allowlist.
1920 tracing::info!("starting runner with {secret}");
1921
1922 // 2. As a credential header in the message body, scheme and all.
1923 tracing::info!("request failed; Authorization: Bearer {secret}");
1924 tracing::warn!("retrying with x-api-key={secret}");
1925
1926 // 3. In a field nobody listed — the case that must be safe with
1927 // no edit to this file.
1928 tracing::info!(runner_token = %secret, "registered");
1929
1930 // 4. In a field that *is* listed, which is where the allowlist
1931 // alone would not save anything.
1932 tracing::info!(outcome = %secret, event = "started", "registered");
1933 tracing::info!(message = %secret, "ignored");
1934
1935 // 5. Through `Debug` rather than `Display`.
1936 tracing::info!(?secret, "debug shaped");
1937
1938 // 6. Embedded in a structured value rather than standing
1939 // alone. Every shape above presents the secret as its
1940 // own whitespace-delimited word, which is the one shape
1941 // the opaque-run rule catches for free -- so the scan
1942 // could pass while the sink leaked anything embedded.
1943 // Compact JSON is what `serde_json::to_string` emits and
1944 // what an HTTP error body arrives as, and it was emitted
1945 // verbatim: `redact_core` recursed into the value for
1946 // `=` only, and the JSON quote left the key spelled
1947 // `encoded_jit_config"`, which is not on CREDENTIAL_KEYS.
1948 for key in ["encoded_jit_config", "runner_token", "pat"] {
1949 tracing::error!("registration failed: {{\"{key}\":\"{secret}\"}}");
1950 tracing::error!("registration failed: {{ \"{key}\": \"{secret}\" }}");
1951 tracing::error!("registration failed: {key}:{secret}");
1952 }
1953
1954 // 7. An `Authorization` header value, in the same three
1955 // embedded shapes.
1956 tracing::error!("response: {{\"authorization\":\"Bearer {secret}\"}}");
1957 tracing::error!("response: {{ \"authorization\": \"Bearer {secret}\" }}");
1958 tracing::error!("response: authorization:Bearer {secret}");
1959
1960 // 9. A compact object with **more than one field**, the
1961 // credential key second. Shape 6 above differs from this by
1962 // field order and by nothing else, and `serde_json::to_string`
1963 // is what chooses the order -- so shape 6 could pass while an
1964 // error body from a struct with two fields leaked. The rules
1965 // split a word once, on the first separator they find, so
1966 // only `runner_id` was ever examined.
1967 for key in ["encoded_jit_config", "runner_token", "access_token"] {
1968 tracing::error!(
1969 "registration failed: {{\"runner_id\":42,\"{key}\":\"{secret}\"}}"
1970 );
1971 tracing::error!(
1972 "registration failed: {{\"status\":422,\"message\":\"bad\",\"{key}\":\"{secret}\"}}"
1973 );
1974 // The spaced spelling of the same thing, which was already
1975 // safe -- by accident, because the value is its own word.
1976 tracing::error!(
1977 "registration failed: {{ \"runner_id\": 42, \"{key}\": \"{secret}\" }}"
1978 );
1979 }
1980
1981 // 10. Nested, one level and two. The value recursion goes to
1982 // `redact_value`, which is a leaf and never re-enters
1983 // `redact_core`, so an object inside an object was emitted
1984 // whole.
1985 tracing::error!("response: {{\"body\":{{\"runner_token\":\"{secret}\"}}}}");
1986 tracing::error!(
1987 "response: {{\"error\":{{\"status\":422,\"body\":{{\"encoded_jit_config\":\"{secret}\"}}}}}}"
1988 );
1989
1990 // 11. A form-encoded body with the credential parameter second.
1991 // `&` was not a separator this module knew, so the whole
1992 // body was one word and only `scope` was ever judged.
1993 tracing::error!("token exchange failed: scope=repo&access_token={secret}");
1994 tracing::error!(
1995 "token exchange failed: grant_type=refresh&refresh_token={secret}&scope=repo"
1996 );
1997
1998 // 12. Backslash-escaped JSON, through `Debug` rather than
1999 // `Display`. Shape 5 is also `Debug`, but it puts the
2000 // secret on an *unlisted* field, which is dropped wholesale
2001 // -- so the `Debug` lens and the compact-JSON lens were both
2002 // here and had never been crossed. `reason` is allowed, so
2003 // this one reaches the scrubber, with its keys spelled
2004 // `\"runner_token\"`.
2005 let failure = StoreError {
2006 body: format!("{{\"runner_token\":\"{secret}\"}}"),
2007 };
2008 tracing::error!(reason = ?failure, "the secret store rejected the request");
2009
2010 // 13. A URL earlier in the same word. `redact_core` split on the
2011 // first `://` and handed everything before it to
2012 // `redact_url` as a "scheme" and everything after it as
2013 // the URL -- and the terminal arm of `redact_url` echoes
2014 // both verbatim. So one URL anywhere in a word put the
2015 // whole of the rest of that word beyond every rule below.
2016 // `documentation_url` is in essentially every GitHub REST
2017 // error body, which makes that "any error body logged
2018 // alongside a credential".
2019 tracing::error!(
2020 "api failed: {{\"message\":\"Bad credentials\",\"documentation_url\":\"https://docs.github.com/rest\",\"token\":\"{secret}\"}}"
2021 );
2022 // The reverse order leaked for the mirror reason: everything
2023 // before the `://` became the scheme, and was echoed.
2024 tracing::error!(
2025 "api failed: {{\"token\":\"{secret}\",\"documentation_url\":\"https://docs.github.com/rest\"}}"
2026 );
2027 // A nested object behind a URL, which is the shape a clone
2028 // failure arrives in.
2029 tracing::error!(
2030 "clone failed: {{\"remote\":\"https://github.com/o/r.git\",\"body\":{{\"password\":\"{secret}\"}}}}"
2031 );
2032
2033 // 14. A value with no key of its own: an array element. The
2034 // structural cut recursed on the *raw* fragment, and the
2035 // terminal fallback then handed it to `redact_value` with
2036 // its quote still attached -- so `"ghu_…` failed
2037 // `starts_with("ghu_")`, failed `is_opaque_char` on the
2038 // quote, failed the `eyJ` test, and failed
2039 // `looks_like_path`. This is shape 9's defect one step
2040 // down: "only the first pair is examined" became "a value
2041 // with no key of its own is never examined", and it
2042 // survived because there was no array among the twelve
2043 // shapes above.
2044 tracing::error!("registration failed: {{\"tokens\":[\"{secret}\",\"x\"]}}");
2045 tracing::error!("registration failed: {{\"tokens\":[\"x\",\"{secret}\"]}}");
2046 tracing::error!("registration failed: [\"x\",\"{secret}\"]");
2047 tracing::error!("registration failed: [{{\"id\":1}},[\"{secret}\"]]");
2048 let listed = StoreError {
2049 body: format!("{{\"tokens\":[\"x\",\"{secret}\"]}}"),
2050 };
2051 tracing::error!(reason = ?listed, "the secret store rejected the list");
2052
2053 // 15. `;` as the separator. It is in `WRAPPERS`, so it was
2054 // recognised as punctuation, and it was not in
2055 // `STRUCTURAL`, so it never cut a word. It is what
2056 // separates the pairs of a Windows connection string, of a
2057 // credential string, and of a cookie header written
2058 // without a space -- `d2`'s territory exactly.
2059 tracing::error!("store rejected: Server=host;Database=x;Password={secret};");
2060 tracing::error!("store rejected: user=operator;password={secret}");
2061 tracing::error!("store rejected: theme=dark;session={secret}");
2062
2063 // 16. Wrapped in an element rather than in a quote.
2064 // `split_wrappers` strips only the *outermost* `<` and
2065 // `>`, so `<string>…</string>` arrived as
2066 // `string>…</string`, which matches no rule at all. `d3`'s
2067 // installers handle launchd plists, which is where this
2068 // shape comes from.
2069 tracing::error!("plist rejected: <string>{secret}</string>");
2070 tracing::error!("plist rejected: <key>token</key><string>{secret}</string>");
2071
2072 // 17. A `;` or an `&` *after a URL in the same word*. This is
2073 // shape 15 and shape 11 with one thing changed: a URL
2074 // earlier in the word. `STRUCTURAL` has nine characters and
2075 // `is_url_terminator` recognised seven of them -- `;` and
2076 // `&` were missing -- and the URL branch runs *ahead* of
2077 // the structural cut. So `split_url` swallowed everything
2078 // to the next terminator, including the separator that
2079 // would have cut the word, and `redact_url`'s terminal arm
2080 // echoed it verbatim.
2081 //
2082 // The L3 fix (bounding the URL) and the L1 fix (cutting on
2083 // `;` and `&`) each work alone and did not compose: this
2084 // commit added `;` to `STRUCTURAL` *for connection strings*
2085 // while leaving the path a URL opens straight through it.
2086 // A connection string whose `Server=` is a URL is exactly
2087 // `d2`'s shape, and a systemd `Environment=` line is
2088 // `d3`'s.
2089 tracing::error!(
2090 "store rejected: Server=https://vault.local/api;Password={secret};"
2091 );
2092 tracing::error!("keychain error: url=https://kc.local;secret={secret}");
2093 tracing::error!("unit rejected: Environment=API=https://a.com/v1;TOKEN={secret}");
2094 tracing::error!("token exchange failed: cb=https://a.com/x&access_token={secret}");
2095 tracing::error!(
2096 "dsn rejected: dsn=https://sentry.local/1;password={secret};user=x"
2097 );
2098 tracing::error!(
2099 "callback failed: redirect=https://a.com/cb&state=1&access_token={secret}"
2100 );
2101 let routed = StoreError {
2102 body: format!("Server=https://vault.local/api;Password={secret};"),
2103 };
2104 tracing::error!(reason = ?routed, "the secret store rejected the connection string");
2105
2106 // 18. A credential key whose value is not in its own fragment.
2107 // The empty-value skip is right, but its justification --
2108 // "the value is in the next fragment, where the structural
2109 // cut reaches it" -- was false: `redact_fragment` carried
2110 // nothing across the cut, so nothing ever reached it. An
2111 // array, a nested object, an empty pair and a plist
2112 // key/value pair are four spellings of the same gap.
2113 tracing::error!("store rejected: {{\"password\":[\"{secret}\"]}}");
2114 tracing::error!("store rejected: {{\"password\":{{\"v\":\"{secret}\"}}}}");
2115 tracing::error!("store rejected: Password=;{secret}");
2116 tracing::error!("plist rejected: <key>password</key><string>{secret}</string>");
2117
2118 // 19. A structural character *inside* a credential value. `,`
2119 // and `&` could already split a secret; this commit added
2120 // `;`, `<` and `>`, so each of those became a new character
2121 // that can cut a punctuated password in half and leave the
2122 // tail standing.
2123 tracing::error!("store rejected: {{\"password\":\"a<{secret}>b\"}}");
2124 tracing::error!("store rejected: {{\"password\":\"a&{secret},b\"}}");
2125
2126 // 20. A secret in a URL *path*. `redact_url` applies no shape
2127 // rule to the path at all, so a token that reaches one is
2128 // echoed whole -- and the token-prefix rule is documented
2129 // as a belt that catches a credential anywhere.
2130 //
2131 // The two workspace paths are excluded, and the exclusion
2132 // is a real limitation rather than a convenience. A path is
2133 // judged one segment at a time, because judging the whole
2134 // of a URL path with `looks_like_path` would redact every
2135 // URL with two segments in it -- which is the
2136 // over-redaction the module documentation explicitly
2137 // promises a full URL escapes. A filesystem path pasted
2138 // into a URL path is therefore indistinguishable from an
2139 // ordinary deep URL path: `/var/lib/…` and `/repos/o/r/…`
2140 // are the same shape, segment by segment. A *credential* in
2141 // a path is caught, because a credential has a shape of its
2142 // own; a path in a path is not.
2143 if !looks_like_path(secret) {
2144 tracing::error!("download failed: https://github.com/o/r/raw/{secret}/f");
2145 tracing::error!("download failed: https://github.com/o/r/raw/{secret}");
2146 }
2147
2148 // 8. Carried on a span rather than on the event.
2149 let span = tracing::info_span!("attempt", jit_config = %secret);
2150 let _entered = span.enter();
2151 tracing::info!(event = "inside_span", "in a span");
2152 }
2153 });
2154
2155 let output = capture.text();
2156 for secret in secrets() {
2157 for needle in needles(secret) {
2158 if output.contains(&needle) {
2159 return Err(format!(
2160 "the sink emitted a secret verbatim: {secret}\n\
2161 (found as: {needle})\n--- output ---\n{output}"
2162 ));
2163 }
2164 }
2165 }
2166 Ok(output)
2167 }
2168
2169 /// Every spelling a secret can have in the sink's output.
2170 ///
2171 /// The sink writes JSON, so a secret containing a character `serde_json`
2172 /// escapes never appears in the output as it was written. `WINDOWS_WORKSPACE`
2173 /// is a raw string with single backslashes and is emitted with doubled ones,
2174 /// so scanning for the literal could not have matched it — not even against
2175 /// `PassthroughLayer`, which redacts nothing at all. The path really is
2176 /// redacted, so this was a hole in the coverage rather than a leak, but a
2177 /// needle that cannot match is a check that cannot fail.
2178 fn needles(secret: &str) -> Vec<String> {
2179 // Strip the quotes `to_string` adds; what is left is the text exactly
2180 // as it appears inside a JSON string literal.
2181 let escape = |text: &str| {
2182 let json = serde_json::to_string(text).expect("a string is serialisable");
2183 json[1..json.len() - 1].to_string()
2184 };
2185
2186 let once = escape(secret);
2187 // Twice, because a secret can be escaped twice on the way out, and
2188 // shape 12 is where that happens: `Debug` on a `String` escapes the
2189 // quotes *and* the backslashes inside it, and the sink then
2190 // JSON-encodes what `Debug` produced. A Windows path arrives in that
2191 // line with four backslashes where the secret has one, so the
2192 // once-escaped needle cannot match it there -- not even against
2193 // `PassthroughLayer`, which redacts nothing at all. That cell of the
2194 // matrix was a check incapable of failing, which is the same defect
2195 // this helper was written to fix one level down.
2196 let twice = escape(&once);
2197
2198 let mut spellings = vec![secret.to_string(), once, twice];
2199 // Consecutive-only is enough: each level of escaping is a superset of
2200 // the last, so equal spellings are always adjacent.
2201 spellings.dedup();
2202 spellings
2203 }
2204
2205 #[test]
2206 fn the_scan_looks_for_a_needle_that_can_actually_occur() {
2207 // Guards the helper above: if `needles` ever stops producing the
2208 // JSON-escaped spelling, the Windows workspace silently stops being
2209 // scanned for and every assertion about it becomes vacuous.
2210 let windows = needles(WINDOWS_WORKSPACE);
2211 assert_eq!(
2212 windows.len(),
2213 3,
2214 "a backslash path has three spellings, one per level of escaping it \
2215 can pass through on the way out: {windows:?}"
2216 );
2217 assert!(
2218 windows[1].contains(r"\\Users\\operator"),
2219 "the once-escaped spelling is what an ordinary JSON line contains: {windows:?}"
2220 );
2221 assert!(
2222 windows[2].contains(r"\\\\Users\\\\operator"),
2223 "the twice-escaped spelling is what a Debug rendering inside a JSON \
2224 line contains: {windows:?}"
2225 );
2226
2227 // The third spelling is not hypothetical: it is exactly what the sink
2228 // writes for shape 12, and without it that cell of the scan was a
2229 // check that could not fail.
2230 let shape_twelve = serde_json::to_string(&Value::String(format!(
2231 "{:?}",
2232 StoreError {
2233 body: format!("{{\"runner_token\":\"{WINDOWS_WORKSPACE}\"}}"),
2234 }
2235 )))
2236 .expect("serialisable");
2237 assert!(
2238 shape_twelve.contains(&windows[2]),
2239 "the twice-escaped needle must be findable in what shape 12 emits: {shape_twelve}"
2240 );
2241 assert!(
2242 !shape_twelve.contains(&windows[1]),
2243 "and the once-escaped one must not be, or the gap was never there: {shape_twelve}"
2244 );
2245
2246 // Confirms the premise: the raw spelling genuinely cannot occur in the
2247 // sink's output, which is why scanning only for it proved nothing.
2248 let rendered = serde_json::to_string(&Value::String(WINDOWS_WORKSPACE.to_string()))
2249 .expect("serialisable");
2250 assert!(
2251 !rendered.contains(WINDOWS_WORKSPACE),
2252 "if this ever contains the raw path, the original scan was fine after all: {rendered}"
2253 );
2254 assert!(rendered.contains(&windows[1]), "{rendered}");
2255
2256 // A secret with nothing to escape has exactly one spelling.
2257 assert_eq!(needles(USER_TOKEN), vec![USER_TOKEN.to_string()]);
2258 }
2259
2260 #[test]
2261 fn the_secret_injection_scan_finds_nothing() {
2262 let capture = Capture::default();
2263 let output = scan_for_leaks(RedactingLayer::new(capture.clone()), &capture)
2264 .unwrap_or_else(|complaint| panic!("{complaint}"));
2265
2266 // Something must have been written, or "no secrets found" is trivially
2267 // true and means nothing.
2268 assert!(!output.trim().is_empty(), "the sink wrote nothing at all");
2269 assert!(
2270 output.contains(REDACTION),
2271 "nothing was redacted, so nothing was routed through the sink:\n{output}"
2272 );
2273 }
2274
2275 #[test]
2276 fn the_scan_catches_a_sink_that_does_not_redact() {
2277 let capture = Capture::default();
2278 let complaint = scan_for_leaks(PassthroughLayer(capture.clone()), &capture)
2279 .expect_err("a sink with no redaction must be caught");
2280 assert!(
2281 complaint.contains("emitted a secret verbatim"),
2282 "the complaint must name the failure mode: {complaint}"
2283 );
2284 }
2285
2286 // -----------------------------------------------------------------------
2287 // The allowlist
2288 // -----------------------------------------------------------------------
2289
2290 fn emit(capture: &Capture, body: impl FnOnce()) -> String {
2291 let subscriber = tracing_subscriber::registry().with(RedactingLayer::new(capture.clone()));
2292 tracing::subscriber::with_default(subscriber, body);
2293 capture.text()
2294 }
2295
2296 #[test]
2297 fn a_field_nobody_listed_is_redacted_by_default() {
2298 let capture = Capture::default();
2299 let output = emit(&capture, || {
2300 tracing::info!(
2301 a_field_added_by_a_later_task = "supersecret-value",
2302 "an event"
2303 );
2304 });
2305
2306 assert!(
2307 !output.contains("supersecret-value"),
2308 "an unlisted field leaked its value:\n{output}"
2309 );
2310 assert!(output.contains(REDACTION), "{output}");
2311 // The name survives: knowing the field was there is useful, and a field
2312 // name is not a credential.
2313 assert!(
2314 output.contains("a_field_added_by_a_later_task"),
2315 "the field name should be kept:\n{output}"
2316 );
2317 }
2318
2319 #[test]
2320 fn an_unlisted_numeric_field_is_redacted_too() {
2321 // The rule has no exception for a type, because "a credential is never
2322 // an integer" is exactly the kind of reasoning that stops being true
2323 // once somebody logs an installation-scoped identifier they should not.
2324 let capture = Capture::default();
2325 let output = emit(&capture, || {
2326 tracing::info!(unlisted_number = 8_675_309_u64, "an event");
2327 });
2328 assert!(!output.contains("8675309"), "{output}");
2329 assert!(output.contains(REDACTION), "{output}");
2330 }
2331
2332 #[test]
2333 fn listed_fields_survive() {
2334 let capture = Capture::default();
2335 let output = emit(&capture, || {
2336 tracing::info!(
2337 event = "reconciled",
2338 policy_id = "9f2c1a44-0000-4000-8000-000000000001",
2339 count = 3,
2340 outcome = "started",
2341 "reconciliation finished"
2342 );
2343 });
2344
2345 for expected in [
2346 "reconciled",
2347 "9f2c1a44-0000-4000-8000-000000000001",
2348 "started",
2349 "reconciliation finished",
2350 ] {
2351 assert!(
2352 output.contains(expected),
2353 "{expected} missing from:\n{output}"
2354 );
2355 }
2356 assert!(output.contains("\"count\":3"), "{output}");
2357 }
2358
2359 #[test]
2360 fn the_allowlist_is_sorted_and_has_no_duplicates() {
2361 // `is_field_allowed` uses a binary search, so an unsorted list would not
2362 // merely be untidy — it would silently start redacting fields that are
2363 // on it.
2364 let mut sorted = ALLOWED_FIELDS.to_vec();
2365 sorted.sort_unstable();
2366 assert_eq!(
2367 ALLOWED_FIELDS,
2368 &sorted[..],
2369 "ALLOWED_FIELDS must stay sorted"
2370 );
2371
2372 let mut deduped = sorted.clone();
2373 deduped.dedup();
2374 assert_eq!(sorted.len(), deduped.len(), "ALLOWED_FIELDS has duplicates");
2375
2376 for name in ALLOWED_FIELDS {
2377 assert!(is_field_allowed(name), "{name} is listed but not allowed");
2378 }
2379 assert!(!is_field_allowed("authorization"));
2380 assert!(!is_field_allowed("runner_token"));
2381 }
2382
2383 #[test]
2384 fn every_record_is_one_parseable_json_object_per_line() {
2385 let capture = Capture::default();
2386 let output = emit(&capture, || {
2387 tracing::info!(event = "one", "first");
2388 tracing::warn!(event = "two", "second");
2389 });
2390
2391 let lines: Vec<&str> = output
2392 .lines()
2393 .filter(|line| !line.trim().is_empty())
2394 .collect();
2395 assert_eq!(lines.len(), 2, "{output}");
2396 for line in lines {
2397 let value: Value = serde_json::from_str(line)
2398 .unwrap_or_else(|error| panic!("not JSON: {error}\n{line}"));
2399 assert!(value.get("timestamp").is_some(), "{line}");
2400 assert!(value.get("level").is_some(), "{line}");
2401 assert!(value.get("logger").is_some(), "{line}");
2402 assert!(value.get("fields").is_some(), "{line}");
2403 }
2404 }
2405
2406 #[test]
2407 fn span_fields_are_redacted_and_carried() {
2408 let capture = Capture::default();
2409 let output = emit(&capture, || {
2410 let span = tracing::info_span!("attempt", attempt_id = "abc-123", jit = %JIT_BLOB);
2411 let _entered = span.enter();
2412 tracing::info!(event = "inside", "in the span");
2413 });
2414
2415 assert!(output.contains("\"name\":\"attempt\""), "{output}");
2416 assert!(
2417 output.contains("abc-123"),
2418 "the listed span field survives:\n{output}"
2419 );
2420 assert!(!output.contains(JIT_BLOB), "a span field leaked:\n{output}");
2421 }
2422
2423 /// Asserts that [`install`] created its directories the restrictive way.
2424 ///
2425 /// `install` used to call `std::fs::create_dir_all(logs_dir)` directly.
2426 /// That is invisible on Windows and *nearly* invisible on Unix — the
2427 /// directory exists either way, and `AppPaths::create_all`'s own test still
2428 /// passed, because it tests `create_all` rather than the path a running
2429 /// daemon actually takes. So this checks the two things that distinguish
2430 /// them:
2431 ///
2432 /// 1. **All four directories exist.** `create_dir_all(logs_dir)` makes
2433 /// exactly one. This half runs on every platform, which matters because
2434 /// Windows is the leg most likely to be run locally.
2435 /// 2. **On Unix the mode is `0700`.** This is the invariant `create_all`
2436 /// documents — that a diagnostics file is not readable by other local
2437 /// accounts — and `tracing_appender` writes 0644 files into whatever
2438 /// directory it is given, so a `0755` `logs/` defeats it entirely.
2439 fn assert_install_created_restricted_directories(paths: &crate::paths::AppPaths) {
2440 for (purpose, path) in paths.all() {
2441 assert!(
2442 path.is_dir(),
2443 "install must create the {purpose} directory too: going through \
2444 AppPaths::create_all is what applies the restriction, and creating only \
2445 logs/ is the bug this asserts against ({})",
2446 path.display()
2447 );
2448
2449 #[cfg(unix)]
2450 {
2451 use std::os::unix::fs::PermissionsExt as _;
2452
2453 let mode = std::fs::metadata(path)
2454 .expect("the directory exists")
2455 .permissions()
2456 .mode()
2457 & 0o777;
2458 assert_eq!(
2459 mode, 0o700,
2460 "the {purpose} directory is mode {mode:04o}; a diagnostics file under a \
2461 group- or world-readable directory is readable by other local accounts"
2462 );
2463 }
2464 }
2465 }
2466
2467 /// The one test that exercises [`install`] rather than assembling a
2468 /// subscriber by hand: the rolling file appender, the non-blocking writer,
2469 /// and the guard that has to be held for any of it to reach disk.
2470 ///
2471 /// It installs a *global* subscriber, which a process can only do once, so
2472 /// it is the only test here that may. Everything else uses
2473 /// `with_default`, which is thread-local and does not conflict — including
2474 /// on threads that run after this one.
2475 #[test]
2476 #[serial_test::serial(global_subscriber)]
2477 fn install_writes_redacted_json_into_the_logs_directory() {
2478 // `install` honours `RUST_LOG`, and a developer who has set it to
2479 // something restrictive would otherwise see this fail for a reason that
2480 // has nothing to do with the code. CI sets no such variable.
2481 if std::env::var_os("RUST_LOG").is_some() {
2482 return;
2483 }
2484
2485 let root = tempfile::tempdir().expect("a temporary directory");
2486 let paths = crate::paths::AppPaths::rooted_at(root.path());
2487
2488 let outcome = install(&paths, LogRole::Operator, "trace");
2489
2490 // Asserted before the early return below, because `install` creates the
2491 // directories before it touches the global subscriber: this holds
2492 // whether or not this test won the race to install one.
2493 assert_install_created_restricted_directories(&paths);
2494
2495 let Ok(guard) = outcome else {
2496 // Another test binary in the same process already installed one.
2497 // Not this test's failure, and not worth making the suite
2498 // order-dependent over.
2499 return;
2500 };
2501
2502 tracing::info!(event = "installed", runner_token = %USER_TOKEN, "hello from the sink");
2503
2504 // Dropping the guard flushes and stops the background writer, which is
2505 // the documented way to be sure the line reached disk.
2506 drop(guard);
2507
2508 let written: Vec<PathBuf> = std::fs::read_dir(paths.logs_dir())
2509 .expect("the log directory was created")
2510 .filter_map(Result::ok)
2511 .map(|entry| entry.path())
2512 .collect();
2513 assert_eq!(
2514 written.len(),
2515 1,
2516 "expected one rotating log file: {written:?}"
2517 );
2518
2519 let contents = std::fs::read_to_string(&written[0]).expect("readable");
2520 assert!(contents.contains("hello from the sink"), "{contents}");
2521 assert!(
2522 !contents.contains(USER_TOKEN),
2523 "the file sink must redact exactly like the in-memory one:\n{contents}"
2524 );
2525 assert!(contents.contains(REDACTION), "{contents}");
2526 serde_json::from_str::<Value>(contents.lines().next().expect("a line"))
2527 .expect("each line is a JSON object");
2528 }
2529
2530 // -----------------------------------------------------------------------
2531 // Two accounts, one logs/ directory
2532 // -----------------------------------------------------------------------
2533
2534 /// The daemon and the operator do not reach for the same file.
2535 ///
2536 /// Cheap, and it is the whole of the separation: everything else about
2537 /// [`LogRole`] follows from these two names being different.
2538 #[test]
2539 fn the_daemon_and_the_operator_write_different_files() {
2540 assert_ne!(
2541 LogRole::Service.file_stem(),
2542 LogRole::Operator.file_stem(),
2543 "a boot-mode daemon runs as another account and creates its file 0644; sharing a \
2544 stem hands whichever of them opened it first the day's file and locks the other out"
2545 );
2546 assert_eq!(LogRole::Operator.file_stem(), OPERATOR_LOG_STEM);
2547 assert_eq!(LogRole::Service.file_stem(), SERVICE_LOG_STEM);
2548 }
2549
2550 /// A file this account may not append to is written *beside*, not panicked
2551 /// on.
2552 ///
2553 /// This is the reported 0.1.17 crash, reproduced at the mode that caused
2554 /// it. On the host it was ownership — `root` had rolled the file over at
2555 /// midnight — and an unprivileged test cannot make a `root`-owned file, so
2556 /// it makes an unwritable one instead: the appender's `OpenOptions` refuse
2557 /// both with the same `EACCES`, and refusing was what
2558 /// `tracing_appender::rolling::daily` turned into a panic.
2559 #[cfg(unix)]
2560 #[test]
2561 fn a_log_file_this_account_cannot_append_to_is_written_beside() {
2562 use std::os::unix::fs::PermissionsExt as _;
2563
2564 // `root` is not subject to the mode bits, so it would sail through the
2565 // very open this test needs to fail.
2566 if account_tag() == "uid-0" {
2567 return;
2568 }
2569
2570 let root = tempfile::tempdir().expect("a temporary directory");
2571 let paths = crate::paths::AppPaths::rooted_at(root.path());
2572 paths
2573 .create_all()
2574 .expect("the four directories are created");
2575
2576 // Every date the appender might choose, so the test cannot flake on a
2577 // run that straddles midnight UTC.
2578 let logs = paths.logs_dir().to_path_buf();
2579 let today = chrono::Utc::now();
2580 for date in [
2581 (today - chrono::Duration::days(1))
2582 .format("%Y-%m-%d")
2583 .to_string(),
2584 today.format("%Y-%m-%d").to_string(),
2585 (today + chrono::Duration::days(1))
2586 .format("%Y-%m-%d")
2587 .to_string(),
2588 ] {
2589 let taken = logs.join(format!("{OPERATOR_LOG_STEM}.{date}"));
2590 std::fs::write(&taken, b"another account's diagnostics").expect("writable");
2591 std::fs::set_permissions(&taken, std::fs::Permissions::from_mode(0o444))
2592 .expect("the mode is applied");
2593 }
2594
2595 let mut appender = open_appender(&logs, LogRole::Operator)
2596 .expect("a diagnostics file is opened beside the one this account may not append to");
2597 appender
2598 .write_all(b"a line\n")
2599 .expect("the line is written");
2600 appender.flush().expect("the line is flushed");
2601
2602 let qualified = account_qualified_stem(OPERATOR_LOG_STEM);
2603 let written: Vec<String> = std::fs::read_dir(&logs)
2604 .expect("the directory is readable")
2605 .flatten()
2606 .map(|entry| entry.file_name().to_string_lossy().into_owned())
2607 .collect();
2608 assert!(
2609 written.iter().any(|name| name.starts_with(&qualified)),
2610 "expected a file under {qualified:?} beside the unwritable ones, and found {written:?}"
2611 );
2612 for name in &written {
2613 if name.starts_with(&qualified) {
2614 continue;
2615 }
2616 assert_eq!(
2617 std::fs::read(logs.join(name)).expect("readable"),
2618 b"another account's diagnostics",
2619 "{name} belongs to another account and must not have been touched"
2620 );
2621 }
2622 }
2623
2624 // -----------------------------------------------------------------------
2625 // The scrubber, in isolation
2626 // -----------------------------------------------------------------------
2627
2628 #[test]
2629 fn tokens_are_redacted_wherever_they_appear() {
2630 for token in [USER_TOKEN, SERVER_TOKEN, FINE_GRAINED] {
2631 for shape in [
2632 token.to_string(),
2633 format!("using {token} now"),
2634 format!("(\"{token}\")"),
2635 format!("token={token}"),
2636 format!("Authorization: Bearer {token}"),
2637 format!("authorization={token}"),
2638 // A URL's userinfo. This is the canonical token-authenticated
2639 // git remote, so it is what a clone or fetch error carries, and
2640 // it is the shape the `://` branch used to hand back verbatim.
2641 format!("https://x-access-token:{token}@github.com/owner/repo.git"),
2642 format!("fatal: could not read from https://{token}@github.com/o/r"),
2643 // Userinfo with no password half.
2644 format!("https://{token}@github.com/o/r.git"),
2645 // A fragment, which used to be stripped only when it was a
2646 // query string.
2647 format!("https://github.com/login/oauth#access_token={token}"),
2648 format!("https://github.com/x?a=1#token={token}"),
2649 ] {
2650 let redacted = redact(&shape);
2651 assert!(
2652 !redacted.contains(token),
2653 "{shape:?} survived redaction as {redacted:?}"
2654 );
2655 }
2656 }
2657 }
2658
2659 #[test]
2660 fn a_url_keeps_what_diagnoses_it_and_loses_what_authenticates_it() {
2661 // The host and the path are the diagnosable part and must survive, or
2662 // nobody keeps this redaction.
2663 assert_eq!(
2664 redact(
2665 "https://x-access-token:ghu_16C7e42F292c6912E7710c838347Ae178B4a@github.com/owner/repo.git"
2666 ),
2667 format!("https://{REDACTION}@github.com/owner/repo.git")
2668 );
2669 assert_eq!(
2670 redact("https://user:hunter2@api.github.com/repos/o/r?page=2"),
2671 format!("https://{REDACTION}@api.github.com/repos/o/r?{REDACTION}")
2672 );
2673 // A password containing an `@`: the host is what follows the last one.
2674 assert_eq!(
2675 redact("https://user:p@ss@github.com/o/r"),
2676 format!("https://{REDACTION}@github.com/o/r")
2677 );
2678 // Userinfo on a bare authority, with no path at all.
2679 assert_eq!(
2680 redact("https://token@github.com"),
2681 format!("https://{REDACTION}@github.com")
2682 );
2683 // An `@` after the first `/` is part of the path, not userinfo.
2684 assert_eq!(
2685 redact("https://github.com/@owner/repo"),
2686 "https://github.com/@owner/repo"
2687 );
2688 }
2689
2690 #[test]
2691 fn an_encoded_jit_configuration_is_redacted() {
2692 assert_eq!(redact(JIT_BLOB), REDACTION);
2693 let sentence = format!("handing off {JIT_BLOB} to the runner");
2694 let redacted = redact(&sentence);
2695 assert!(!redacted.contains(JIT_BLOB), "{redacted}");
2696 assert!(redacted.starts_with("handing off "), "{redacted}");
2697 assert!(redacted.ends_with(" to the runner"), "{redacted}");
2698 }
2699
2700 #[test]
2701 fn a_secret_embedded_in_a_structured_value_is_redacted() {
2702 // Compact JSON is what `serde_json::to_string` emits and what an
2703 // HTTP error body arrives as; spaced JSON is the only shape that
2704 // used to be safe, and it was safe by accident -- the value is its
2705 // own word there, so the opaque-run rule caught it without the key
2706 // ever being recognised.
2707 for shape in [
2708 format!("{{\"encoded_jit_config\":\"{JIT_BLOB}\"}}"),
2709 format!("{{ \"encoded_jit_config\": \"{JIT_BLOB}\" }}"),
2710 format!("encoded_jit_config:{JIT_BLOB}"),
2711 format!("{{\"runner_token\":\"{USER_TOKEN}\"}}"),
2712 format!("runner_token:{USER_TOKEN}"),
2713 format!("pat:{USER_TOKEN}"),
2714 format!("{{\"authorization\":\"Bearer {USER_TOKEN}\"}}"),
2715 ] {
2716 let redacted = redact(&shape);
2717 assert!(
2718 !redacted.contains(JIT_BLOB) && !redacted.contains(USER_TOKEN),
2719 "leaked from {shape}:\n{redacted}"
2720 );
2721 }
2722
2723 // A credential short enough to clear the opaque-run threshold and
2724 // without a GitHub prefix has nothing but the key to give it away,
2725 // so it leaked from the spaced shape too: `\"password\":` left the
2726 // key spelled `password\"`, which is on no list.
2727 for shape in [
2728 "{\"password\":\"hunter2\"}",
2729 "{ \"password\": \"hunter2\" }",
2730 ] {
2731 let redacted = redact(shape);
2732 assert!(
2733 !redacted.contains("hunter2"),
2734 "leaked from {shape}: {redacted}"
2735 );
2736 }
2737
2738 // The neighbouring context still survives: this is a scrubber, not
2739 // a deleter.
2740 let body = format!("registration failed: {{\"encoded_jit_config\":\"{JIT_BLOB}\"}}");
2741 let redacted = redact(&body);
2742 assert!(redacted.starts_with("registration failed: "), "{redacted}");
2743 assert!(redacted.contains("encoded_jit_config"), "{redacted}");
2744 }
2745
2746 #[test]
2747 fn a_credential_key_is_found_wherever_it_sits_in_a_compact_structure() {
2748 // Every shape the test above covers puts the credential in the
2749 // *first* key/value pair, and the rules split a word once, on the
2750 // first separator they find. So redaction was a function of field
2751 // order -- and `serde_json::to_string` is what decides field order for
2752 // any struct with more than one field, which is what an error body is.
2753 //
2754 // Nesting and a form-encoded body are the same defect wearing
2755 // different punctuation: the value recursion ends at `redact_value`,
2756 // which is a leaf, and `&` was not a separator at all.
2757 for shape in [
2758 // The credential key second, in a compact object.
2759 format!("{{\"runner_id\":42,\"encoded_jit_config\":\"{JIT_BLOB}\"}}"),
2760 format!("{{\"status\":422,\"message\":\"bad\",\"runner_token\":\"{USER_TOKEN}\"}}"),
2761 // Nested one level, and two.
2762 format!("{{\"body\":{{\"runner_token\":\"{USER_TOKEN}\"}}}}"),
2763 format!(
2764 "{{\"error\":{{\"status\":422,\"body\":{{\"encoded_jit_config\":\"{JIT_BLOB}\"}}}}}}"
2765 ),
2766 // An array of objects, which is what a list endpoint returns.
2767 format!("[{{\"id\":1}},{{\"access_token\":\"{USER_TOKEN}\"}}]"),
2768 // Form-encoded, credential second and in the middle.
2769 format!("scope=repo&access_token={USER_TOKEN}"),
2770 format!("grant_type=refresh&refresh_token={USER_TOKEN}&scope=repo"),
2771 ] {
2772 let redacted = redact(&shape);
2773 assert!(
2774 !redacted.contains(JIT_BLOB) && !redacted.contains(USER_TOKEN),
2775 "leaked from {shape}:\n{redacted}"
2776 );
2777 assert!(redacted.contains(REDACTION), "{shape} -> {redacted}");
2778 }
2779
2780 // The pairs around it stay legible. A body whose every field came back
2781 // `[redacted]` diagnoses nothing, and is how a redaction gets turned
2782 // off rather than fixed.
2783 let redacted = redact(&format!(
2784 "failed: {{\"runner_id\":42,\"encoded_jit_config\":\"{JIT_BLOB}\"}}"
2785 ));
2786 assert!(redacted.starts_with("failed: "), "{redacted}");
2787 assert!(redacted.contains("\"runner_id\":42"), "{redacted}");
2788 assert!(redacted.contains("encoded_jit_config"), "{redacted}");
2789
2790 // A credential short enough to clear the opaque-run threshold and
2791 // carrying no GitHub prefix has nothing but its key to give it away,
2792 // so it is the case the shape rules cannot rescue.
2793 for shape in [
2794 "{\"user\":\"operator\",\"password\":\"hunter2\"}",
2795 "{\"body\":{\"password\":\"hunter2\"}}",
2796 "user=operator&password=hunter2",
2797 ] {
2798 assert!(
2799 !redact(shape).contains("hunter2"),
2800 "leaked from {shape}: {}",
2801 redact(shape)
2802 );
2803 }
2804
2805 // Ordinary punctuation still survives the cut, or the structure that
2806 // makes a log line readable is gone with the secret.
2807 assert_eq!(
2808 redact("desired 3, active 1, headroom 2"),
2809 "desired 3, active 1, headroom 2"
2810 );
2811 assert_eq!(
2812 redact("labels=[linux,x64,self-hosted]"),
2813 "labels=[linux,x64,self-hosted]"
2814 );
2815 }
2816
2817 #[test]
2818 fn backslash_escaped_json_reaches_the_key_rules_and_the_value_rules() {
2819 // `tracing::error!(reason = ?err)` reaches this module through
2820 // `record_debug` and `format!("{:?}")`, and `Debug` on a `String`
2821 // escapes the quotes inside it. So an error whose `Debug` embeds an
2822 // HTTP body arrives with its keys spelled `\"password\"` -- and `\`
2823 // is not in `WRAPPERS`, so `trim_matches(WRAPPERS)` left it welded on
2824 // and no list contained the result. `reason` is on ALLOWED_FIELDS, so
2825 // this reaches the scrubber rather than being dropped.
2826 let failure = StoreError {
2827 body: "{\"password\":\"hunter2\"}".to_string(),
2828 };
2829 // The fixture carries the secret before anything has looked at it. A
2830 // premise, asserted rather than assumed: a fixture that quietly
2831 // stopped carrying one would make every assertion below vacuously
2832 // true.
2833 assert!(failure.body.contains("hunter2"), "{}", failure.body);
2834 let rendered = format!("{failure:?}");
2835 // The premise, asserted rather than assumed: `Debug` really does
2836 // produce the escaped spelling. If it ever stops, this test is
2837 // measuring something else.
2838 assert!(
2839 rendered.contains("\\\"password\\\""),
2840 "the premise is that Debug escapes the quotes: {rendered}"
2841 );
2842 assert!(
2843 !redact(&rendered).contains("hunter2"),
2844 "leaked: {}",
2845 redact(&rendered)
2846 );
2847
2848 for shape in [
2849 "{\\\"password\\\":\\\"hunter2\\\"}",
2850 "Error { body: \"{\\\"access_token\\\":\\\"hunter2\\\"}\" }",
2851 ] {
2852 assert!(
2853 !redact(shape).contains("hunter2"),
2854 "leaked from {shape}: {}",
2855 redact(shape)
2856 );
2857 }
2858
2859 // The escaped spelling of a long secret leaked too, and for the same
2860 // reason: the key was unrecognised, so nothing below it ever ran.
2861 let escaped = format!("{{\\\"encoded_jit_config\\\":\\\"{JIT_BLOB}\\\"}}");
2862 assert!(!redact(&escaped).contains(JIT_BLOB), "{}", redact(&escaped));
2863
2864 // Trimming the key is only half of it, and it is the half that is
2865 // easy to mistake for the whole. `runner_token` is deliberately *not*
2866 // on CREDENTIAL_KEYS -- a field name is not what makes a value a
2867 // secret, and this module's own documentation says so -- so that pair
2868 // is caught by the token-prefix rule reading its *value*, or it is not
2869 // caught at all. The escaped quote hid the value from that rule
2870 // exactly as it hid the key from the key rules, and a key-only fix
2871 // leaves this one leaking through the sink.
2872 assert!(
2873 !is_credential_key("runner_token"),
2874 "the premise of this case is an unlisted key; once it is listed, \
2875 this stops exercising the value side at all"
2876 );
2877 let escaped_value = format!("{{\\\"runner_token\\\":\\\"{USER_TOKEN}\\\"}}");
2878 assert!(
2879 !redact(&escaped_value).contains(USER_TOKEN),
2880 "the value side leaked: {}",
2881 redact(&escaped_value)
2882 );
2883
2884 // The trim is unconditional on a key and conditional on a value: a
2885 // backslash comes off a value only where it is escaping punctuation.
2886 // `split_wrappers` runs before `looks_like_path`, so putting `\` in
2887 // `WRAPPERS` would trim away the leading `\\` that UNC detection keys
2888 // on and turn a share path back into ordinary text.
2889 assert_eq!(redact(r"\\fileserver\share\jit"), PATH_REDACTION);
2890 assert_eq!(redact(r"\\?\C:\Users\operator\runtime"), PATH_REDACTION);
2891 // And the escaped spelling of a share path is still a share path:
2892 // `\\` escapes nothing, so it survives the trim that `\"` does not.
2893 assert_eq!(redact(r"\\\\fileserver\\share\\jit"), PATH_REDACTION);
2894 // A path ending in its own separator is still a path without it. The
2895 // separator is punctuation, so it is trimmed, judged, and put back.
2896 let trailing = redact("C:\\Users\\operator\\runtime\\");
2897 assert!(trailing.starts_with(PATH_REDACTION), "{trailing}");
2898 assert!(!trailing.contains("operator"), "{trailing}");
2899 }
2900
2901 #[test]
2902 fn a_url_does_not_make_the_rest_of_its_word_unredactable() {
2903 // `redact_core` split on the first `://` and handed *everything*
2904 // before it to `redact_url` as a scheme and everything after it as a
2905 // URL. The terminal arm of `redact_url` echoes both verbatim, so a
2906 // single URL anywhere in a word turned the whole of the rest of that
2907 // word into text no rule below could reach. The only thing that saved
2908 // the shape was a `?` or `#` inside the URL, which made `redact_url`
2909 // replace the tail.
2910 //
2911 // `documentation_url` is in essentially every GitHub REST error body,
2912 // so this was any such body logged alongside a credential.
2913 let body = format!(
2914 "{{\"message\":\"Bad credentials\",\"documentation_url\":\"https://docs.github.com/rest\",\"token\":\"{USER_TOKEN}\"}}"
2915 );
2916 let redacted = redact(&body);
2917 assert!(!redacted.contains(USER_TOKEN), "leaked: {redacted}");
2918 // The URL is the diagnosable part and must survive, or nobody keeps
2919 // this redaction.
2920 assert!(
2921 redacted.contains("https://docs.github.com/rest"),
2922 "the URL should survive: {redacted}"
2923 );
2924
2925 // The mirror order: everything before the `://` became the "scheme".
2926 let reversed = format!(
2927 "{{\"token\":\"{USER_TOKEN}\",\"documentation_url\":\"https://docs.github.com/rest\"}}"
2928 );
2929 let redacted = redact(&reversed);
2930 assert!(!redacted.contains(USER_TOKEN), "leaked: {redacted}");
2931
2932 // A nested object behind a URL was missed even when the URL's own
2933 // userinfo was caught, because the miss and the catch happened in the
2934 // same call.
2935 let clone = format!(
2936 "{{\"remote\":\"https://x-access-token:{USER_TOKEN}@github.com/o/r.git\",\"body\":{{\"password\":\"hunter2\"}}}}"
2937 );
2938 let redacted = redact(&clone);
2939 assert!(!redacted.contains(USER_TOKEN), "leaked: {redacted}");
2940 assert!(!redacted.contains("hunter2"), "leaked: {redacted}");
2941 assert!(
2942 redacted.contains("@github.com/o/r.git"),
2943 "the remote should stay diagnosable: {redacted}"
2944 );
2945
2946 // A URL still owns its own query string, which is why the URL check
2947 // sits ahead of the structural cut: `?` and `#` are not structural
2948 // characters, and an OAuth response puts the token after one of them.
2949 assert_eq!(
2950 redact(&format!(
2951 "{{\"url\":\"https://api.github.com/x?token={USER_TOKEN}\"}}"
2952 )),
2953 format!("{{\"url\":\"https://api.github.com/x?{REDACTION}\"}}")
2954 );
2955 // And a URL standing on its own is untouched.
2956 assert_eq!(
2957 redact("GET https://api.github.com/repos/o/r/actions/runners"),
2958 "GET https://api.github.com/repos/o/r/actions/runners"
2959 );
2960
2961 // A URL that is a credential key's *own* value keeps its scheme, host
2962 // and path like every other URL -- a URL is not a token, and this
2963 // module keeps exactly that much of one everywhere else. What must not
2964 // happen is the key's empty value being redacted on the way past,
2965 // which put the URL out behind a `[redacted]` that had replaced
2966 // nothing: `token=[redacted]https://evil.example/x`. Bounding the URL
2967 // is what created that shape, and pass one declining an empty value is
2968 // what closes it.
2969 assert_eq!(
2970 redact("token=https://evil.example/x"),
2971 "token=https://evil.example/x"
2972 );
2973 assert_eq!(
2974 redact("{\"token\":\"https://evil.example/x\"}"),
2975 "{\"token\":\"https://evil.example/x\"}"
2976 );
2977 // An empty credential value is nothing to redact wherever it sits, and
2978 // saying otherwise reports a secret in a place none was.
2979 assert_eq!(redact("{\"password\":\"\"}"), "{\"password\":\"\"}");
2980 }
2981
2982 #[test]
2983 fn an_array_element_is_judged_without_the_quote_that_wraps_it() {
2984 // The structural cut recursed on the *raw* fragment, and the terminal
2985 // fallback then called `redact_value` with the wrappers still on. A
2986 // fragment carrying no `:` or `=` of its own -- which is exactly what
2987 // an array element is -- therefore reached the shape rules as
2988 // `"ghu_…`: `starts_with("ghu_")` fails, `is_opaque_char` fails on the
2989 // quote, `starts_with("eyJ")` fails, and `looks_like_path` never gets
2990 // a clean look at `"C:\Users\…`.
2991 //
2992 // This is the defect the structural cut was written to close, one step
2993 // further down: "only the first key/value pair is ever examined"
2994 // became "a value with no key of its own is never examined". It
2995 // survived a round because `scan_for_leaks` had no array among its
2996 // twelve shapes.
2997 for shape in [
2998 format!("{{\"tokens\":[\"{USER_TOKEN}\",\"x\"]}}"),
2999 format!("{{\"tokens\":[\"x\",\"{USER_TOKEN}\"]}}"),
3000 format!("[\"x\",\"{USER_TOKEN}\"]"),
3001 format!("[{{\"id\":1}},[\"{USER_TOKEN}\"]]"),
3002 // The `Debug`-escaped spelling of the same thing.
3003 format!("{{\\\"tokens\\\":[\\\"x\\\",\\\"{USER_TOKEN}\\\"]}}"),
3004 ] {
3005 let redacted = redact(&shape);
3006 assert!(
3007 !redacted.contains(USER_TOKEN),
3008 "leaked from {shape}: {redacted}"
3009 );
3010 assert!(redacted.contains(REDACTION), "{shape} -> {redacted}");
3011 }
3012
3013 // Every other shape rule was reachable the same way.
3014 let jit = format!("{{\"items\":[\"{JIT_BLOB}\"]}}");
3015 assert!(!redact(&jit).contains(JIT_BLOB), "{}", redact(&jit));
3016 let assertions = format!("{{\"assertions\":[\"{JWT}\"]}}");
3017 assert!(
3018 !redact(&assertions).contains(JWT),
3019 "{}",
3020 redact(&assertions)
3021 );
3022 let opaque = "ZYXWVUTSRQPONMLKJIHGFEDCBA9876543210zyxwvut";
3023 assert!(opaque.len() > OPAQUE_RUN_THRESHOLD, "{}", opaque.len());
3024 let listed = format!("[\"x\",\"{opaque}\"]");
3025 assert!(!redact(&listed).contains(opaque), "{}", redact(&listed));
3026
3027 // A path in an array. `07-security.md` requires paths redacted, and
3028 // only `looks_like_path` can see one -- with a clean look at the value
3029 // and not before.
3030 let roots = format!("{{\"roots\":[\"x\",\"{WINDOWS_WORKSPACE}\"]}}");
3031 let redacted = redact(&roots);
3032 assert!(!redacted.contains(WINDOWS_WORKSPACE), "leaked: {redacted}");
3033 assert!(redacted.contains(PATH_REDACTION), "{redacted}");
3034
3035 // The array survives being scrubbed: this is a scrubber, not a
3036 // deleter.
3037 assert_eq!(
3038 redact("labels=[\"linux\",\"x64\"]"),
3039 "labels=[\"linux\",\"x64\"]"
3040 );
3041 }
3042
3043 #[test]
3044 fn a_semicolon_cuts_a_word_the_way_a_comma_does() {
3045 // `;` was in `WRAPPERS` -- recognised as punctuation -- and not in
3046 // `STRUCTURAL`, so it never cut a word. It is the separator for a
3047 // Windows connection string, for a credential string, and for cookie
3048 // pairs written without a space, which is `d2`'s territory exactly.
3049 // `Set-Cookie: theme=dark; session=…` was safe only because of the
3050 // space after the `;`.
3051 for shape in [
3052 "store rejected: Server=host;Database=x;Password=hunter2;",
3053 "store rejected: user=operator;password=hunter2",
3054 "Server=host;Password=hunter2;Database=x",
3055 ] {
3056 let redacted = redact(shape);
3057 assert!(
3058 !redacted.contains("hunter2"),
3059 "leaked from {shape}: {redacted}"
3060 );
3061 }
3062
3063 let cookies = format!("theme=dark;session={USER_TOKEN}");
3064 let redacted = redact(&cookies);
3065 assert!(!redacted.contains(USER_TOKEN), "leaked: {redacted}");
3066
3067 // Separators go back verbatim, so ordinary prose is unaffected.
3068 assert_eq!(
3069 redact("started; then reconciled; then idled"),
3070 "started; then reconciled; then idled"
3071 );
3072 assert_eq!(
3073 redact("desired 3;active 1;headroom 2"),
3074 "desired 3;active 1;headroom 2"
3075 );
3076 }
3077
3078 #[test]
3079 fn an_element_wrapped_value_is_redacted() {
3080 // `split_wrappers` strips only the *outermost* `<` and `>`, so
3081 // `<string>ghu_…</string>` arrived as `string>ghu_…</string`, which
3082 // matches no rule at all. `d3`'s installers handle launchd plists,
3083 // which is where this shape comes from; a systemd unit line is the
3084 // `key=value` spelling and was already covered.
3085 for shape in [
3086 format!("<string>{USER_TOKEN}</string>"),
3087 format!("<key>token</key><string>{USER_TOKEN}</string>"),
3088 format!("<dict><key>Token</key><string>{USER_TOKEN}</string></dict>"),
3089 ] {
3090 let redacted = redact(&shape);
3091 assert!(
3092 !redacted.contains(USER_TOKEN),
3093 "leaked from {shape}: {redacted}"
3094 );
3095 assert!(redacted.contains(REDACTION), "{shape} -> {redacted}");
3096 }
3097
3098 // The element names survive: they are what says the line was about a
3099 // plist at all.
3100 let plist = format!("<key>token</key><string>{JIT_BLOB}</string>");
3101 let redacted = redact(&plist);
3102 assert!(!redacted.contains(JIT_BLOB), "leaked: {redacted}");
3103 assert!(redacted.contains("<key>token</key>"), "{redacted}");
3104
3105 // An angle bracket in ordinary text is re-emitted verbatim.
3106 assert_eq!(redact("Custom<Io>"), "Custom<Io>");
3107 }
3108
3109 #[test]
3110 fn a_redacted_value_keeps_the_punctuation_that_wrapped_it() {
3111 // Pass one returned `format!("{key}{separator}{REDACTION}")` and
3112 // dropped the value's trailing wrapper, so a redacted object came out
3113 // with an unbalanced quote: `{"password":[redacted]"}`. Pass two
3114 // already put `lead` and `trail` back.
3115 //
3116 // Worth fixing because this module argues, correctly, that the
3117 // structure around a redaction is what keeps a line diagnosable -- and
3118 // a reader who cannot parse the line cannot tell a redaction from a
3119 // truncation.
3120 assert_eq!(
3121 redact("{\"password\":\"hunter2\"}"),
3122 format!("{{\"password\":\"{REDACTION}\"}}")
3123 );
3124 assert_eq!(
3125 redact(&format!("{{\"access_token\":\"{USER_TOKEN}\"}}")),
3126 format!("{{\"access_token\":\"{REDACTION}\"}}")
3127 );
3128 assert_eq!(
3129 redact(&format!(
3130 "[{{\"id\":1}},{{\"access_token\":\"{USER_TOKEN}\"}}]"
3131 )),
3132 format!("[{{\"id\":1}},{{\"access_token\":\"{REDACTION}\"}}]")
3133 );
3134 // The `Debug`-escaped spelling keeps its escaped quotes.
3135 assert_eq!(
3136 redact("{\\\"password\\\":\\\"hunter2\\\"}"),
3137 format!("{{\\\"password\\\":\\\"{REDACTION}\\\"}}")
3138 );
3139
3140 // The point of all of it: what the sink writes is still the JSON it
3141 // was handed, minus the secret.
3142 let line = redact(&format!(
3143 "{{\"runner_id\":42,\"access_token\":\"{USER_TOKEN}\"}}"
3144 ));
3145 serde_json::from_str::<Value>(&line)
3146 .unwrap_or_else(|error| panic!("a redacted body must still parse: {line} ({error})"));
3147 }
3148
3149 #[test]
3150 fn a_bare_jwt_is_redacted_despite_its_dots() {
3151 // `is_opaque_char` excludes `.`, so a JWT is three opaque runs rather
3152 // than one, each under the threshold, and a 100-character credential
3153 // printed verbatim. `Authorization: Bearer <jwt>` is caught by the
3154 // scheme rule and a credential-keyed one by the key rule, so this bit
3155 // only where a token stood alone or under a name nobody listed.
3156 assert!(
3157 JWT.len() > 100,
3158 "the premise is a long token: {}",
3159 JWT.len()
3160 );
3161 assert_eq!(redact(JWT), REDACTION);
3162 assert_eq!(
3163 redact(&format!("minted {JWT} for the installation")),
3164 format!("minted {REDACTION} for the installation")
3165 );
3166 // Sentence-final punctuation is trimmed as a wrapper first, so the
3167 // token is still recognised.
3168 assert!(!redact(&format!("minted {JWT}.")).contains(JWT));
3169 // Under a key nobody listed.
3170 assert!(!redact(&format!("assertion={JWT}")).contains(JWT));
3171 assert!(!redact(&format!("{{\"assertion\":\"{JWT}\"}}")).contains(JWT));
3172
3173 // Narrow on purpose. Adding `.` to `is_opaque_char` is the obvious fix
3174 // and the wrong one: it swallows every long dotted word there is.
3175 for ordinary in [
3176 "com.example.runner.manager.platform.process.identity.token",
3177 "runner-manager.2026.08.21.log",
3178 "api.github.com",
3179 "9f2c1a44-0000-4000-8000-000000000001.attempt.json",
3180 ] {
3181 assert_eq!(redact(ordinary), ordinary, "over-redacted {ordinary}");
3182 }
3183 }
3184
3185 #[test]
3186 fn the_sink_redacts_a_short_credential_that_only_its_key_gives_away() {
3187 // `scan_for_leaks` cannot carry this case. A credential short enough
3188 // to clear the opaque-run threshold and carrying no GitHub prefix is
3189 // indistinguishable from an ordinary word when it is logged bare, so
3190 // injecting it through shape 1 would demand a redaction no shape rule
3191 // can deliver. Here the key is always present, which is the situation
3192 // `d2`'s secret store is actually in -- and it is through the sink,
3193 // not through `redact` alone, because that distinction is why these
3194 // shapes survived a round.
3195 let capture = Capture::default();
3196 let output = emit(&capture, || {
3197 tracing::error!("store rejected: {{\"user\":\"operator\",\"password\":\"hunter2\"}}");
3198 tracing::error!("store rejected: {{\"body\":{{\"password\":\"hunter2\"}}}}");
3199 tracing::error!("store rejected: user=operator&password=hunter2");
3200 let failure = StoreError {
3201 body: "{\"password\":\"hunter2\"}".to_string(),
3202 };
3203 tracing::error!(reason = ?failure, "store rejected the request");
3204
3205 // A `;` or an `&` after a URL in the same word. The URL branch runs
3206 // ahead of the structural cut and `split_url` did not stop at
3207 // either character, so the separator that would have cut the word
3208 // was swallowed into the URL and echoed.
3209 tracing::error!("store rejected: Server=https://vault.local/api;Password=hunter2;");
3210 tracing::error!("keychain error: url=https://kc.local;password=hunter2");
3211 tracing::error!("unit rejected: Environment=API=https://a.com/v1;PASSWORD=hunter2");
3212 tracing::error!("token exchange failed: cb=https://a.com/x&password=hunter2");
3213
3214 // A credential key whose value is in a *later* fragment. The
3215 // empty-value skip is right; the claim that the structural cut
3216 // reaches such a value was not, because nothing carried the key
3217 // across the cut.
3218 tracing::error!("store rejected: {{\"password\":[\"hunter2\"]}}");
3219 tracing::error!("store rejected: {{\"password\":{{\"v\":\"hunter2\"}}}}");
3220 tracing::error!("store rejected: Password=;hunter2");
3221 tracing::error!("plist rejected: <key>password</key><string>hunter2</string>");
3222 tracing::error!(
3223 "plist rejected: <dict><key>password</key><string>hunter2</string></dict>"
3224 );
3225
3226 // A structural character inside the value. `,` and `&` could
3227 // already split a secret; this commit added `;`, `<` and `>`.
3228 //
3229 // The pieces are spelled so that none of them is a substring of
3230 // anything the line legitimately keeps -- `ss` would have "found" a
3231 // leak in the surviving key `password`, which is a check that fails
3232 // for the wrong reason and is no better than one that cannot fail.
3233 tracing::error!("store rejected: {{\"password\":\"qq<vv>xx\"}}");
3234 tracing::error!("store rejected: {{\"password\":\"j1&k2,m3\"}}");
3235 tracing::error!("store rejected: {{\"password\":\"n4;p5<q6>r7,t8\"}}");
3236 });
3237
3238 assert!(
3239 !output.contains("hunter2"),
3240 "a short credential leaked through the sink:\n{output}"
3241 );
3242 // The punctuated passwords: every piece a structural character can cut
3243 // one into has to go, not just the piece that kept the key company.
3244 for piece in [
3245 "qq", "vv", "xx", "j1", "k2", "m3", "n4", "p5", "q6", "r7", "t8",
3246 ] {
3247 assert!(
3248 !output.contains(piece),
3249 "a structural character split a secret and the tail survived \
3250 ({piece}):\n{output}"
3251 );
3252 }
3253 assert!(output.contains(REDACTION), "{output}");
3254 // Sixteen lines, or the sink was never reached and "no secret found" is
3255 // true of an empty string.
3256 assert_eq!(
3257 output
3258 .lines()
3259 .filter(|line| !line.trim().is_empty())
3260 .count(),
3261 16,
3262 "{output}"
3263 );
3264 }
3265
3266 /// The multi-word plist spelling, which is worse than the one-word one:
3267 /// the credential key and the value are in the same word, but the value
3268 /// itself is two words, so closing it needs the fragment carry to reach the
3269 /// word-level follow-on rule.
3270 #[test]
3271 fn a_credential_value_that_runs_past_its_own_word_is_still_redacted() {
3272 let capture = Capture::default();
3273 let output = emit(&capture, || {
3274 tracing::error!("plist rejected: <key>password</key><string>correct horse</string>");
3275 tracing::error!("plist rejected: <key>password</key> <string>correct horse</string>");
3276 });
3277 for piece in ["correct", "horse"] {
3278 assert!(
3279 !output.contains(piece),
3280 "a multi-word credential value leaked ({piece}):\n{output}"
3281 );
3282 }
3283 }
3284
3285 /// The other half of the fragment carry: it must not swallow the ordinary,
3286 /// *closed* pairs sitting next to a credential.
3287 ///
3288 /// Every shape here is one the carry has an opportunity to over-redact —
3289 /// a closed empty value, a neighbouring key, the pairs of a connection
3290 /// string, and the element names of a plist. Redaction that eats the
3291 /// diagnostics is redaction nobody keeps, and a carry with no terminator
3292 /// is exactly how that happens.
3293 #[test]
3294 fn the_fragment_carry_stops_where_the_value_does() {
3295 for (input, expected) in [
3296 (
3297 "{\"password\":\"abc\",\"user\":\"bob\"}",
3298 format!("{{\"password\":\"{REDACTION}\",\"user\":\"bob\"}}"),
3299 ),
3300 (
3301 "Server=host;Password=hunter2;User=bob",
3302 format!("Server=host;Password={REDACTION};User=bob"),
3303 ),
3304 (
3305 "{\"password\":\"\",\"user\":\"bob\"}",
3306 "{\"password\":\"\",\"user\":\"bob\"}".to_string(),
3307 ),
3308 (
3309 "<dict><key>password</key><string>hunter2</string></dict>",
3310 format!("<dict><key>password</key><string>{REDACTION}</string></dict>"),
3311 ),
3312 (
3313 "{\"password\":\"qq<vv>xx\"}",
3314 format!("{{\"password\":\"{REDACTION}<{REDACTION}>{REDACTION}\"}}"),
3315 ),
3316 ] {
3317 assert_eq!(redact(input), expected, "from {input}");
3318 }
3319
3320 // A closed value ends the claim, so the word after it is ordinary text.
3321 assert_eq!(
3322 redact("{\"password\":\"x\"} ok"),
3323 format!("{{\"password\":\"{REDACTION}\"}} ok")
3324 );
3325 assert_eq!(
3326 redact("Server=host;Password=hunter2; ok"),
3327 format!("Server=host;Password={REDACTION}; ok")
3328 );
3329
3330 // `{"password":""} ok` is *not* on that list, and the reason is worth
3331 // recording rather than asserting away. `split_wrappers` strips the
3332 // empty value with the rest of the trailing punctuation, so the word
3333 // reaches `redact_word` as the core `password":` — a bare credential
3334 // key, which the stem rule has always read as "the value is the next
3335 // word". That rule predates the carry, is untouched by it, and fires
3336 // first; the empty-value skip below it never gets a look. So the `ok`
3337 // is redacted, exactly as it was before any of this.
3338 assert_eq!(
3339 redact("{\"password\":\"\"} ok"),
3340 format!("{{\"password\":\"\"}} {REDACTION}")
3341 );
3342 // What the empty-value skip does still guarantee is the thing it was
3343 // written for: no `[redacted]` is invented *inside* the pair itself.
3344 assert_eq!(redact("{\"password\":\"\"}"), "{\"password\":\"\"}");
3345
3346 // Ordinary prose is untouched: the carry is only ever armed by a
3347 // credential key.
3348 assert_eq!(
3349 redact("started; then reconciled; then idled"),
3350 "started; then reconciled; then idled"
3351 );
3352 assert_eq!(redact("Custom<Io>"), "Custom<Io>");
3353 }
3354
3355 #[test]
3356 fn paths_are_redacted_on_both_families() {
3357 assert_eq!(redact(WORKSPACE), PATH_REDACTION);
3358 assert_eq!(redact(WINDOWS_WORKSPACE), PATH_REDACTION);
3359 assert_eq!(redact("\\\\fileserver\\share\\jit"), PATH_REDACTION);
3360 assert_eq!(
3361 redact("~/Library/Application Support/x"),
3362 format!("{PATH_REDACTION} Support/x")
3363 );
3364 assert_eq!(
3365 redact("runtime=/var/lib/runner-manager/runtime"),
3366 format!("runtime={PATH_REDACTION}")
3367 );
3368 }
3369
3370 #[test]
3371 fn a_url_survives_but_its_query_string_and_fragment_do_not() {
3372 assert_eq!(
3373 redact("GET https://api.github.com/repos/owner/repo/actions/runners"),
3374 "GET https://api.github.com/repos/owner/repo/actions/runners"
3375 );
3376 assert_eq!(
3377 redact("https://api.github.com/x?access_token=ghu_secret"),
3378 format!("https://api.github.com/x?{REDACTION}")
3379 );
3380 // A fragment carries a token in an OAuth implicit-flow response, and
3381 // is never needed to diagnose an HTTP call.
3382 assert_eq!(
3383 redact("https://api.github.com/x#access_token=ghu_secret"),
3384 format!("https://api.github.com/x#{REDACTION}")
3385 );
3386 // Whichever comes first ends the diagnosable part.
3387 assert_eq!(
3388 redact("https://api.github.com/x?page=2#access_token=ghu_secret"),
3389 format!("https://api.github.com/x?{REDACTION}")
3390 );
3391 }
3392
3393 /// `;` and `&` end a URL, but only ahead of its query string.
3394 ///
3395 /// `STRUCTURAL` has nine characters and `is_url_terminator` recognised
3396 /// seven of them. Because the URL branch runs *ahead* of the structural
3397 /// cut, a URL earlier in a word made `split_url` swallow everything to the
3398 /// next terminator — including the `;` or `&` that would have cut the word
3399 /// — and `redact_url`'s terminal arm echoes what it is given. So the L3 fix
3400 /// (bounding a URL) and the L1 fix (cutting on `;` and `&`) did not
3401 /// compose, and this commit added `;` to `STRUCTURAL` for connection
3402 /// strings while leaving the path a URL opens straight through it.
3403 #[test]
3404 fn a_separator_after_a_url_still_cuts_the_word() {
3405 for shape in [
3406 format!("store rejected: Server=https://vault.local/api;Password={USER_TOKEN};"),
3407 format!("keychain error: url=https://kc.local;secret={USER_TOKEN}"),
3408 format!("unit rejected: Environment=API=https://a.com/v1;TOKEN={USER_TOKEN}"),
3409 format!("token exchange failed: cb=https://a.com/x&access_token={USER_TOKEN}"),
3410 format!("dsn rejected: dsn=https://sentry.local/1;password={USER_TOKEN};user=x"),
3411 ] {
3412 let redacted = redact(&shape);
3413 assert!(
3414 !redacted.contains(USER_TOKEN),
3415 "leaked from {shape}:\n{redacted}"
3416 );
3417 }
3418
3419 // The URL itself still survives, or nobody keeps this redaction.
3420 assert_eq!(
3421 redact("store rejected: Server=https://vault.local/api;Password=hunter2;"),
3422 format!("store rejected: Server=https://vault.local/api;Password={REDACTION};")
3423 );
3424
3425 // The obvious fix is the wrong one, and this is what it costs. Making
3426 // `;` and `&` terminators everywhere ends a URL *inside* its own query
3427 // string, and `redact_url` replaces a query wholesale precisely because
3428 // a token can be in any parameter and this module does not guess which:
3429 // `?[redacted]` would become `?[redacted]&state=hunter2`. So the cut is
3430 // restricted to the part of the URL ahead of the first `?` or `#`.
3431 assert_eq!(
3432 redact("https://a.com/cb?code=1&state=hunter2"),
3433 format!("https://a.com/cb?{REDACTION}")
3434 );
3435 assert_eq!(
3436 redact("https://a.com/cb#code=1&state=hunter2"),
3437 format!("https://a.com/cb#{REDACTION}")
3438 );
3439 assert_eq!(
3440 redact(&format!(
3441 "https://a.com/cb?a=1;b=2&access_token={USER_TOKEN}"
3442 )),
3443 format!("https://a.com/cb?{REDACTION}")
3444 );
3445
3446 // And leaving `\` out of the terminators is still right: a Windows
3447 // path used as a URL password puts the `@` that identifies the
3448 // userinfo behind the first backslash, and `redact_url` echoes what it
3449 // is given.
3450 assert_eq!(
3451 redact(r"https://x-access-token:C:\Users\op\p@github.com/o/r.git"),
3452 format!("https://{REDACTION}@github.com/o/r.git")
3453 );
3454 }
3455
3456 /// A secret in a URL *path* is echoed verbatim.
3457 ///
3458 /// `redact_url` applied no shape rule to the path at all. The design
3459 /// intends a path to be diagnosable — and it still is — but the
3460 /// token-prefix rule is documented as a belt that catches a credential
3461 /// *anywhere*, and a path was the one place it never ran.
3462 #[test]
3463 fn a_secret_in_a_url_path_is_redacted_and_the_rest_of_the_path_is_not() {
3464 for shape in [
3465 format!("https://github.com/o/r/raw/{USER_TOKEN}/f"),
3466 format!("https://api.github.com/{JIT_BLOB}"),
3467 format!("https://a.com/x/{JWT}?page=2"),
3468 ] {
3469 let redacted = redact(&shape);
3470 assert!(
3471 !redacted.contains(USER_TOKEN)
3472 && !redacted.contains(JIT_BLOB)
3473 && !redacted.contains(JWT),
3474 "leaked from {shape}:\n{redacted}"
3475 );
3476 }
3477
3478 assert_eq!(
3479 redact(&format!("https://github.com/o/r/raw/{USER_TOKEN}/f")),
3480 format!("https://github.com/o/r/raw/{REDACTION}/f")
3481 );
3482
3483 // The rest of the path is exactly as diagnosable as it was: a segment
3484 // is judged on its own, and an ordinary one is not a secret.
3485 for url in [
3486 "https://api.github.com/repos/owner/repo/actions/runners",
3487 "https://github.com/actions/runner/releases/download/v2.330.0/actions-runner-linux-x64-2.330.0.tar.gz",
3488 "https://github.com/o/r.git",
3489 "https://github.com/@owner/repo",
3490 "https://api.github.com/repos/o/r/actions/runners/42",
3491 ] {
3492 assert_eq!(redact(url), url, "over-redacted a diagnosable path: {url}");
3493 }
3494 }
3495
3496 /// A large message must not take the process down.
3497 ///
3498 /// The URL branch recursed into `redact_core` on both sides of the cut. The
3499 /// termination argument was sound — every call is on a strictly shorter
3500 /// slice — and it was silent on *depth*, which was linear in the length of
3501 /// the input. A message of ~2000 URL-carrying items, about 86 KB, exited
3502 /// `0xc00000fd STATUS_STACK_OVERFLOW`.
3503 ///
3504 /// **A stack overflow is not catchable — it aborts the process.** A large
3505 /// HTTP error body is attacker-influenceable content, so this was a way to
3506 /// kill the agent from inside its own log sink, which is worse than any
3507 /// leak: a sink that is not running redacts nothing.
3508 ///
3509 /// Note what this test can and cannot do. An overflow aborts the test
3510 /// binary rather than failing an assertion, so the value of this test is
3511 /// that **the suite completes at all**; the assertions below only confirm
3512 /// it did the work rather than skipping it.
3513 #[test]
3514 fn a_large_message_does_not_overflow_the_stack() {
3515 // 20000 items is ~860 KB and an order of magnitude past the ~2000 that
3516 // was measured to abort. It is also what the commit *before* the URL
3517 // branch survived, because that branch returned without recursing --
3518 // so this is a regression guard with the margin the regression had.
3519 const ITEMS: usize = 20_000;
3520 let body = r#"{"url":"https://api.github.com/repos/o/r"},"#.repeat(ITEMS);
3521 assert!(body.len() > 800_000, "the premise is a large body");
3522
3523 let redacted = redact(&body);
3524 assert!(
3525 redacted.contains("https://api.github.com/repos/o/r"),
3526 "the URLs are the diagnosable part and must survive"
3527 );
3528
3529 // The same depth, reached through the structural cut and through a
3530 // credential value rather than through a bare URL.
3531 let nested = format!("{{\"error\":{{\"body\":{{\"list\":[{}]}}}}}}", body);
3532 assert!(!redact(&nested).is_empty());
3533
3534 // A long run with no URL in it at all, so the structural loop is
3535 // exercised on its own.
3536 let flat = "{\"a\":1},".repeat(ITEMS);
3537 assert!(!redact(&flat).is_empty());
3538
3539 // And one long unbroken URL, where the *path* loop is what iterates.
3540 let long_path = format!("https://a.com/{}", "seg/".repeat(ITEMS));
3541 assert!(!redact(&long_path).is_empty());
3542 }
3543
3544 #[test]
3545 fn a_credential_header_loses_its_scheme_and_its_value() {
3546 assert_eq!(
3547 redact("Authorization: Bearer abc123"),
3548 format!("Authorization: {REDACTION} {REDACTION}")
3549 );
3550 assert_eq!(
3551 redact("Authorization: Bearer abc123, Accept: application/json"),
3552 // The comma ends the header value, so the next header's name is not
3553 // swallowed.
3554 format!("Authorization: {REDACTION} {REDACTION} Accept: application/json")
3555 );
3556 assert_eq!(
3557 redact("x-api-key=hunter2"),
3558 format!("x-api-key={REDACTION}")
3559 );
3560 assert_eq!(
3561 redact("Cookie: session=abc"),
3562 format!("Cookie: {REDACTION}")
3563 );
3564
3565 // A webhook signature is not a credential the way a token is -- it is
3566 // derived, and it verifies rather than authenticates -- but it has a
3567 // SHA-256's exact shape, so the digest carve-out rendered it as a
3568 // labelled 12-character prefix rather than redacting it. Twelve hex
3569 // characters of an HMAC are of no use to anybody, which is why the
3570 // carve-out is safe in general; the header is on the list anyway,
3571 // because there is no diagnostic worth having in a signature and one
3572 // entry is cheaper than the argument.
3573 let hmac = "9f86d081884c7d659a2feaa0c55ad015a3bf4f1b2b0b822cd15d6c15b0f00a08";
3574 assert_eq!(
3575 redact(&format!("X-Hub-Signature-256: sha256={hmac}")),
3576 format!("X-Hub-Signature-256: {REDACTION}")
3577 );
3578 // Pass one puts the value's wrapping quote back, so what comes out is
3579 // still the object that went in. It used to emit
3580 // `{"x-hub-signature-256":[redacted]"}` -- an unbalanced quote in a
3581 // line this module argues has to stay diagnosable.
3582 //
3583 // This case is also `redact_core`'s two-pass witness, and the comment
3584 // there names it: the `=` comes first and names nothing, but what
3585 // follows it is a whole HMAC -- non-empty -- so a merged pass inspects
3586 // that value and returns before ever reaching the `:` that names
3587 // `x-hub-signature-256`.
3588 assert_eq!(
3589 redact(&format!("{{\"x-hub-signature-256\":\"sha256={hmac}\"}}")),
3590 format!("{{\"x-hub-signature-256\":\"{REDACTION}\"}}")
3591 );
3592 // The SHA-1 spelling GitHub still sends alongside it.
3593 assert_eq!(
3594 redact(&format!("X-Hub-Signature: sha1={hmac}")),
3595 format!("X-Hub-Signature: {REDACTION}")
3596 );
3597 // The carve-out itself is untouched: a bare digest still renders as a
3598 // prefix, because a checksum gate that cannot say which digest it got
3599 // is a gate nobody can act on.
3600 assert_eq!(redact(hmac), "sha256:9f86d081884c…");
3601 }
3602
3603 #[test]
3604 fn ordinary_text_survives_intact() {
3605 // Redaction that eats the diagnostics is redaction nobody keeps. These
3606 // are the shapes this product's own log lines actually take.
3607 for text in [
3608 "reconciliation finished",
3609 "runner exited idle without work",
3610 "desired 3, active 1, headroom 2",
3611 "attempt 9f2c1a44-0000-4000-8000-000000000001 is busy",
3612 "http 403 after 2 retries",
3613 "windows/x64 is a documented pair",
3614 ] {
3615 assert_eq!(redact(text), text, "redaction damaged an ordinary message");
3616 }
3617 }
3618
3619 /// A SHA-256 is 64 opaque characters and would otherwise be swallowed by
3620 /// the opaque-run rule. `07-security.md` makes checksum verification a
3621 /// security gate, and a gate that cannot say *which* digest it got is a
3622 /// gate nobody can act on, so a digest renders as a labelled prefix.
3623 #[test]
3624 fn a_digest_renders_as_a_prefix_rather_than_disappearing() {
3625 let digest = "9f86d081884c7d659a2feaa0c55ad015a3bf4f1b2b0b822cd15d6c15b0f00a08";
3626
3627 assert_eq!(redact(digest), "sha256:9f86d081884c…");
3628 // The point of the change: expected-versus-actual stays legible.
3629 let other = "60303ae22b998861bce3b28f33eec1be758a213c86c93c076dbe9f558c11c752";
3630 assert_ne!(
3631 redact(digest),
3632 redact(other),
3633 "two digests must stay distinguishable"
3634 );
3635
3636 // In the sentence shape `e2` will actually write.
3637 assert_eq!(
3638 redact(&format!("checksum mismatch: expected {digest} got {other}")),
3639 "checksum mismatch: expected sha256:9f86d081884c… got sha256:60303ae22b99…"
3640 );
3641
3642 // A prefix a caller logged itself is below the threshold and untouched.
3643 assert_eq!(redact(&digest[..12]), digest[..12].to_string());
3644
3645 // An already-labelled digest is labelled once, not twice, and is
3646 // truncated like a bare one.
3647 //
3648 // Before `redact_core` recursed into a `:` value this arrived at
3649 // `redact_value` whole, matched nothing there -- a `:` is not an
3650 // opaque character -- and was printed in full. Recursing hands
3651 // `as_sha256_digest` the digest on its own, which re-attaches its own
3652 // label, so the redundant one is dropped rather than doubled.
3653 //
3654 // The truncation is the part worth having: a 64-character lowercase
3655 // hex run is only *usually* a digest, an HMAC-SHA256 signature has
3656 // the same shape, and `sha256:<hmac>` used to be emitted whole.
3657 assert_eq!(redact(&format!("sha256:{digest}")), "sha256:9f86d081884c…");
3658 // The `=` spelling had the same doubling and is fixed with it; the
3659 // caller's own separator survives either way.
3660 assert_eq!(redact(&format!("sha256={digest}")), "sha256=9f86d081884c…");
3661 }
3662
3663 #[test]
3664 fn the_digest_exception_is_exactly_sixty_four_lowercase_hex_and_nothing_else() {
3665 // The narrower this carve-out is, the less there is to reason about.
3666 // Anything that is not precisely a lowercase SHA-256 stays redacted by
3667 // the opaque-run rule.
3668 let digest = "9f86d081884c7d659a2feaa0c55ad015a3bf4f1b2b0b822cd15d6c15b0f00a08";
3669
3670 assert_eq!(
3671 redact(&digest.to_ascii_uppercase()),
3672 REDACTION,
3673 "uppercase hex is not the shape this exception recognises"
3674 );
3675 assert_eq!(
3676 redact(&format!("{digest}0")),
3677 REDACTION,
3678 "65 characters is not a SHA-256"
3679 );
3680 // 64 characters of base64, which is what an encoded secret of that
3681 // length looks like: not hex, so not exempt.
3682 let base64ish = "ZYXWVUTSRQPONMLKJIHGFEDCBA9876543210zyxwvutsrqponmlkjihgfedcba98";
3683 assert_eq!(base64ish.len(), 64);
3684 assert_eq!(redact(base64ish), REDACTION);
3685
3686 // And the JIT blob, which is the thing the opaque-run rule exists for,
3687 // must not have been weakened by any of this.
3688 assert_eq!(redact(JIT_BLOB), REDACTION);
3689 }
3690
3691 #[test]
3692 fn a_uuid_survives() {
3693 // 36 characters, below the opaque-run threshold on purpose: every
3694 // identifier in this product's domain model is a UUID, and redacting
3695 // them would make the logs useless.
3696 let id = "9f2c1a44-0000-4000-8000-000000000001";
3697 assert_eq!(redact(id), id);
3698 assert!(id.len() < OPAQUE_RUN_THRESHOLD);
3699 }
3700
3701 #[test]
3702 fn redaction_preserves_whitespace_and_line_structure() {
3703 let input = "line one\nAuthorization: Bearer x\nline three";
3704 let redacted = redact(input);
3705 assert_eq!(redacted.lines().count(), 3, "{redacted}");
3706 assert!(redacted.starts_with("line one\n"), "{redacted}");
3707 assert!(redacted.ends_with("\nline three"), "{redacted}");
3708 }
3709}