Merge: a log that survives the process, so the tablet can be debugged
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> # Conflicts: # apps/darkroom-android/Cargo.toml # apps/darkroom-desktop/Cargo.toml # platform/dr-plat/src/lib.rs
This commit is contained in:
Generated
+2
@@ -1224,6 +1224,7 @@ name = "darkroom-android"
|
||||
version = "0.9.0"
|
||||
dependencies = [
|
||||
"android_logger",
|
||||
"dr-plat",
|
||||
"dr-sync",
|
||||
"dr-ui",
|
||||
"jni 0.21.1",
|
||||
@@ -1236,6 +1237,7 @@ name = "darkroom-desktop"
|
||||
version = "0.9.0"
|
||||
dependencies = [
|
||||
"anyhow",
|
||||
"dr-plat",
|
||||
"dr-ui",
|
||||
"env_logger",
|
||||
"log",
|
||||
|
||||
@@ -19,9 +19,10 @@ dr-ui.workspace = true
|
||||
# For `account::set_data_dir`: only the platform entry point knows where Android
|
||||
# lets this app keep files, and it must be set before any store is opened.
|
||||
dr-sync.workspace = true
|
||||
# For the panic hook, and for `crash::set_state_dir` — Android has no XDG
|
||||
# directories, so the entry point is the only place that knows where a crash
|
||||
# record may be written.
|
||||
# For the panic hook, for `state::set_state_dir` and for
|
||||
# `diagnostics::install`. Android has no XDG directories, so the entry point is
|
||||
# the only place that knows where a crash record or a log file may be written,
|
||||
# and both have to be in place before anything can fail.
|
||||
dr-plat.workspace = true
|
||||
# Directly, not just through dr-ui: `android_main` takes an `AndroidApp` and
|
||||
# calls `slint::android::init`, both of which come from this crate. The backend
|
||||
|
||||
@@ -6,8 +6,10 @@
|
||||
//! * There are no command-line paths. Android's SAF hands out document URIs,
|
||||
//! not filesystem paths (ARCH §6.9), so the viewer opens with an empty
|
||||
//! browsing list and the library grid is the only way in.
|
||||
//! * Logging goes to logcat. `env_logger` writes to stderr, which Android
|
||||
//! discards.
|
||||
//! * Logging goes to logcat *and* to a file. `env_logger` writes to stderr,
|
||||
//! which Android discards; logcat replaces it, and a rotating file beside it
|
||||
//! replaces the thing logcat cannot be — a record that outlives the session
|
||||
//! and can be sent to somebody (NFR-OPS-1, [`dr_plat::diagnostics`]).
|
||||
//!
|
||||
//! The first of those has one exception, and it is the launch `Intent`: a
|
||||
//! gallery, a file manager or the share sheet can name images to open, and
|
||||
@@ -29,11 +31,39 @@ mod intents;
|
||||
/// Android application entry point, called by android-activity's glue.
|
||||
#[no_mangle]
|
||||
fn android_main(app: slint::android::AndroidApp) {
|
||||
android_logger::init_once(
|
||||
// Before the logger, because the logger needs somewhere to write, and
|
||||
// before any `log::` call at all, because records emitted before this line
|
||||
// reach nothing.
|
||||
//
|
||||
// **The external directory, not the internal one, and the difference is
|
||||
// the entire point of the file.** Both are app-private and both survive
|
||||
// backgrounding — the volatile one is the *cache* directory, which is not
|
||||
// in play here. What separates them is retrieval:
|
||||
// `/data/data/<pkg>/files` needs `run-as` against a debuggable build or
|
||||
// root to read, and `/sdcard/Android/data/<pkg>/files` is a plain
|
||||
// `adb pull` from any build, needing no permission since API 19. A log
|
||||
// nobody can get off the device does not do the job NFR-OPS-1 describes.
|
||||
//
|
||||
// The consequence is that anyone holding the tablet can read it, which is
|
||||
// why `dr_plat::diagnostics` redacts at the sink and why configuration —
|
||||
// the account list, and the credential reference beside it — stays on
|
||||
// `internal_data_path` below rather than moving here (NFR-SEC-2).
|
||||
let external = app.external_data_path();
|
||||
if let Some(dir) = external.clone().or_else(|| app.internal_data_path()) {
|
||||
dr_plat::set_state_dir(dir);
|
||||
}
|
||||
|
||||
// `AndroidLogger` rather than `init_once`, so logcat can be *teed* rather
|
||||
// than replaced: `init_once` installs itself as the global logger and
|
||||
// there is only one of those. Everything that reached logcat before this
|
||||
// change still reaches it, at the same level and under the same tag; the
|
||||
// file is strictly additional.
|
||||
let console = android_logger::AndroidLogger::new(
|
||||
android_logger::Config::default()
|
||||
.with_max_level(log::LevelFilter::Info)
|
||||
.with_tag("DarkRoom"),
|
||||
);
|
||||
let logging = dr_plat::diagnostics::install(Box::new(console), log::LevelFilter::Info);
|
||||
|
||||
// Panics go to stderr, and Android discards stderr. Without this hook a
|
||||
// worker thread that panics is invisible: the process survives, the
|
||||
@@ -54,6 +84,25 @@ fn android_main(app: slint::android::AndroidApp) {
|
||||
|
||||
log::info!("DarkRoom v{}", env!("CARGO_PKG_VERSION"));
|
||||
|
||||
// Said in logcat as well as in the file, because the first thing anybody
|
||||
// asked for a log needs is where it is — and on a device that is a path
|
||||
// nobody can guess and a command nobody remembers.
|
||||
match &logging {
|
||||
dr_plat::Installed::ToFile(path) => {
|
||||
log::info!("logging to {}", path.display());
|
||||
if external.is_none() {
|
||||
log::warn!(
|
||||
"no external storage; the log is app-private and needs \
|
||||
`adb shell run-as paris.tourolle.darkroom cat files/darkroom.log` \
|
||||
on a debuggable build"
|
||||
);
|
||||
}
|
||||
}
|
||||
dr_plat::Installed::ConsoleOnly(why) => {
|
||||
log::warn!("no log file this session, only logcat: {why}");
|
||||
}
|
||||
}
|
||||
|
||||
// Before anything opens a store: Android has no $HOME and no XDG
|
||||
// directories, so the default guess resolves to a path the app cannot
|
||||
// write. Nothing failed loudly — the session list went to a doomed path, so
|
||||
|
||||
@@ -7,9 +7,9 @@ license.workspace = true
|
||||
|
||||
[dependencies]
|
||||
dr-ui.workspace = true
|
||||
# For the panic hook alone. Directly rather than through dr-ui, because it has
|
||||
# to be installed before `dr_ui::run` — a panic during startup is exactly the
|
||||
# one this exists to catch.
|
||||
# For the panic hook and the log sink, directly rather than through dr-ui:
|
||||
# both have to be installed before `dr_ui::run`, because a panic during startup
|
||||
# is exactly the one they exist to catch and record (NFR-OPS-1, NFR-OPS-2).
|
||||
dr-plat.workspace = true
|
||||
anyhow.workspace = true
|
||||
env_logger.workspace = true
|
||||
|
||||
@@ -4,11 +4,21 @@
|
||||
|
||||
use std::path::PathBuf;
|
||||
|
||||
use dr_plat::diagnostics::Installed;
|
||||
|
||||
fn main() -> anyhow::Result<()> {
|
||||
env_logger::Builder::from_env(env_logger::Env::default().default_filter_or(
|
||||
// Built rather than `init`ed, so the same logger can be handed to the
|
||||
// diagnostics tee: `env_logger` keeps writing to stderr exactly as before,
|
||||
// and every record it accepts is also appended to the on-disk log
|
||||
// (NFR-OPS-1). `filter()` is asked afterwards because the environment may
|
||||
// have overridden the default below, and the file must not be quieter than
|
||||
// the terminal.
|
||||
let console = env_logger::Builder::from_env(env_logger::Env::default().default_filter_or(
|
||||
"info,wgpu_core=warn,wgpu_hal=warn,zbus=warn,tracing=warn,calloop=warn,rawler=warn",
|
||||
))
|
||||
.init();
|
||||
.build();
|
||||
let level = console.filter();
|
||||
let logging = dr_plat::diagnostics::install(Box::new(console), level);
|
||||
|
||||
// Immediately after the logger and before anything that could fail. Until
|
||||
// now a panic on desktop went to stderr and died with the terminal, which
|
||||
@@ -19,6 +29,12 @@ fn main() -> anyhow::Result<()> {
|
||||
dr_plat::crash::install(env!("CARGO_PKG_VERSION"));
|
||||
|
||||
log::info!("DarkRoom v{}", env!("CARGO_PKG_VERSION"));
|
||||
// First thing in the file, so a user asked for "the log" can find it
|
||||
// without being told a path over the phone.
|
||||
match &logging {
|
||||
Installed::ToFile(path) => log::info!("logging to {}", path.display()),
|
||||
Installed::ConsoleOnly(why) => log::warn!("no log file this session: {why}"),
|
||||
}
|
||||
|
||||
let paths: Vec<PathBuf> = std::env::args().skip(1).map(PathBuf::from).collect();
|
||||
if paths.is_empty() {
|
||||
|
||||
@@ -8,7 +8,12 @@ license.workspace = true
|
||||
[dependencies]
|
||||
dr-types.workspace = true
|
||||
thiserror.workspace = true
|
||||
log.workspace = true
|
||||
# `std` is not one of `log`'s default features, and `diagnostics::install`
|
||||
# needs `set_boxed_logger`, which is gated behind it. Stated here rather than
|
||||
# left to feature unification with whichever dependant happens to pull
|
||||
# `env_logger` in — that unification holds for `cargo build --workspace` and
|
||||
# not for `cargo build -p dr-plat`.
|
||||
log = { workspace = true, features = ["std"] }
|
||||
|
||||
[target.'cfg(all(unix, not(target_os = "android")))'.dependencies]
|
||||
keyring.workspace = true
|
||||
|
||||
@@ -56,7 +56,7 @@
|
||||
//! for Android where XDG does not exist), [`redact`] (NFR-OPS-1's "automatic
|
||||
//! redaction of credentials and tokens" is the same function), and `prune`
|
||||
//! (size-capped rotation is this counting files instead of bytes). A log
|
||||
//! belongs at `state_dir().join("log")` beside `crash/`, and the diagnostics
|
||||
//! belongs beside `crash/` on desktop, and the diagnostics
|
||||
//! bundle then has one directory to collect.
|
||||
|
||||
use std::path::{Path, PathBuf};
|
||||
|
||||
@@ -0,0 +1,614 @@
|
||||
//! TRACES: NFR-OPS-1 | NFR-SEC-2
|
||||
//! A log the photographer still has tomorrow.
|
||||
//!
|
||||
//! Until this existed, everything this application knew about a failure went
|
||||
//! to stderr on the desktop and to logcat on Android, and both are gone the
|
||||
//! moment the terminal closes or the ring buffer wraps. That is tolerable when
|
||||
//! the person debugging is sitting at the machine. It is useless for the case
|
||||
//! this module is built for and which NFR-OPS-1 describes: **somebody
|
||||
//! reproduces a bug on a tablet, and then sends us a file.**
|
||||
//!
|
||||
//! Android makes that the *normal* case rather than an awkward one. A
|
||||
//! `NativeActivity` has no console. `adb logcat` requires a cable, developer
|
||||
//! mode, and — crucially — that you were already watching when it happened.
|
||||
//! The failures most worth catching are the ones that are one line long and
|
||||
//! scroll past: a class the activity's loader could not find, a permission
|
||||
//! that was refused, a root the system revoked while the app was backgrounded.
|
||||
//! A file survives all three.
|
||||
//!
|
||||
//! # The shape of it
|
||||
//!
|
||||
//! One [`LogFile`] in [`crate::state::state_dir`], teed with whatever logger
|
||||
//! the platform already had rather than replacing it — logcat stays exactly as
|
||||
//! it was, which matters because losing it while debugging would make this a
|
||||
//! downgrade. [`install`] is the whole of the wiring.
|
||||
//!
|
||||
//! Three properties, each of which is a test below:
|
||||
//!
|
||||
//! * **Capped.** Two files of [`MAX_FILE_BYTES`], so the worst case is stated
|
||||
//! rather than discovered on a full phone.
|
||||
//! * **Redacted at the sink** ([`redact`]), not at the call sites. A rule
|
||||
//! every author has to remember is not a rule.
|
||||
//! * **Durable per line.** No `BufWriter` anywhere, which is deliberate and
|
||||
//! costs a syscall per record: the line worth having is the last one before
|
||||
//! the process died, and on Android processes do not die politely — the
|
||||
//! system kills them, with no unwinding and no `Drop`. A buffered log loses
|
||||
//! precisely the evidence it was kept for.
|
||||
//!
|
||||
//! # Where the file lands
|
||||
//!
|
||||
//! * Linux: `$XDG_STATE_HOME/darkroom/darkroom.log`, else
|
||||
//! `~/.local/state/darkroom/darkroom.log`.
|
||||
//! * Android: `/sdcard/Android/data/paris.tourolle.darkroom/files/darkroom.log`,
|
||||
//! which `adb pull` reads from an ordinary release build. See
|
||||
//! [`crate::state`] for why not the internal directory, and
|
||||
//! [`redact`] for the consequence.
|
||||
//!
|
||||
//! # How crash capture should reach this
|
||||
//!
|
||||
//! It should not open its own file. A panic hook that calls `log::error!`
|
||||
//! lands here like anything else, and lands *completely*, because writes are
|
||||
//! unbuffered and per record — that is the property NFR-OPS-2 needs from
|
||||
//! NFR-OPS-1 and the reason the two are not the same file. For a crash record
|
||||
//! written separately, [`log_path`] says which log belongs with it and
|
||||
//! [`redact::redact`] is public so the record gets the same treatment as the
|
||||
//! lines around it.
|
||||
|
||||
pub mod redact;
|
||||
|
||||
use std::fmt::Write as _;
|
||||
use std::fs::{self, File, OpenOptions};
|
||||
use std::io::{self, Write as _};
|
||||
use std::path::{Path, PathBuf};
|
||||
use std::sync::{Mutex, OnceLock};
|
||||
use std::time::{SystemTime, UNIX_EPOCH};
|
||||
|
||||
use log::{LevelFilter, Log, Metadata, Record};
|
||||
|
||||
/// The current log, and — after one rotation — `darkroom.log.1` beside it.
|
||||
const FILE_NAME: &str = "darkroom.log";
|
||||
|
||||
/// The stated cap, per file. With [`RETAINED_GENERATIONS`] the application
|
||||
/// occupies at most 8 MiB of the state directory, ever.
|
||||
///
|
||||
/// Chosen against the retrieval, not against the disk: this is roughly forty
|
||||
/// thousand lines at `info`, which is a long session's worth of context, and
|
||||
/// it is small enough that `adb pull` over USB is instant and a user can
|
||||
/// attach it to a message without thinking about it. A larger cap would buy
|
||||
/// history nobody reads at the price of a file nobody sends.
|
||||
pub const MAX_FILE_BYTES: u64 = 4 * 1024 * 1024;
|
||||
|
||||
/// How many rotated files are kept behind the current one.
|
||||
///
|
||||
/// One. The reason to keep any is that the interesting event often precedes
|
||||
/// the rotation that a burst of retry logging then caused; the reason not to
|
||||
/// keep more is that the worst case has to be a number this module can state.
|
||||
pub const RETAINED_GENERATIONS: usize = 1;
|
||||
|
||||
/// The longest one record may be before it is cut short.
|
||||
///
|
||||
/// A guard against a single `{:?}` on something large — a decoded buffer, a
|
||||
/// face embedding, an entire WebDAV response — turning the whole cap into one
|
||||
/// unreadable line and evicting everything that led up to it. Generous enough
|
||||
/// that no real message reaches it.
|
||||
pub const MAX_LINE_BYTES: usize = 8 * 1024;
|
||||
|
||||
const TRUNCATION_MARK: &str = "…[truncated]";
|
||||
|
||||
/// Set by [`install`] once, so crash capture can name the file without
|
||||
/// re-deriving the directory and possibly disagreeing about it.
|
||||
static LOG_PATH: OnceLock<PathBuf> = OnceLock::new();
|
||||
|
||||
/// What [`install`] managed, said as data rather than as a log line — because
|
||||
/// at the moment it is decided there is no logger to say it with.
|
||||
///
|
||||
/// The caller logs it as the first line of the session, which is how the file
|
||||
/// ends up naming itself to anyone reading logcat over the user's shoulder.
|
||||
#[derive(Debug, Clone)]
|
||||
pub enum Installed {
|
||||
/// The tee is live and this is the file to ask the user for.
|
||||
ToFile(PathBuf),
|
||||
/// Logging works, but only where it always did, and this is why. A
|
||||
/// read-only or missing state directory is not a reason to start the
|
||||
/// application without a logger.
|
||||
ConsoleOnly(String),
|
||||
}
|
||||
|
||||
/// Where this session is logging, if it is logging to a file at all.
|
||||
pub fn log_path() -> Option<PathBuf> {
|
||||
LOG_PATH.get().cloned()
|
||||
}
|
||||
|
||||
/// Install the file sink alongside the logger the platform already provides.
|
||||
///
|
||||
/// `console` is the platform's own logger — `env_logger`'s on the desktop,
|
||||
/// `android_logger`'s on a device — and it keeps receiving every record it
|
||||
/// would have received. `level` is the maximum level to let through globally;
|
||||
/// pass whatever the console logger was built to filter at, so the two agree.
|
||||
///
|
||||
/// Call it exactly once, first thing, and *after*
|
||||
/// [`crate::state::set_state_dir`] on any platform that needs to declare a
|
||||
/// directory.
|
||||
pub fn install(console: Box<dyn Log>, level: LevelFilter) -> Installed {
|
||||
let dir = crate::state::state_dir();
|
||||
|
||||
let (file, outcome) = match LogFile::open_in(&dir, MAX_FILE_BYTES) {
|
||||
Ok(file) => {
|
||||
let path = file.path().to_path_buf();
|
||||
let _ = LOG_PATH.set(path.clone());
|
||||
(Some(file), Installed::ToFile(path))
|
||||
}
|
||||
Err(e) => (
|
||||
None,
|
||||
Installed::ConsoleOnly(format!("{} is not writable: {e}", dir.display())),
|
||||
),
|
||||
};
|
||||
|
||||
if log::set_boxed_logger(Box::new(Tee { console, file })).is_err() {
|
||||
// Something installed a logger before us. Saying so is the only useful
|
||||
// response: whatever it was is still logging, and the file is not.
|
||||
return Installed::ConsoleOnly("a logger was already installed".to_string());
|
||||
}
|
||||
log::set_max_level(level);
|
||||
outcome
|
||||
}
|
||||
|
||||
/// The platform's logger and ours, both fed from every record.
|
||||
struct Tee {
|
||||
console: Box<dyn Log>,
|
||||
file: Option<LogFile>,
|
||||
}
|
||||
|
||||
impl Log for Tee {
|
||||
fn enabled(&self, metadata: &Metadata<'_>) -> bool {
|
||||
self.console.enabled(metadata)
|
||||
}
|
||||
|
||||
fn log(&self, record: &Record<'_>) {
|
||||
// The console first, and unconditionally: it applies its own filter,
|
||||
// and on Android it is the thing a developer is watching live.
|
||||
self.console.log(record);
|
||||
|
||||
if let Some(file) = &self.file {
|
||||
// The same gate the console applies, so the file is a transcript
|
||||
// of logcat rather than a different log with different contents.
|
||||
// It can be a slight superset — `env_logger`'s message-regex
|
||||
// filter is applied inside its `log` and not by `enabled` — and a
|
||||
// superset is the right way round for a file nobody is watching.
|
||||
if self.console.enabled(record.metadata()) {
|
||||
file.write_line(&format_record(record));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
fn flush(&self) {
|
||||
self.console.flush();
|
||||
// Nothing to do for the file: there is no buffer to flush, which is
|
||||
// the point. See the module documentation.
|
||||
}
|
||||
}
|
||||
|
||||
/// The log file itself, with its rotation.
|
||||
///
|
||||
/// Cheap to construct and safe to share: every write takes a mutex, and the
|
||||
/// formatting and redaction that precede it happen outside the lock, so a
|
||||
/// thread logging cannot hold up an unrelated one for longer than a `write`.
|
||||
pub struct LogFile {
|
||||
path: PathBuf,
|
||||
/// The single retained generation. Named once here rather than derived at
|
||||
/// each rotation, so the two cannot drift.
|
||||
previous: PathBuf,
|
||||
cap: u64,
|
||||
open: Mutex<Open>,
|
||||
}
|
||||
|
||||
struct Open {
|
||||
file: File,
|
||||
/// Bytes in the *current* file. Seeded from the file's length on open
|
||||
/// rather than from zero — otherwise an application restarted often enough
|
||||
/// would append past the cap forever and NFR-OPS-1's "size-capped" would
|
||||
/// hold only within a single run.
|
||||
written: u64,
|
||||
}
|
||||
|
||||
impl LogFile {
|
||||
/// Open (or create) the log in `dir`, creating the directory if needed.
|
||||
///
|
||||
/// `cap` is per file; the directory holds at most `cap * 2`. Public with
|
||||
/// an explicit cap because the tests need a small one — a rotation test
|
||||
/// that had to write 4 MiB would be a rotation test nobody runs.
|
||||
pub fn open_in(dir: &Path, cap: u64) -> io::Result<Self> {
|
||||
fs::create_dir_all(dir)?;
|
||||
let path = dir.join(FILE_NAME);
|
||||
let file = open_append(&path)?;
|
||||
// A failure to stat a file we just opened is not worth refusing to log
|
||||
// over; treating it as empty costs at most one late rotation.
|
||||
let written = file.metadata().map(|m| m.len()).unwrap_or(0);
|
||||
Ok(Self {
|
||||
path,
|
||||
previous: dir.join(format!("{FILE_NAME}.1")),
|
||||
cap,
|
||||
open: Mutex::new(Open { file, written }),
|
||||
})
|
||||
}
|
||||
|
||||
/// The file to ask the user to send.
|
||||
pub fn path(&self) -> &Path {
|
||||
&self.path
|
||||
}
|
||||
|
||||
/// Redact, cap, and append one record.
|
||||
///
|
||||
/// Infallible by design. A logger that panicked, or that tried to report
|
||||
/// its own failure through `log`, would take the application down or
|
||||
/// recurse; a log line lost to a full disk is a smaller problem than
|
||||
/// either.
|
||||
pub fn write_line(&self, line: &str) {
|
||||
// Both before the lock: neither can block, and neither should make
|
||||
// another thread's `write` wait.
|
||||
let mut line = redact::redact(line);
|
||||
truncate_to(&mut line, MAX_LINE_BYTES);
|
||||
line.push('\n');
|
||||
|
||||
// A poisoned mutex means another thread panicked mid-write. The log is
|
||||
// exactly what is wanted at that moment, so carry on with whatever
|
||||
// state it left: the worst case is one interleaved line.
|
||||
let mut open = self.open.lock().unwrap_or_else(|e| e.into_inner());
|
||||
|
||||
let len = line.len() as u64;
|
||||
if open.written > 0 && open.written + len > self.cap {
|
||||
// A failed rotation is not a reason to drop the record. The only
|
||||
// way `rename` fails on a directory we opened a file in is that
|
||||
// the directory has gone, in which case the write below fails too
|
||||
// and the line is lost either way.
|
||||
let _ = self.rotate(&mut open);
|
||||
}
|
||||
|
||||
if open.file.write_all(line.as_bytes()).is_ok() {
|
||||
open.written += len;
|
||||
}
|
||||
}
|
||||
|
||||
/// `darkroom.log` becomes `darkroom.log.1`; the previous `.1` is dropped.
|
||||
///
|
||||
/// Rename rather than copy-and-truncate, so a reader holding the old file
|
||||
/// keeps reading a whole file and never sees it shrink under them. The old
|
||||
/// descriptor stays valid against the renamed inode until it is replaced
|
||||
/// on the next line.
|
||||
fn rotate(&self, open: &mut Open) -> io::Result<()> {
|
||||
let _ = fs::remove_file(&self.previous);
|
||||
fs::rename(&self.path, &self.previous)?;
|
||||
open.file = open_append(&self.path)?;
|
||||
open.written = 0;
|
||||
Ok(())
|
||||
}
|
||||
}
|
||||
|
||||
fn open_append(path: &Path) -> io::Result<File> {
|
||||
let mut options = OpenOptions::new();
|
||||
options.create(true).append(true);
|
||||
// The log names the user's photographs and the shape of their library,
|
||||
// which is nobody else's business on a shared machine. Applied at
|
||||
// creation only, which is all that is needed, and ignored by the
|
||||
// FAT-derived filesystem Android presents as external storage — where the
|
||||
// directory is already scoped to this application.
|
||||
#[cfg(unix)]
|
||||
{
|
||||
use std::os::unix::fs::OpenOptionsExt as _;
|
||||
options.mode(0o600);
|
||||
}
|
||||
options.open(path)
|
||||
}
|
||||
|
||||
/// One record as one line.
|
||||
///
|
||||
/// The thread name is here and not in `env_logger`'s default format because of
|
||||
/// what it costs to leave out on Android: the failure this module was written
|
||||
/// to catch is a class the activity's loader will not resolve, and whether the
|
||||
/// call came from `android_main`'s thread or from a worker is the entire
|
||||
/// diagnosis. Unnamed threads report their id instead of nothing, so two
|
||||
/// interleaved workers can still be told apart.
|
||||
fn format_record(record: &Record<'_>) -> String {
|
||||
let mut line = String::with_capacity(128);
|
||||
push_timestamp(&mut line, SystemTime::now());
|
||||
|
||||
let thread = std::thread::current();
|
||||
let _ = match thread.name() {
|
||||
Some(name) => write!(line, " {:<5} [{name}]", record.level()),
|
||||
None => write!(line, " {:<5} [{:?}]", record.level(), thread.id()),
|
||||
};
|
||||
let _ = write!(line, " {}: {}", record.target(), record.args());
|
||||
line
|
||||
}
|
||||
|
||||
/// `2026-08-30T12:34:56.789Z`, in UTC.
|
||||
///
|
||||
/// Hand-rolled rather than reached for from a crate. `chrono` and `jiff` are
|
||||
/// both already in the lock file, and pulling either into `dr-plat` would put
|
||||
/// a new dependency in the Android cross-compile for twenty lines of
|
||||
/// arithmetic that cannot change — which is the same reasoning the workspace
|
||||
/// manifest applies to TLS, SQLite and lens profiles, at a much smaller scale.
|
||||
///
|
||||
/// UTC and not local time, deliberately: a log is read by somebody other than
|
||||
/// the person who produced it, and a timestamp with no zone in it is a
|
||||
/// timestamp that has to be guessed at. Milliseconds are there to line the
|
||||
/// file up against a logcat capture of the same session.
|
||||
fn push_timestamp(out: &mut String, now: SystemTime) {
|
||||
let since_epoch = now.duration_since(UNIX_EPOCH).unwrap_or_default();
|
||||
let secs = since_epoch.as_secs() as i64;
|
||||
let millis = since_epoch.subsec_millis();
|
||||
|
||||
// `div_euclid`, not `/`: the truncating division would put every instant
|
||||
// in the six hours before 1970 on the wrong day. A clock that has not been
|
||||
// set yet reports one of them.
|
||||
let (year, month, day) = civil_from_days(secs.div_euclid(86_400));
|
||||
let second_of_day = secs.rem_euclid(86_400);
|
||||
|
||||
let _ = write!(
|
||||
out,
|
||||
"{year:04}-{month:02}-{day:02}T{:02}:{:02}:{:02}.{millis:03}Z",
|
||||
second_of_day / 3600,
|
||||
(second_of_day % 3600) / 60,
|
||||
second_of_day % 60,
|
||||
);
|
||||
}
|
||||
|
||||
/// Days since 1970-01-01 to a proleptic Gregorian date.
|
||||
///
|
||||
/// Howard Hinnant's `civil_from_days`, which is the algorithm every date
|
||||
/// library uses underneath: it shifts the epoch to 0000-03-01 so that the
|
||||
/// leap day falls at the end of the year and the 400-year cycle divides
|
||||
/// evenly, which is what removes every branch.
|
||||
fn civil_from_days(days: i64) -> (i64, i64, i64) {
|
||||
let z = days + 719_468;
|
||||
// Split out rather than written inline: `if a { x } else { y } / n` is a
|
||||
// parse hazard in Rust, and getting it wrong here would be a silent
|
||||
// off-by-a-century for dates before 1970 rather than a compile error.
|
||||
let toward_negative_infinity = if z >= 0 { z } else { z - 146_096 };
|
||||
let era = toward_negative_infinity / 146_097;
|
||||
let day_of_era = z - era * 146_097;
|
||||
let year_of_era =
|
||||
(day_of_era - day_of_era / 1460 + day_of_era / 36_524 - day_of_era / 146_096) / 365;
|
||||
let year = year_of_era + era * 400;
|
||||
let day_of_year = day_of_era - (365 * year_of_era + year_of_era / 4 - year_of_era / 100);
|
||||
let month_shifted = (5 * day_of_year + 2) / 153;
|
||||
let day = day_of_year - (153 * month_shifted + 2) / 5 + 1;
|
||||
let month = if month_shifted < 10 {
|
||||
month_shifted + 3
|
||||
} else {
|
||||
month_shifted - 9
|
||||
};
|
||||
(if month <= 2 { year + 1 } else { year }, month, day)
|
||||
}
|
||||
|
||||
/// Cut a line to `max` bytes without splitting a character in half.
|
||||
fn truncate_to(line: &mut String, max: usize) {
|
||||
if line.len() <= max {
|
||||
return;
|
||||
}
|
||||
let mut cut = max.saturating_sub(TRUNCATION_MARK.len());
|
||||
while cut > 0 && !line.is_char_boundary(cut) {
|
||||
cut -= 1;
|
||||
}
|
||||
line.truncate(cut);
|
||||
line.push_str(TRUNCATION_MARK);
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
|
||||
/// An empty directory of this test's own. The convention elsewhere in the
|
||||
/// workspace (`dr_decode::base_curve`), and it matters more here: two
|
||||
/// tests sharing a log directory would rotate each other's files.
|
||||
fn a_log_dir(name: &str) -> PathBuf {
|
||||
let dir = std::env::temp_dir().join(format!("darkroom-diagnostics-{name}"));
|
||||
let _ = fs::remove_dir_all(&dir);
|
||||
fs::create_dir_all(&dir).expect("a writable temp directory");
|
||||
dir
|
||||
}
|
||||
|
||||
fn read(path: &Path) -> String {
|
||||
fs::read_to_string(path).unwrap_or_default()
|
||||
}
|
||||
|
||||
/// Long enough that a handful of them cross a small cap, short enough that
|
||||
/// the arithmetic in each test stays readable.
|
||||
fn a_line(n: usize) -> String {
|
||||
format!("{n:04} scanning /home/duncan/Pictures/2026/Iceland for images")
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_log_stays_under_its_stated_cap() {
|
||||
// **This is NFR-OPS-1's "size-capped".** Without rotation a phone left
|
||||
// running fills its state directory and the failure lands on the user
|
||||
// as "storage full", days after the logging that caused it.
|
||||
let dir = a_log_dir("cap");
|
||||
let cap = 4096;
|
||||
let log = LogFile::open_in(&dir, cap).expect("opens");
|
||||
|
||||
for n in 0..500 {
|
||||
log.write_line(&a_line(n));
|
||||
}
|
||||
|
||||
let current = fs::metadata(dir.join(FILE_NAME))
|
||||
.expect("a current log")
|
||||
.len();
|
||||
assert!(current <= cap, "the current log is {current} bytes, over {cap}");
|
||||
|
||||
let previous = fs::metadata(dir.join(format!("{FILE_NAME}.1")))
|
||||
.expect("a rotated log, since 500 lines cannot fit in 4 KiB")
|
||||
.len();
|
||||
assert!(
|
||||
previous <= cap,
|
||||
"the rotated log is {previous} bytes, over {cap}"
|
||||
);
|
||||
|
||||
assert!(
|
||||
!dir.join(format!("{FILE_NAME}.2")).exists(),
|
||||
"only {RETAINED_GENERATIONS} generation is kept; a second would make the \
|
||||
worst case unstatable"
|
||||
);
|
||||
assert!(
|
||||
current + previous <= cap * 2,
|
||||
"the whole directory must fit in twice the cap"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn rotation_keeps_the_newest_lines_and_drops_the_oldest() {
|
||||
// Which half survives is the whole value of the feature: the user
|
||||
// reports a bug and the interesting lines are the last ones.
|
||||
let dir = a_log_dir("newest");
|
||||
let log = LogFile::open_in(&dir, 4096).expect("opens");
|
||||
for n in 0..500 {
|
||||
log.write_line(&a_line(n));
|
||||
}
|
||||
|
||||
let current = read(&dir.join(FILE_NAME));
|
||||
let previous = read(&dir.join(format!("{FILE_NAME}.1")));
|
||||
assert!(
|
||||
current.contains(&a_line(499)),
|
||||
"the last line written must be in the current log"
|
||||
);
|
||||
let oldest = a_line(0);
|
||||
assert!(
|
||||
!current.contains(&oldest) && !previous.contains(&oldest),
|
||||
"the oldest lines are what a cap gives up"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_line_survives_a_process_restart() {
|
||||
// The requirement in one test. Everything else about this module is an
|
||||
// implementation detail of "the user reproduces it, quits, and sends
|
||||
// us the file".
|
||||
let dir = a_log_dir("restart");
|
||||
{
|
||||
let log = LogFile::open_in(&dir, MAX_FILE_BYTES).expect("opens");
|
||||
log.write_line("the failure the user is about to report");
|
||||
} // the process ends here
|
||||
|
||||
let log = LogFile::open_in(&dir, MAX_FILE_BYTES).expect("reopens");
|
||||
log.write_line("the next launch");
|
||||
|
||||
let text = read(&dir.join(FILE_NAME));
|
||||
assert!(
|
||||
text.contains("the failure the user is about to report"),
|
||||
"a restart truncated the log: {text}"
|
||||
);
|
||||
assert!(text.contains("the next launch"));
|
||||
assert!(
|
||||
text.find("the failure") < text.find("the next launch"),
|
||||
"the second session must append, not prepend"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_cap_survives_a_restart_too() {
|
||||
// The bug this exists to prevent: seeding `written` from zero on open
|
||||
// rather than from the file's length. Nothing looks wrong until an
|
||||
// application that restarts often has a log of unbounded size, which
|
||||
// is the one failure mode a cap is for.
|
||||
let dir = a_log_dir("restart-cap");
|
||||
let cap = 2048;
|
||||
for _ in 0..40 {
|
||||
let log = LogFile::open_in(&dir, cap).expect("opens");
|
||||
for n in 0..5 {
|
||||
log.write_line(&a_line(n));
|
||||
}
|
||||
}
|
||||
|
||||
let current = fs::metadata(dir.join(FILE_NAME))
|
||||
.expect("a current log")
|
||||
.len();
|
||||
assert!(
|
||||
current <= cap,
|
||||
"forty restarts appended {current} bytes into a {cap}-byte file"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_credential_never_reaches_the_file() {
|
||||
// **NFR-SEC-2 at the sink**, which is the placement the requirement
|
||||
// depends on: the call site here has done nothing wrong that a
|
||||
// reviewer would catch, and the credential still does not land.
|
||||
let dir = a_log_dir("redaction");
|
||||
let log = LogFile::open_in(&dir, MAX_FILE_BYTES).expect("opens");
|
||||
log.write_line(r#"login response {"loginName":"duncan","appPassword":"wYh3K8mLpQr2"}"#);
|
||||
log.write_line("PUT https://duncan:hunter2@cloud.example/remote.php/dav failed");
|
||||
|
||||
let text = read(&dir.join(FILE_NAME));
|
||||
assert!(
|
||||
!text.contains("wYh3K8mLpQr2"),
|
||||
"an app password reached the log: {text}"
|
||||
);
|
||||
assert!(
|
||||
!text.contains("hunter2"),
|
||||
"a URL password reached the log: {text}"
|
||||
);
|
||||
assert!(
|
||||
text.contains("cloud.example") && text.contains("duncan"),
|
||||
"the diagnostic part must survive the redaction: {text}"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn one_enormous_record_cannot_evict_the_whole_log() {
|
||||
// A `{:?}` on something large — a decoded buffer, an embedding — must
|
||||
// cost a line rather than the file.
|
||||
let dir = a_log_dir("truncation");
|
||||
let log = LogFile::open_in(&dir, MAX_FILE_BYTES).expect("opens");
|
||||
log.write_line("a line worth keeping");
|
||||
log.write_line(&"x".repeat(MAX_LINE_BYTES * 4));
|
||||
|
||||
let text = read(&dir.join(FILE_NAME));
|
||||
assert!(text.contains("a line worth keeping"));
|
||||
assert!(
|
||||
text.contains(TRUNCATION_MARK),
|
||||
"the oversized record should have been cut short"
|
||||
);
|
||||
assert!(
|
||||
text.len() < MAX_LINE_BYTES * 2,
|
||||
"the oversized record was written whole: {} bytes",
|
||||
text.len()
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn truncation_never_splits_a_character() {
|
||||
let mut line = "é".repeat(64);
|
||||
truncate_to(&mut line, 40);
|
||||
// The assertion is that this is still a `String` at all — the failure
|
||||
// is a panic inside `truncate` on a non-boundary index — plus that it
|
||||
// says it was cut.
|
||||
assert!(line.ends_with(TRUNCATION_MARK));
|
||||
assert!(line.len() <= 40);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_timestamp_is_utc_and_sortable() {
|
||||
let mut out = String::new();
|
||||
let an_instant = UNIX_EPOCH + std::time::Duration::from_millis(1_700_000_000_123);
|
||||
push_timestamp(&mut out, an_instant);
|
||||
assert_eq!(out, "2023-11-14T22:13:20.123Z");
|
||||
|
||||
let mut epoch = String::new();
|
||||
push_timestamp(&mut epoch, UNIX_EPOCH);
|
||||
assert_eq!(epoch, "1970-01-01T00:00:00.000Z");
|
||||
|
||||
// Lexicographic order is chronological order, which is what makes
|
||||
// `sort` and a plain `grep` on a date prefix work.
|
||||
assert!(epoch < out);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_calendar_handles_the_cases_that_are_usually_wrong() {
|
||||
assert_eq!(civil_from_days(0), (1970, 1, 1));
|
||||
assert_eq!(civil_from_days(19_723), (2024, 1, 1));
|
||||
// 2024 is a leap year; 2100 will not be, and the century rule is the
|
||||
// one every hand-rolled calendar gets wrong.
|
||||
assert_eq!(civil_from_days(19_782), (2024, 2, 29));
|
||||
assert_eq!(civil_from_days(-1), (1969, 12, 31));
|
||||
}
|
||||
}
|
||||
@@ -0,0 +1,467 @@
|
||||
//! TRACES: NFR-SEC-2
|
||||
//! Taking the credentials back out of a line that already contains them.
|
||||
//!
|
||||
//! NFR-SEC-2 says credentials are never written to logs. NFR-OPS-1 restates it
|
||||
//! as an obligation on the diagnostics path specifically — "automatic
|
||||
//! redaction of credentials and tokens" — and the word doing the work is
|
||||
//! *automatic*. A rule that every call site must remember is not a rule; it is
|
||||
//! a hope, and it fails the first time somebody debugging a 401 writes
|
||||
//! `log::debug!("{response:?}")` at two in the morning and forgets to take it
|
||||
//! out. So the redaction happens once, at the sink, on the formatted line,
|
||||
//! after every call site has had its say.
|
||||
//!
|
||||
//! On Android this is not a defence-in-depth nicety. The log lives in the
|
||||
//! app's *external* directory so that `adb pull` can reach it
|
||||
//! ([`crate::state`]), which means anyone holding the device can read it, and
|
||||
//! a Nextcloud app password in there is a working credential for the user's
|
||||
//! whole server.
|
||||
//!
|
||||
//! # What it looks for, and why not a regex
|
||||
//!
|
||||
//! A credential in a log line is nearly always adjacent to a word that names
|
||||
//! it — `appPassword`, `Authorization`, `token=` — because it got there
|
||||
//! through a `Debug` impl, a serialised request, or a URL. That adjacency is
|
||||
//! the only reliable signal there is: the app password Nextcloud issues is an
|
||||
//! opaque 72-character string with no structure to match on, so a scanner that
|
||||
//! hunted for *secret-shaped* text would find every base64 blob and every
|
||||
//! content hash in the file and redact those instead.
|
||||
//!
|
||||
//! Hence a keyword scanner, hand-rolled rather than `regex`. The workspace has
|
||||
//! no regex dependency and this is not worth acquiring one for — the grammar
|
||||
//! is "a known word, an `=` or a `:`, a value" plus the two forms that carry a
|
||||
//! credential with no keyword at all: an `Authorization` scheme and a URL's
|
||||
//! userinfo. Three rules, each of which fits in a function and has a test.
|
||||
//!
|
||||
//! # What it deliberately leaves alone
|
||||
//!
|
||||
//! **Filesystem paths, and the names of the user's own photographs.** They are
|
||||
//! not in NFR-SEC-2's list, they are not in NFR-SEC-5's, and they are the
|
||||
//! single most useful thing in a log about a file that would not open. A
|
||||
//! diagnostics file that says "failed to decode <redacted>" is not a
|
||||
//! diagnostic. The rule NFR-OPS-1 states — an explicit preview-and-consent
|
||||
//! step before anything leaves the device — is the one that governs paths, and
|
||||
//! it governs them better than scrubbing would, because it lets the user look.
|
||||
//!
|
||||
//! **Face data (NFR-SEC-5).** Not because it is permitted here, but because
|
||||
//! this is the wrong instrument for it. An embedding is 512 floats; by the
|
||||
//! time one has reached a formatted log line, redacting it would be a guess at
|
||||
//! what a `[f32]` looks like in prose. NFR-SEC-5 makes confinement
|
||||
//! *structural* — "the code path does not exist" — and the sink's contribution
|
||||
//! to that is to not be one: it opens no bundle, uploads nothing, and adds no
|
||||
//! new route off the device. The one thing it does do about the shape of the
|
||||
//! problem is cap the line length (see [`super::MAX_LINE_BYTES`]), so a
|
||||
//! `{embedding:?}` that should never have been written costs kilobytes rather
|
||||
//! than megabytes and is obvious in the file rather than buried.
|
||||
|
||||
/// What a redacted value is replaced by. Chosen to be greppable and obviously
|
||||
/// not a value: a reader finding this in a log knows something was removed,
|
||||
/// which an empty string or a row of asterisks would not tell them.
|
||||
pub const PLACEHOLDER: &str = "<redacted>";
|
||||
|
||||
/// The words that introduce a credential.
|
||||
///
|
||||
/// Matched case-insensitively and only on a whole-word boundary, so `password`
|
||||
/// does not fire inside `passwordless` and `token` does not fire inside
|
||||
/// `tokenizer`. Longer entries are not redundant with shorter ones for the
|
||||
/// same reason — `apppassword` has no boundary before its `password`, so
|
||||
/// without its own entry `"appPassword": "…"` would sail through, and that is
|
||||
/// the exact key Nextcloud's Login Flow v2 returns the credential under
|
||||
/// (`dr_sync_nextcloud::auth::AppCredentials`).
|
||||
const SENSITIVE_KEYS: &[&str] = &[
|
||||
"apppassword",
|
||||
"app_password",
|
||||
"password",
|
||||
"passwd",
|
||||
"pwd",
|
||||
"access_token",
|
||||
"refresh_token",
|
||||
"id_token",
|
||||
"apikey",
|
||||
"api_key",
|
||||
"authorization",
|
||||
"credentials",
|
||||
"credential",
|
||||
"secret",
|
||||
"token",
|
||||
];
|
||||
|
||||
/// The `Authorization` schemes that carry the credential in the value rather
|
||||
/// than after a keyword. `Basic dXNlcjpwdw==` is `login:password` in base64 —
|
||||
/// reversible with one shell command — and every WebDAV request this app makes
|
||||
/// is signed with one (`dr_sync_nextcloud`, `basic_auth`).
|
||||
const AUTH_SCHEMES: &[&str] = &["basic ", "bearer "];
|
||||
|
||||
/// Remove anything that looks like a credential from one formatted line.
|
||||
///
|
||||
/// Cheap enough for the write path: one ASCII-lowercased copy and a single
|
||||
/// left-to-right pass, with no allocation per match beyond the output string.
|
||||
/// Non-ASCII is untouched by the lowercasing, which is what keeps the byte
|
||||
/// offsets of the copy and the original identical — `to_lowercase` would not,
|
||||
/// and a one-byte drift would slice a message mid-character.
|
||||
pub fn redact(line: &str) -> String {
|
||||
let lower = line.to_ascii_lowercase();
|
||||
let low = lower.as_bytes();
|
||||
|
||||
let mut out = String::with_capacity(line.len());
|
||||
// Everything from here to the current position is verbatim text not yet
|
||||
// copied, so an unmatched line copies itself in one `push_str`.
|
||||
let mut copied = 0usize;
|
||||
let mut i = 0usize;
|
||||
|
||||
while i < low.len() {
|
||||
match secret_at(low, i) {
|
||||
Some((start, end)) => {
|
||||
out.push_str(&line[copied..start]);
|
||||
out.push_str(PLACEHOLDER);
|
||||
copied = end;
|
||||
i = end;
|
||||
}
|
||||
None => i += 1,
|
||||
}
|
||||
}
|
||||
|
||||
out.push_str(&line[copied..]);
|
||||
out
|
||||
}
|
||||
|
||||
/// The byte range of a secret beginning at or just after `i`, if there is one.
|
||||
///
|
||||
/// Every rule is anchored on an ASCII byte, and every boundary it returns is
|
||||
/// found by scanning for ASCII delimiters — which cannot occur inside a
|
||||
/// multi-byte UTF-8 sequence — so the ranges are always char boundaries even
|
||||
/// though the scan is over bytes.
|
||||
fn secret_at(low: &[u8], i: usize) -> Option<(usize, usize)> {
|
||||
if let Some(range) = keyed_value_at(low, i) {
|
||||
return Some(range);
|
||||
}
|
||||
if let Some(range) = bare_scheme_at(low, i) {
|
||||
return Some(range);
|
||||
}
|
||||
url_userinfo_at(low, i)
|
||||
}
|
||||
|
||||
/// `password=hunter2`, `"appPassword": "…"`, `Authorization: Basic …`.
|
||||
fn keyed_value_at(low: &[u8], i: usize) -> Option<(usize, usize)> {
|
||||
if i > 0 && is_word_byte(low[i - 1]) {
|
||||
return None;
|
||||
}
|
||||
for key in SENSITIVE_KEYS {
|
||||
if !low[i..].starts_with(key.as_bytes()) {
|
||||
continue;
|
||||
}
|
||||
let after = i + key.len();
|
||||
// A whole word, so `tokenizer` is not a token and `secretary` is not
|
||||
// a secret. `continue` rather than `return`: a short key failing its
|
||||
// boundary test must not mask a longer one that would have passed,
|
||||
// which is how `credential` would otherwise swallow `credentials`.
|
||||
if low.get(after).is_some_and(|b| is_word_byte(*b)) {
|
||||
continue;
|
||||
}
|
||||
return value_after_assignment(low, after);
|
||||
}
|
||||
None
|
||||
}
|
||||
|
||||
/// The value introduced by an `=` or a `:` following a key.
|
||||
///
|
||||
/// Requiring one of those two is what keeps prose out of it. Plenty of log
|
||||
/// lines say the word — "password rejected", "no token yet" — and a rule that
|
||||
/// redacted the next word after any mention of a credential would make those
|
||||
/// lines unreadable while protecting nothing.
|
||||
fn value_after_assignment(low: &[u8], mut j: usize) -> Option<(usize, usize)> {
|
||||
j = skip_spaces(low, j);
|
||||
// The closing quote of a quoted key: `"password": "…"`.
|
||||
if matches!(low.get(j), Some(b'"' | b'\'')) {
|
||||
j = skip_spaces(low, j + 1);
|
||||
}
|
||||
if !matches!(low.get(j), Some(b'=' | b':')) {
|
||||
return None;
|
||||
}
|
||||
j = skip_spaces(low, j + 1);
|
||||
|
||||
// An opening quote is stepped over rather than redacted, so the result is
|
||||
// still shaped like what it replaced: `"password": "<redacted>"` reads as
|
||||
// a redacted field, `"password": <redacted>` reads as damage.
|
||||
let quote = match low.get(j) {
|
||||
Some(&q) if q == b'"' || q == b'\'' => {
|
||||
j += 1;
|
||||
Some(q)
|
||||
}
|
||||
_ => None,
|
||||
};
|
||||
|
||||
// `Authorization: Basic dXNlcjpwdw==` — keep the scheme, take the rest.
|
||||
// Which scheme was in use is diagnostic (a request signed as `Bearer`
|
||||
// where the app only ever issues `Basic` is a bug worth seeing) and it is
|
||||
// not itself a secret.
|
||||
for scheme in AUTH_SCHEMES {
|
||||
if low[j..].starts_with(scheme.as_bytes()) {
|
||||
j = skip_spaces(low, j + scheme.len());
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
let start = j;
|
||||
let end = match quote {
|
||||
Some(q) => low[start..]
|
||||
.iter()
|
||||
.position(|b| *b == q)
|
||||
.map_or(low.len(), |n| start + n),
|
||||
None => value_end(low, start),
|
||||
};
|
||||
|
||||
// `password=` with nothing after it has nothing to hide, and replacing an
|
||||
// empty value would only make the line say less.
|
||||
(end > start).then_some((start, end))
|
||||
}
|
||||
|
||||
/// `Basic dXNlcjpwdw==` on its own, with no keyword in front of it — a header
|
||||
/// dumped by its value, or a `curl` line pasted into a message.
|
||||
fn bare_scheme_at(low: &[u8], i: usize) -> Option<(usize, usize)> {
|
||||
if i > 0 && is_word_byte(low[i - 1]) {
|
||||
return None;
|
||||
}
|
||||
let scheme = AUTH_SCHEMES
|
||||
.iter()
|
||||
.find(|scheme| low[i..].starts_with(scheme.as_bytes()))?;
|
||||
let start = skip_spaces(low, i + scheme.len());
|
||||
let end = value_end(low, start);
|
||||
// Unlike the keyed rule, nothing here has established that a credential
|
||||
// was intended — and `basic` is an ordinary English word. "using basic
|
||||
// sRGB as the fallback" must survive, so the token itself has to look the
|
||||
// part.
|
||||
looks_like_a_credential(&low[start..end]).then_some((start, end))
|
||||
}
|
||||
|
||||
/// Whether an unkeyed token is credential-shaped.
|
||||
///
|
||||
/// Base64 is long and drawn from a fixed alphabet; a word of prose is neither.
|
||||
/// Sixteen bytes is comfortably below the shortest thing that could be a real
|
||||
/// `Basic` credential — base64 of `a:b` is already 8, and a Nextcloud app
|
||||
/// password is 72 — and comfortably above the words that follow "basic" in a
|
||||
/// sentence.
|
||||
fn looks_like_a_credential(token: &[u8]) -> bool {
|
||||
token.len() >= 16
|
||||
&& token.iter().all(|b| {
|
||||
b.is_ascii_alphanumeric() || matches!(*b, b'+' | b'/' | b'=' | b'-' | b'_' | b'.')
|
||||
})
|
||||
}
|
||||
|
||||
/// The password in `https://duncan:hunter2@cloud.example/remote.php/dav`.
|
||||
///
|
||||
/// URLs are logged constantly and this form survives every keyword rule, since
|
||||
/// the credential is punctuation-delimited rather than named. The host and the
|
||||
/// login are left in place: which server failed, and as whom, is the substance
|
||||
/// of a sync bug report.
|
||||
fn url_userinfo_at(low: &[u8], i: usize) -> Option<(usize, usize)> {
|
||||
if !low[i..].starts_with(b"://") {
|
||||
return None;
|
||||
}
|
||||
let authority = i + 3;
|
||||
// The authority ends at the path, the query, the fragment, or whatever
|
||||
// punctuation the surrounding prose used to end the URL.
|
||||
let end = low[authority..]
|
||||
.iter()
|
||||
.position(|b| matches!(*b, b'/' | b'?' | b'#') || is_value_delimiter(*b))
|
||||
.map_or(low.len(), |n| authority + n);
|
||||
|
||||
// The *last* `@`, because a userinfo may legally contain a percent-encoded
|
||||
// one and the host may not.
|
||||
let at = authority + low[authority..end].iter().rposition(|b| *b == b'@')?;
|
||||
let colon = authority + low[authority..at].iter().position(|b| *b == b':')?;
|
||||
|
||||
(at > colon + 1).then_some((colon + 1, at))
|
||||
}
|
||||
|
||||
fn skip_spaces(low: &[u8], mut j: usize) -> usize {
|
||||
while matches!(low.get(j), Some(b' ' | b'\t')) {
|
||||
j += 1;
|
||||
}
|
||||
j
|
||||
}
|
||||
|
||||
/// Where an unquoted value stops.
|
||||
fn value_end(low: &[u8], start: usize) -> usize {
|
||||
low[start..]
|
||||
.iter()
|
||||
.position(|b| is_value_delimiter(*b))
|
||||
.map_or(low.len(), |n| start + n)
|
||||
}
|
||||
|
||||
/// The punctuation that ends an unquoted value in every form this sees: JSON
|
||||
/// (`,` `}` `]` `"`), a query string (`&` `;`), a `Debug` impl (`,` `)` `}`),
|
||||
/// and prose (whitespace).
|
||||
fn is_value_delimiter(b: u8) -> bool {
|
||||
matches!(
|
||||
b,
|
||||
b' ' | b'\t'
|
||||
| b'\r'
|
||||
| b'\n'
|
||||
| b'"'
|
||||
| b'\''
|
||||
| b','
|
||||
| b';'
|
||||
| b'&'
|
||||
| b')'
|
||||
| b']'
|
||||
| b'}'
|
||||
| b'>'
|
||||
)
|
||||
}
|
||||
|
||||
/// What counts as "inside a word" for the boundary test. `_` is included so
|
||||
/// that `access_token` is one word rather than two, which is what stops the
|
||||
/// `token` rule from firing in the middle of it and redacting from there.
|
||||
fn is_word_byte(b: u8) -> bool {
|
||||
b.is_ascii_alphanumeric() || b == b'_'
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
|
||||
/// The strongest form of the assertion: not "the line changed" but "the
|
||||
/// secret is gone". A rule that redacted the wrong span would pass a
|
||||
/// weaker test.
|
||||
fn assert_gone(secret: &str, line: &str) -> String {
|
||||
let out = redact(line);
|
||||
assert!(
|
||||
!out.contains(secret),
|
||||
"redaction left the credential behind\n in: {line}\n out: {out}"
|
||||
);
|
||||
assert!(out.contains(PLACEHOLDER), "nothing was marked as removed: {out}");
|
||||
out
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_credential_login_flow_returns_never_reaches_the_file() {
|
||||
// Verbatim the shape of `AppCredentials` as serde writes it — the one
|
||||
// credential this application actually holds (FR-NC-1).
|
||||
let out = assert_gone(
|
||||
"wYh3K8mLpQr2",
|
||||
r#"got {"server":"https://cloud.example","loginName":"duncan","appPassword":"wYh3K8mLpQr2"}"#,
|
||||
);
|
||||
// The rest of the response is the diagnostic, and it survives.
|
||||
assert!(out.contains("cloud.example"));
|
||||
assert!(out.contains("duncan"));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_debug_printed_credential_struct_is_scrubbed() {
|
||||
// The two-in-the-morning case: `log::debug!("{creds:?}")`.
|
||||
assert_gone(
|
||||
"wYh3K8mLpQr2",
|
||||
r#"AppCredentials { server: "https://cloud.example", login_name: "duncan", app_password: "wYh3K8mLpQr2" }"#,
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_basic_auth_header_keeps_its_scheme_and_loses_its_secret() {
|
||||
let out = assert_gone(
|
||||
"ZHVuY2FuOmh1bnRlcjI=",
|
||||
"PROPFIND /remote.php/dav authorization: Basic ZHVuY2FuOmh1bnRlcjI=",
|
||||
);
|
||||
assert!(
|
||||
out.contains("Basic"),
|
||||
"which scheme was used is diagnostic, and is not the secret: {out}"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_bearer_token_with_no_keyword_in_front_of_it_still_goes() {
|
||||
assert_gone("eyJhbGciOiJIUzI1NiJ9", "sending Bearer eyJhbGciOiJIUzI1NiJ9");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_password_in_a_url_goes_and_the_server_stays() {
|
||||
let out = assert_gone(
|
||||
"hunter2",
|
||||
"PUT https://duncan:hunter2@cloud.example/remote.php/dav/files/x.cr2 failed",
|
||||
);
|
||||
assert!(
|
||||
out.contains("duncan") && out.contains("cloud.example"),
|
||||
"which server, and as whom, is the whole of a sync bug report: {out}"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_query_string_token_goes() {
|
||||
assert_gone(
|
||||
"abc123def",
|
||||
"polling https://cloud.example/login/v2/poll?token=abc123def&x=1",
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_word_alone_is_not_a_secret() {
|
||||
// The over-redaction failure, which is how a scrubber makes a log
|
||||
// useless without ever being caught: these lines say nothing secret
|
||||
// and must come through untouched.
|
||||
for line in [
|
||||
"password rejected by the server",
|
||||
"no token yet; still polling",
|
||||
"the tokenizer produced 41 tokens",
|
||||
"authorization failed with 401",
|
||||
"secretary@cloud.example added",
|
||||
// The unkeyed `Basic ` rule has no keyword to justify itself, and
|
||||
// `basic` is an ordinary word. This is the line it must not eat.
|
||||
"using basic sRGB as the fallback",
|
||||
"bearer of the news: 12 images",
|
||||
] {
|
||||
assert_eq!(redact(line), line, "over-redacted: {line}");
|
||||
}
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_photographs_path_is_not_a_secret() {
|
||||
// Stated as a test because it is a design decision and not an
|
||||
// oversight: NFR-SEC-2 lists credentials, and a log that cannot name
|
||||
// the file that failed to decode is not a diagnostic. See the module
|
||||
// documentation.
|
||||
let line = "decode failed: /home/duncan/Pictures/2026/Iceland/DSC_0431.NEF";
|
||||
assert_eq!(redact(line), line);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn several_secrets_in_one_line_all_go() {
|
||||
let out = redact(r#"{"password":"a1b2c3","token":"d4e5f6","user":"duncan"}"#);
|
||||
assert!(!out.contains("a1b2c3"), "{out}");
|
||||
assert!(!out.contains("d4e5f6"), "{out}");
|
||||
assert!(out.contains("duncan"), "{out}");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn redaction_keeps_the_line_shaped_like_what_it_replaced() {
|
||||
assert_eq!(
|
||||
redact(r#"{"password": "hunter2"}"#),
|
||||
r#"{"password": "<redacted>"}"#
|
||||
);
|
||||
assert_eq!(redact("password=hunter2"), "password=<redacted>");
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_line_with_no_secret_survives_byte_for_byte() {
|
||||
// Including non-ASCII, which is the case the ASCII lowercasing exists
|
||||
// to protect: a `to_lowercase` here would shift byte offsets under a
|
||||
// Turkish dotted capital and slice the next character in half.
|
||||
for line in [
|
||||
"opened /home/duncan/Bilder/Ölandsbron/DSC_0431.NEF",
|
||||
"İSTANBUL library scanned: 12 034 images",
|
||||
"",
|
||||
] {
|
||||
assert_eq!(redact(line), line);
|
||||
}
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_url_without_a_credential_is_left_whole() {
|
||||
let line = "GET https://cloud.example/remote.php/dav/files/duncan/";
|
||||
assert_eq!(redact(line), line);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn an_email_address_is_not_a_url_userinfo() {
|
||||
let line = "sharing with duncan@tourolle.paris";
|
||||
assert_eq!(redact(line), line);
|
||||
}
|
||||
}
|
||||
@@ -4,18 +4,21 @@
|
||||
//! construction, so `core/` contains no `#[cfg(target_os)]` (NFR-PORT-1,
|
||||
//! ARCH §10).
|
||||
|
||||
// Not a trait, and the one module here that is not. It belongs in this crate
|
||||
// for the same reason the traits do: "where does this platform let an
|
||||
// application keep state" is a platform question, and both entry points need
|
||||
// the answer before either has a window. Resolving it in `apps/` would mean
|
||||
// writing it twice, once per platform, which is the arrangement this crate
|
||||
// exists to prevent.
|
||||
// Neither of the next two is a trait, and they are the modules here that are
|
||||
// not. They belong in this crate for the same reason the traits do: "where does
|
||||
// this platform let an application keep state" is a platform question, and both
|
||||
// entry points need the answer before either has a window. Resolving it in
|
||||
// `apps/` would mean writing it twice, once per platform, which is the
|
||||
// arrangement this crate exists to prevent.
|
||||
pub mod crash;
|
||||
pub mod diagnostics;
|
||||
pub mod display;
|
||||
pub mod secrets;
|
||||
pub mod state;
|
||||
pub mod storage;
|
||||
pub mod volumes;
|
||||
|
||||
pub use diagnostics::{Installed, LogFile};
|
||||
pub use display::{
|
||||
Bounds, DisplayInfo, DisplayProfile, DisplayServer, DisplaySurvey, FallbackReason,
|
||||
ProfileSource,
|
||||
@@ -23,6 +26,7 @@ pub use display::{
|
||||
pub use secrets::{
|
||||
EphemeralSecretStore, PlatformSecretStore, SecretError, SecretKind, SecretRef, SecretStore,
|
||||
};
|
||||
pub use state::{set_state_dir, state_dir};
|
||||
pub use storage::{
|
||||
DirRef, Entry, LocalStorage, NewFile, Node, SeekableRead, Storage, StorageError,
|
||||
WritableStorage,
|
||||
|
||||
@@ -0,0 +1,148 @@
|
||||
//! TRACES: NFR-OPS-1
|
||||
//! Where this platform lets the application keep notes about itself.
|
||||
//!
|
||||
//! Not the catalog, not the photographs, not the user's configuration — those
|
||||
//! three already have homes (`dr_sync::account::config_dir`,
|
||||
//! `dr_ui::library::data_root`, and the sidecars beside the images). This is
|
||||
//! the fourth thing: the diagnostic residue an application leaves so that a
|
||||
//! failure yesterday can be read about today. A log, and — when the crash
|
||||
//! path lands — a crash record.
|
||||
//!
|
||||
//! # Why it is its own directory and not one of the other three
|
||||
//!
|
||||
//! XDG separates them for a reason that is not tidiness. `$XDG_CONFIG_HOME`
|
||||
//! is what the user has chosen and would miss; `$XDG_DATA_HOME` is what the
|
||||
//! application built and would have to rebuild; `$XDG_STATE_HOME` is
|
||||
//! "state that should persist between restarts but is not important or
|
||||
//! portable enough for the data directory" — which is exactly a log file. It
|
||||
//! is also the directory nobody backs up, and a log is the one file here we
|
||||
//! actively want a user to be able to delete without consequence.
|
||||
//!
|
||||
//! # Android has none of those variables, so the platform must say
|
||||
//!
|
||||
//! There is no `$HOME` on Android and no XDG anything (ARCH §6.9), so the
|
||||
//! guesses below resolve to a path the app cannot write. `dr_sync::account`
|
||||
//! learned this the expensive way — the session list went to a doomed path,
|
||||
//! nothing failed loudly, and backgrounding the app lost the sign-in — and the
|
||||
//! shape of the fix is copied here deliberately: the platform entry point
|
||||
//! declares the directory once, before anything opens a file in it.
|
||||
//!
|
||||
//! **Which Android directory is a diagnostics decision, and it belongs to the
|
||||
//! caller.** `AndroidApp` offers two, and they differ in precisely the way
|
||||
//! that matters here:
|
||||
//!
|
||||
//! * `internal_data_path` — `/data/data/<pkg>/files`. Private, durable, and
|
||||
//! unreachable: pulling a file out of it needs `run-as` against a debuggable
|
||||
//! build, or root.
|
||||
//! * `external_data_path` — `/sdcard/Android/data/<pkg>/files`. Same lifetime
|
||||
//! (the system deletes it with the app, not under storage pressure — that is
|
||||
//! the *cache* directory), needs no permission since API 19, and `adb pull`
|
||||
//! reads it from any build.
|
||||
//!
|
||||
//! A log nobody can retrieve is not a diagnostic, so `darkroom-android` points
|
||||
//! this at the external one. That choice has a consequence, and it is the
|
||||
//! reason [`crate::diagnostics`] redacts at the sink rather than trusting call
|
||||
//! sites: everything written here is readable by anyone holding the device.
|
||||
|
||||
use std::ffi::OsString;
|
||||
use std::path::{Path, PathBuf};
|
||||
use std::sync::OnceLock;
|
||||
|
||||
/// Declared once by the platform entry point; a guess otherwise.
|
||||
static STATE_DIR: OnceLock<PathBuf> = OnceLock::new();
|
||||
|
||||
/// Declare where this platform keeps application state.
|
||||
///
|
||||
/// Call it before anything opens a file — installing the logger is normally
|
||||
/// the very next line — because a later call is *ignored* rather than obeyed.
|
||||
/// That is deliberate: two callers disagreeing about the directory would
|
||||
/// otherwise split the log across two files depending on which ran first, and
|
||||
/// a silently-ignored second call leaves one log rather than two halves.
|
||||
///
|
||||
/// Desktop needs no call. The XDG resolution below is correct there.
|
||||
pub fn set_state_dir(dir: PathBuf) {
|
||||
let _ = STATE_DIR.set(dir);
|
||||
}
|
||||
|
||||
/// The directory this application's state belongs in.
|
||||
///
|
||||
/// It is not created here. Whoever writes into it creates it, so that merely
|
||||
/// asking the question leaves nothing behind on a machine that never logs.
|
||||
pub fn state_dir() -> PathBuf {
|
||||
if let Some(dir) = STATE_DIR.get() {
|
||||
return dir.clone();
|
||||
}
|
||||
xdg_state_dir(
|
||||
std::env::var_os("XDG_STATE_HOME"),
|
||||
std::env::var_os("HOME"),
|
||||
)
|
||||
}
|
||||
|
||||
/// The XDG resolution, as a function of its inputs rather than of the process
|
||||
/// environment, so it can be tested without `set_var` racing every other test
|
||||
/// in the binary.
|
||||
///
|
||||
/// Relative values are ignored rather than resolved against the working
|
||||
/// directory: the base-directory specification says so explicitly, and the
|
||||
/// alternative is a `darkroom/` directory appearing wherever the app was
|
||||
/// launched from.
|
||||
fn xdg_state_dir(xdg_state_home: Option<OsString>, home: Option<OsString>) -> PathBuf {
|
||||
xdg_state_home
|
||||
.filter(|value| Path::new(value).is_absolute())
|
||||
.map(PathBuf::from)
|
||||
.or_else(|| {
|
||||
home.filter(|value| Path::new(value).is_absolute())
|
||||
.map(|value| PathBuf::from(value).join(".local/state"))
|
||||
})
|
||||
// A container or a systemd unit with neither variable set. Writing a
|
||||
// log into `/tmp` is a poor outcome; refusing to log at all, on the
|
||||
// one kind of machine nobody is sitting in front of, is a worse one.
|
||||
.unwrap_or_else(std::env::temp_dir)
|
||||
.join("darkroom")
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
|
||||
#[test]
|
||||
fn the_log_goes_under_the_state_directory_the_user_named() {
|
||||
// NFR-OPS-1 says "the XDG state directory", and honouring
|
||||
// $XDG_STATE_HOME is the whole of what that means to a user who has
|
||||
// moved theirs.
|
||||
let dir = xdg_state_dir(Some("/var/lib/dr".into()), Some("/home/someone".into()));
|
||||
assert_eq!(dir, PathBuf::from("/var/lib/dr/darkroom"));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn without_the_variable_it_is_the_specifications_default() {
|
||||
let dir = xdg_state_dir(None, Some("/home/someone".into()));
|
||||
assert_eq!(dir, PathBuf::from("/home/someone/.local/state/darkroom"));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_relative_value_is_ignored_rather_than_resolved() {
|
||||
// The specification requires this, and the failure it prevents is a
|
||||
// `darkroom/` directory appearing in whatever the working directory
|
||||
// happened to be — including, on a desktop launcher, `/`.
|
||||
let dir = xdg_state_dir(Some("state".into()), Some("/home/someone".into()));
|
||||
assert_eq!(dir, PathBuf::from("/home/someone/.local/state/darkroom"));
|
||||
|
||||
let dir = xdg_state_dir(Some("".into()), Some("".into()));
|
||||
assert!(
|
||||
dir.is_absolute(),
|
||||
"an empty HOME must not produce a relative state directory"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_declared_directory_is_declared_once() {
|
||||
// The property the entry points rely on: two callers cannot split the
|
||||
// log in half. Exercised on a fresh `OnceLock` rather than the global
|
||||
// one, which any other test in this binary may already have set.
|
||||
let cell: OnceLock<PathBuf> = OnceLock::new();
|
||||
assert!(cell.set(PathBuf::from("/first")).is_ok());
|
||||
assert!(cell.set(PathBuf::from("/second")).is_err());
|
||||
assert_eq!(cell.get(), Some(&PathBuf::from("/first")));
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user