use std::ffi::OsString;
use std::fmt;
use std::path::Path;
use std::sync::Arc;
use std::time::{Duration, Instant};
use async_trait::async_trait;
use processkit::{
Command, Error, ErrorKind, JobRunner, ProcessResult, ProcessRunner, Result, RunningProcess,
};
pub const MAX_VALUE_LEN: usize = 160;
const SENSITIVE_FLAGS: &[&str] = &[
"token",
"password",
"passwd",
"secret",
"auth",
"authorization",
"credential",
"credentials",
"api-key",
"apikey",
"access-token",
"private-token",
"gh-token",
"github-token",
"gitlab-token",
"bearer",
"otp",
"pat",
];
const SECRET_PREFIXES: &[&str] = &[
"ghp_",
"gho_",
"ghu_",
"ghs_",
"ghr_",
"github_pat_",
"glpat-",
"glptt-",
"xoxb-",
"xoxp-",
"xoxa-",
"xoxr-",
];
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub enum CommandStatus {
Exited(i32),
Signalled(Option<i32>),
TimedOut,
Started,
Failed(&'static str),
}
#[derive(Debug)]
pub struct CommandRecord<'a> {
pub program: &'a str,
pub args: &'a [String],
pub working_dir: Option<&'a Path>,
pub status: CommandStatus,
pub duration: Duration,
}
impl fmt::Display for CommandRecord<'_> {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{}", self.program)?;
for arg in self.args {
write!(f, " {arg}")?;
}
if let Some(dir) = self.working_dir {
write!(f, " (cwd: {})", dir.display())?;
}
match self.status {
CommandStatus::Started => write!(f, " -> started (streaming)"),
CommandStatus::Exited(code) => write!(f, " -> exit {code} in {:?}", self.duration),
CommandStatus::Signalled(Some(sig)) => {
write!(f, " -> signal {sig} in {:?}", self.duration)
}
CommandStatus::Signalled(None) => write!(f, " -> signalled in {:?}", self.duration),
CommandStatus::TimedOut => write!(f, " -> timed out in {:?}", self.duration),
CommandStatus::Failed(kind) => write!(f, " -> failed: {kind} in {:?}", self.duration),
}
}
}
pub trait CommandObserver: Send + Sync {
fn on_command(&self, record: &CommandRecord<'_>);
}
#[derive(Debug, Clone)]
pub struct StderrObserver {
tag: Arc<str>,
}
impl StderrObserver {
pub fn new(tag: impl Into<Arc<str>>) -> Self {
Self { tag: tag.into() }
}
}
impl Default for StderrObserver {
fn default() -> Self {
Self::new("command")
}
}
impl CommandObserver for StderrObserver {
fn on_command(&self, record: &CommandRecord<'_>) {
eprintln!("{}: {record}", self.tag);
}
}
pub struct LoggingRunner<R: ProcessRunner = JobRunner> {
inner: R,
observer: Arc<dyn CommandObserver>,
}
impl<R: ProcessRunner> LoggingRunner<R> {
pub fn new(inner: R, tag: impl Into<Arc<str>>) -> Self {
Self::with_observer(inner, Arc::new(StderrObserver::new(tag)))
}
pub fn with_observer(inner: R, observer: Arc<dyn CommandObserver>) -> Self {
Self { inner, observer }
}
pub fn observer(&self) -> &Arc<dyn CommandObserver> {
&self.observer
}
pub fn inner(&self) -> &R {
&self.inner
}
fn observe(&self, command: &Command, status: CommandStatus, duration: Duration) {
let program = command.program().to_string_lossy();
let args = redact_args(command.arguments());
let record = CommandRecord {
program: program.as_ref(),
args: &args,
working_dir: command.working_dir(),
status,
duration,
};
self.observer.on_command(&record);
}
}
impl<R: ProcessRunner + fmt::Debug> fmt::Debug for LoggingRunner<R> {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
f.debug_struct("LoggingRunner")
.field("inner", &self.inner)
.field("observer", &"<dyn CommandObserver>")
.finish()
}
}
#[async_trait]
impl<R: ProcessRunner> ProcessRunner for LoggingRunner<R> {
async fn output_string(&self, command: &Command) -> Result<ProcessResult<String>> {
let started = Instant::now();
let result = self.inner.output_string(command).await;
self.observe(command, status_of(&result), started.elapsed());
result
}
async fn output_bytes(&self, command: &Command) -> Result<ProcessResult<Vec<u8>>> {
let started = Instant::now();
let result = self.inner.output_bytes(command).await;
self.observe(command, status_of(&result), started.elapsed());
result
}
async fn start(&self, command: &Command) -> Result<RunningProcess> {
let result = self.inner.start(command).await;
let status = match &result {
Ok(_) => CommandStatus::Started,
Err(err) => CommandStatus::Failed(error_category(err)),
};
self.observe(command, status, Duration::ZERO);
result
}
}
fn status_of<T>(result: &Result<ProcessResult<T>>) -> CommandStatus {
match result {
Ok(res) => {
if let Some(code) = res.code() {
CommandStatus::Exited(code)
} else if res.timed_out() {
CommandStatus::TimedOut
} else {
CommandStatus::Signalled(res.signal())
}
}
Err(err) => CommandStatus::Failed(error_category(err)),
}
}
fn error_category(err: &Error) -> &'static str {
match err.kind() {
ErrorKind::NotFound => "program not found",
ErrorKind::Spawn => "spawn failed",
ErrorKind::PermissionDenied => "permission denied",
ErrorKind::Timeout => "timed out",
ErrorKind::Cancelled => "cancelled",
ErrorKind::Unsupported => "unsupported",
ErrorKind::Exit => "non-zero exit",
ErrorKind::Signalled => "signalled",
ErrorKind::Predicate => "predicate rejected",
_ if err.output_overflow().is_some() => "output too large",
_ => "error",
}
}
pub fn redact_args(args: &[OsString]) -> Vec<String> {
let mut out = Vec::with_capacity(args.len());
let mut mask_next = false;
for arg in args {
let s = arg.to_string_lossy();
if mask_next {
out.push(REDACTED.to_string());
mask_next = false;
continue;
}
if s.starts_with('-') {
let name_part = s.trim_start_matches('-');
let dashes_len = s.len() - name_part.len();
if let Some(eq) = name_part.find('=') {
let name = &name_part[..eq];
let value = &name_part[eq + 1..];
if is_sensitive_flag(name) {
out.push(format!("{}{name}={REDACTED}", &s[..dashes_len]));
} else {
out.push(format!(
"{}{name}={}",
&s[..dashes_len],
redact_arg_value(value)
));
}
} else {
if is_sensitive_flag(name_part) {
mask_next = true;
}
out.push(s.into_owned());
}
} else {
out.push(redact_arg_value(&s));
}
}
out
}
const REDACTED: &str = "<redacted>";
fn is_sensitive_flag(name: &str) -> bool {
let name = name.to_ascii_lowercase();
SENSITIVE_FLAGS.contains(&name.as_str())
}
pub fn redact_value(value: &str) -> String {
if value.is_empty() {
return String::new();
}
let lower = value.to_ascii_lowercase();
if let Some(masked) = mask_url_userinfo(value) {
return redact_secret_shapes(&masked);
}
if contains_secret_shape(&lower) {
return redact_secret_shapes(value);
}
value.to_owned()
}
fn redact_arg_value(value: &str) -> String {
if contains_secret_shape(&value.to_ascii_lowercase()) && mask_url_userinfo(value).is_none() {
return REDACTED.to_string();
}
truncate(&redact_value(value))
}
fn redact_secret_shapes(value: &str) -> String {
let lower = value.to_ascii_lowercase();
let mut out = String::with_capacity(value.len());
let mut cursor = 0;
while cursor < value.len() {
let Some((start, marker_len)) = SECRET_PREFIXES
.iter()
.map(|prefix| (*prefix, prefix.len()))
.chain(std::iter::once((
"x-access-token:",
"x-access-token:".len(),
)))
.filter_map(|(marker, marker_len)| {
lower[cursor..]
.find(marker)
.map(|at| (cursor + at, marker_len))
})
.min_by_key(|(start, _)| *start)
else {
out.push_str(&value[cursor..]);
break;
};
out.push_str(&value[cursor..start]);
let end = secret_shape_end(value.as_bytes(), start + marker_len);
out.push_str(REDACTED);
cursor = end;
}
out
}
fn secret_shape_end(bytes: &[u8], start: usize) -> usize {
let mut end = start;
while end < bytes.len()
&& !bytes[end].is_ascii_whitespace()
&& !matches!(bytes[end], b'"' | b'\'' | b',' | b']' | b'}' | b')' | b';')
{
end += 1;
}
end
}
fn contains_secret_shape(lower: &str) -> bool {
SECRET_PREFIXES.iter().any(|p| lower.contains(p)) || lower.contains("x-access-token:")
}
fn mask_url_userinfo(value: &str) -> Option<String> {
let scheme_end = value.find("://")?;
let after = &value[scheme_end + 3..];
let authority = after.split(['/', '?', '#']).next().unwrap_or(after);
let at = authority.rfind('@')?;
let userinfo = &authority[..at];
if value[..scheme_end].eq_ignore_ascii_case("ssh") && userinfo == "git" {
return None;
}
Some(format!(
"{}://{REDACTED}@{}",
&value[..scheme_end],
&after[at + 1..]
))
}
fn truncate_cow(value: &str) -> Option<String> {
if is_canonical_truncation(value) {
return None;
}
let count = value.chars().count();
if count <= MAX_VALUE_LEN {
return None;
}
let head: String = value.chars().take(MAX_VALUE_LEN).collect();
Some(format!("{head}…({count} chars)"))
}
fn is_canonical_truncation(value: &str) -> bool {
let Some((head, marker)) = value.rsplit_once("…(") else {
return false;
};
let Some(original_len) = marker
.strip_suffix(" chars)")
.and_then(|digits| digits.parse::<usize>().ok())
else {
return false;
};
head.chars().count() == MAX_VALUE_LEN && original_len > MAX_VALUE_LEN
}
fn truncate(value: &str) -> String {
truncate_cow(value).unwrap_or_else(|| value.to_string())
}
#[cfg(test)]
mod tests {
use super::*;
use processkit::testing::{RecordingRunner, Reply};
use proptest::prelude::*;
use std::sync::Mutex;
fn argv(args: &[&str]) -> Vec<OsString> {
args.iter().map(OsString::from).collect()
}
#[derive(Default)]
struct Capture(Mutex<Vec<String>>);
impl CommandObserver for Capture {
fn on_command(&self, record: &CommandRecord<'_>) {
self.0.lock().unwrap().push(record.to_string());
}
}
#[tokio::test]
async fn every_failure_kind_gets_its_stable_category() {
use processkit::{ErrorReason, OutputBufferPolicy, OverflowMode};
use std::io;
let io_err = |kind: io::ErrorKind| io::Error::from(kind);
let cases: Vec<(Error, &str)> = vec![
(Error::not_found("git", None), "program not found"),
(
Error::spawn("git", io_err(io::ErrorKind::InvalidInput)),
"spawn failed",
),
(
Error::spawn("git", io_err(io::ErrorKind::PermissionDenied)),
"permission denied",
),
(
Error::timeout("git", Duration::from_secs(1), "", ""),
"timed out",
),
(
ErrorReason::Cancelled {
program: "git".into(),
}
.into(),
"cancelled",
),
(
ErrorReason::Unsupported {
operation: "suspend".into(),
}
.into(),
"unsupported",
),
(Error::exit("git", 1, "", "boom"), "non-zero exit"),
(Error::signalled("git", Some(9), "", ""), "signalled"),
(
ErrorReason::Io(io_err(io::ErrorKind::BrokenPipe)).into(),
"error",
),
(Error::parse("git", "unrecognisable version"), "error"),
];
for (err, expected) in cases {
assert_eq!(error_category(&err), expected, "for {err:?}");
}
let runner = RecordingRunner::replying(Reply::ok("x".repeat(4096)));
let command = Command::new("git").args(["diff"]).output_buffer(
OutputBufferPolicy::unbounded()
.with_overflow(OverflowMode::Error)
.with_max_bytes(16),
);
let over_budget = runner
.output_bytes(&command)
.await
.expect_err("4 KiB of output must trip a 16-byte ceiling");
assert_eq!(error_category(&over_budget), "output too large");
}
#[test]
fn ordinary_argv_is_shown_verbatim() {
let out = redact_args(&argv(&["status", "--porcelain", "-z"]));
assert_eq!(out, vec!["status", "--porcelain", "-z"]);
}
#[test]
fn single_value_redaction_masks_secrets_without_truncating_output() {
let secret = "github_pat_SINGLE_VALUE_MUST_NOT_LEAK";
assert_eq!(redact_value(&format!("token={secret}")), "token=<redacted>");
assert_eq!(
redact_value("https://user:password@example.test/repo"),
"https://<redacted>@example.test/repo"
);
let output = "ordinary-json-value ".repeat(32);
assert_eq!(redact_value(&output), output);
assert_eq!(redact_value("status"), "status");
}
#[test]
fn value_after_a_sensitive_flag_is_masked() {
let out = redact_args(&argv(&["--token", "ghp_supersecretvalue", "pr", "list"]));
assert_eq!(out, vec!["--token", "<redacted>", "pr", "list"]);
let out = redact_args(&argv(&["log", "-p", "HEAD~1"]));
assert_eq!(out, vec!["log", "-p", "HEAD~1"]);
}
#[test]
fn inline_sensitive_flag_value_is_masked() {
let out = redact_args(&argv(&["--password=hunter2", "--auth=Bearer xyz"]));
assert_eq!(out, vec!["--password=<redacted>", "--auth=<redacted>"]);
}
#[test]
fn secret_looking_positional_is_masked_even_without_a_flag() {
let out = redact_args(&argv(&[
"push",
"glpat-abcdEFGH1234 ",
"github_pat_11ABCDEF",
]));
assert_eq!(out[0], "push");
assert_eq!(out[1], "<redacted>");
assert_eq!(out[2], "<redacted>");
}
#[test]
fn url_userinfo_credentials_are_masked_but_host_kept() {
let out = redact_args(&argv(&[
"clone",
"https://user:tokensecret@github.com/o/r.git",
]));
assert_eq!(out[0], "clone");
assert_eq!(out[1], "https://<redacted>@github.com/o/r.git");
assert!(!out[1].contains("tokensecret"));
let out = redact_args(&argv(&["fetch", "ssh://git@github.com/o/r.git"]));
assert_eq!(out[1], "ssh://git@github.com/o/r.git");
}
#[test]
fn url_userinfo_token_usernames_are_masked() {
for (url, secret) in [
(
"https://ghp_THIS_MUST_NOT_LEAK@github.com/o/r.git",
"ghp_THIS_MUST_NOT_LEAK",
),
(
"https://glpat-THIS_MUST_NOT_LEAK@gitlab.com/o/r.git",
"glpat-THIS_MUST_NOT_LEAK",
),
(
"https://x-access-token@github.com/o/r.git",
"x-access-token",
),
] {
let out = redact_args(&argv(&["clone", url]));
assert_eq!(
out[1],
"https://<redacted>@".to_string() + url.split('@').nth(1).unwrap()
);
assert!(
!out[1].contains(secret),
"userinfo leaked from {url}: {}",
out[1]
);
}
}
#[test]
fn url_at_in_path_is_not_mistaken_for_userinfo() {
let out = redact_args(&argv(&["clone", "https://host:8443/dir/file@rev"]));
assert_eq!(out[0], "clone");
assert_eq!(
out[1], "https://host:8443/dir/file@rev",
"no credential ⇒ nothing is masked; host/port/path stay intact"
);
assert!(
!out[1].contains(REDACTED),
"the value must not be redacted: {}",
out[1]
);
let out = redact_args(&argv(&[
"clone",
"https://user:secret@host:8443/dir/file@rev",
]));
assert_eq!(out[1], "https://<redacted>@host:8443/dir/file@rev");
assert!(!out[1].contains("secret"), "credential masked: {}", out[1]);
}
#[test]
fn long_free_text_is_truncated_not_dumped() {
let body = "x".repeat(MAX_VALUE_LEN + 50);
let out = redact_args(&argv(&["pr", "create", "--body", &body]));
assert_eq!(&out[..3], &["pr", "create", "--body"]);
let shown = &out[3];
assert!(shown.len() < body.len(), "the body was truncated");
assert!(shown.contains("chars)"), "carries a length marker: {shown}");
let out = redact_args(&argv(&["pr", "create", &format!("--body={body}")]));
assert!(out[2].starts_with("--body=x"));
assert!(out[2].contains("chars)"));
}
fn harmless_args() -> impl Strategy<Value = Vec<String>> {
prop::collection::vec("[a-z0-9./_]{0,24}", 0..6)
}
fn known_token() -> impl Strategy<Value = String> {
(prop::sample::select(SECRET_PREFIXES), "[A-Za-z0-9_-]{8,48}")
.prop_map(|(prefix, suffix)| format!("{prefix}{suffix}"))
}
fn opaque_secret() -> impl Strategy<Value = String> {
"LEAK_[A-Za-z0-9_-]{8,48}"
}
fn secret_argv() -> impl Strategy<Value = (Vec<OsString>, String)> {
(
harmless_args(),
harmless_args(),
known_token(),
opaque_secret(),
prop::sample::select(SENSITIVE_FLAGS),
"[a-z0-9 =:;]{0,24}",
"[a-z0-9 =:;]{0,24}",
0_u8..8,
)
.prop_map(|(before, after, token, opaque, flag, left, right, shape)| {
let mut args = before;
let secret = match shape {
0 => {
args.push(format!("{left}{token}{right}"));
token
}
1 => {
args.extend([format!("--{flag}"), opaque.clone()]);
opaque
}
2 => {
args.push(format!("--{flag}={opaque}"));
opaque
}
3 => {
args.push(format!("https://user:{opaque}@example.test/owner/repo.git"));
opaque
}
4 => {
args.push(format!("https://{token}@example.test/owner/repo.git"));
token
}
5 => {
args.push(format!(
"https://x-access-token:{opaque}@example.test/owner/repo.git"
));
opaque
}
6 => {
args.push(format!("--body={left}{token}{right}"));
token
}
_ => {
args.push(format!(
"https://user:{opaque}@example.test/{left}{token}{right}"
));
token
}
};
args.extend(after);
(args.into_iter().map(OsString::from).collect(), secret)
})
}
fn unicode_string(max_chars: usize) -> impl Strategy<Value = String> {
prop::collection::vec(any::<char>(), 0..max_chars)
.prop_map(|chars| chars.into_iter().collect())
}
proptest! {
#![proptest_config(ProptestConfig::with_cases(128))]
#[test]
fn generated_secret_literals_never_survive((args, secret) in secret_argv()) {
let redacted = redact_args(&args);
prop_assert!(
redacted.iter().all(|arg| !arg.contains(&secret)),
"secret {secret:?} survived in {redacted:?}"
);
}
#[test]
fn generated_single_value_secrets_never_survive(token in known_token()) {
let value = format!("gh output: {token}");
let redacted = redact_value(&value);
prop_assert!(!redacted.contains(&token), "secret {token:?} survived");
}
#[test]
fn arbitrary_single_values_are_idempotent(value in unicode_string(512)) {
let once = redact_value(&value);
prop_assert_eq!(redact_value(&once), once);
}
#[test]
fn arbitrary_argv_is_panic_free_and_idempotent(
args in prop::collection::vec(unicode_string(512), 0..24)
) {
let args: Vec<OsString> = args.into_iter().map(OsString::from).collect();
let once = redact_args(&args);
let twice_input: Vec<OsString> = once.iter().map(OsString::from).collect();
prop_assert_eq!(redact_args(&twice_input), once);
}
#[test]
fn huge_multibyte_values_are_panic_free_and_idempotent(
chars in prop::collection::vec(
prop::sample::select(vec!['é', 'Ж', '漢', '🦀']),
(MAX_VALUE_LEN + 1)..4096,
)
) {
let value: String = chars.into_iter().collect();
let once = redact_args(&[OsString::from(value)]);
let twice_input: Vec<OsString> = once.iter().map(OsString::from).collect();
prop_assert_eq!(redact_args(&twice_input), once);
}
}
#[cfg(unix)]
proptest! {
#![proptest_config(ProptestConfig::with_cases(128))]
#[test]
fn arbitrary_os_bytes_are_panic_free_and_idempotent(
bytes in prop::collection::vec(any::<u8>(), 0..4096)
) {
use std::os::unix::ffi::OsStringExt;
let once = redact_args(&[OsString::from_vec(bytes)]);
let twice_input: Vec<OsString> = once.iter().map(OsString::from).collect();
prop_assert_eq!(redact_args(&twice_input), once);
}
}
#[tokio::test]
async fn runner_observes_a_command_without_leaking_a_secret() {
let inner = RecordingRunner::replying(Reply::ok("ok"));
let capture = Arc::new(Capture::default());
let runner = LoggingRunner::with_observer(&inner, capture.clone());
let secret = "ghp_THIS_MUST_NOT_APPEAR";
let command = Command::new("gh")
.args([
"pr",
"create",
"--token",
secret,
"--body",
&"z".repeat(400),
])
.current_dir("/tmp/work");
let result = runner
.output_string(&command)
.await
.expect("the inner runner replied ok");
assert_eq!(result.stdout(), "ok");
assert_eq!(inner.calls().len(), 1);
let lines = capture.0.lock().unwrap();
assert_eq!(lines.len(), 1, "exactly one record per command");
let line = &lines[0];
assert!(
!line.contains(secret),
"the secret must not appear in the log line: {line}"
);
assert!(
line.contains("<redacted>"),
"the token value is masked: {line}"
);
assert!(line.contains("gh"), "shows the program: {line}");
assert!(line.contains("pr create"), "shows the subcommand: {line}");
assert!(
line.contains("cwd: "),
"shows the working directory: {line}"
);
assert!(line.contains("exit 0"), "shows the exit code: {line}");
assert!(
!line.contains(&"z".repeat(400)),
"the body is not dumped: {line}"
);
}
#[tokio::test]
async fn the_streaming_start_path_logs_the_spawn() {
let inner = RecordingRunner::replying(Reply::ok("a line\n"));
let capture = Arc::new(Capture::default());
let runner = LoggingRunner::with_observer(&inner, capture.clone());
let command = Command::new("gh").args(["run", "watch"]);
let _ = runner.start(&command).await;
let lines = capture.0.lock().unwrap();
assert_eq!(lines.len(), 1, "the spawn is logged exactly once");
assert!(
lines[0].contains("gh run watch"),
"logs the spawn: {}",
lines[0]
);
assert!(
lines[0].contains("started"),
"reports the streaming spawn: {}",
lines[0]
);
}
}