Audit writer: open a record-less log, share the log-name rule, keep the lock file

M3a review findings 1, 2, 4 and part of 5. One empty log file made brokerd
panic at startup (files[len - 2]); it now opens as an empty log. brokerd's
name check tested one month digit, so a file bxctl ignored could become
brokerd's latest file; both now use proto::is_audit_log_name. Writer no
longer unlinks audit/.lock, which opened a two-writer window. No unwrap in
short_check.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
2026-09-22 21:05:13 -07:00
co-authored by Claude Opus 5.5
parent 22a26aad45
commit eed0a221ca
6 changed files with 182 additions and 70 deletions
+26 -45
View File
@@ -11,7 +11,8 @@ use std::os::unix::fs::{DirBuilderExt, OpenOptionsExt};
use std::path::{Path, PathBuf}; use std::path::{Path, PathBuf};
use proto::{ use proto::{
AuditEvent, AuditRecord, ChainFailure, ChainReport, ChainVerifier, Hash32, Timestamp, sha256, AuditEvent, AuditRecord, ChainFailure, ChainReport, ChainVerifier, Hash32, Timestamp,
is_audit_log_name, sha256,
}; };
/// The notice appended to the log when a torn final line is recovered, as the RUNBOOK entry names. /// The notice appended to the log when a torn final line is recovered, as the RUNBOOK entry names.
@@ -83,21 +84,6 @@ impl From<io::Error> for AuditError {
} }
} }
/// A name is a log file when it is `<YYYY-MM-DD>.jsonl`: 16 chars, `-` at 4 and 7, `.jsonl` at 10
/// to 15, digits elsewhere.
fn is_log_name(name: &str) -> bool {
let b = name.as_bytes();
if b.len() != 16 {
return false;
}
b[4] == b'-'
&& b[7] == b'-'
&& &b[10..16] == b".jsonl"
&& b[0..4].iter().all(|c| c.is_ascii_digit())
&& b[5..6].iter().all(|c| c.is_ascii_digit())
&& b[8..10].iter().all(|c| c.is_ascii_digit())
}
/// The log file name for a record's time: the day of the timestamp, `.jsonl`. /// The log file name for a record's time: the day of the timestamp, `.jsonl`.
fn day_name(time: Timestamp) -> String { fn day_name(time: Timestamp) -> String {
let when = time.to_rfc3339(); let when = time.to_rfc3339();
@@ -138,7 +124,7 @@ fn log_files(dir: &Path) -> Result<Vec<String>, AuditError> {
let entry = entry.map_err(|e| io("read audit log", dir, e))?; let entry = entry.map_err(|e| io("read audit log", dir, e))?;
let name = entry.file_name(); let name = entry.file_name();
let name = name.to_string_lossy(); let name = name.to_string_lossy();
if is_log_name(&name) { if is_audit_log_name(&name) {
names.push(name.into_owned()); names.push(name.into_owned());
} }
} }
@@ -162,11 +148,9 @@ pub fn verify_dir(dir: &Path) -> Result<ChainReport, AuditError> {
/// is a record. Otherwise the whole log is verified. /// is a record. Otherwise the whole log is verified.
fn short_check(dir: &Path) -> Result<ChainReport, AuditError> { fn short_check(dir: &Path) -> Result<ChainReport, AuditError> {
let files = log_files(dir)?; let files = log_files(dir)?;
if files.len() < 2 { let (Some(latest), Some(before)) = (files.last(), files.iter().rev().nth(1)) else {
return verify_dir(dir); return verify_dir(dir);
} };
let latest = files.last().unwrap();
let before = &files[files.len() - 2];
let path_before = dir.join(before); let path_before = dir.join(before);
let bytes = fs::read(&path_before).map_err(|e| io("read audit log", &path_before, e))?; let bytes = fs::read(&path_before).map_err(|e| io("read audit log", &path_before, e))?;
let line = match last_line(&bytes) { let line = match last_line(&bytes) {
@@ -192,6 +176,21 @@ fn short_check(dir: &Path) -> Result<ChainReport, AuditError> {
Ok(verifier.finish()) Ok(verifier.finish())
} }
/// The hash of the last line of the file before the latest, or zero if there is no such file or
/// it has no line.
fn tail_of_file_before_latest(dir: &Path) -> Result<Hash32, AuditError> {
let files = log_files(dir)?;
let Some(before) = files.iter().rev().nth(1) else {
return Ok(Hash32::ZERO);
};
let path = dir.join(before);
let bytes = fs::read(&path).map_err(|e| io("read audit log", &path, e))?;
match last_line(&bytes) {
Some(line) => Ok(sha256(line).map_err(io::Error::other)?),
None => Ok(Hash32::ZERO),
}
}
/// Append one record: serialise it, open the target file, write the line, and return the seq and /// Append one record: serialise it, open the target file, write the line, and return the seq and
/// the hash of the line it wrote. A fresh file is created mode 0600 and the directory synced. /// the hash of the line it wrote. A fresh file is created mode 0600 and the directory synced.
fn write_record( fn write_record(
@@ -251,7 +250,8 @@ impl std::fmt::Debug for Lock {
/// refused. /// refused.
#[derive(Debug)] #[derive(Debug)]
pub struct Writer { pub struct Writer {
lock_file: Lock, /// Held, never read: closing the file is what releases the lock. The file itself stays.
_lock: Lock,
path: PathBuf, path: PathBuf,
latest: Option<String>, latest: Option<String>,
prev: Hash32, prev: Hash32,
@@ -336,22 +336,11 @@ impl Writer {
)?; )?;
(hash, seq.checked_add(1).unwrap_or(report.next_seq)) (hash, seq.checked_add(1).unwrap_or(report.next_seq))
} else { } else {
// No record verified: the chain goes on from the last line of the file before the
// latest, or starts at zero when there is none (a log whose only file is empty).
let prev = match report.head { let prev = match report.head {
Some(head) => head, Some(head) => head,
None => { None => tail_of_file_before_latest(dir)?,
let files = log_files(dir)?;
if files.is_empty() {
Hash32::ZERO
} else {
let before = &files[files.len() - 2];
let path = dir.join(before);
let bytes = fs::read(&path).map_err(|e| io("read audit log", &path, e))?;
match last_line(&bytes) {
Some(line) => sha256(line).map_err(io::Error::other)?,
None => Hash32::ZERO,
}
}
}
}; };
(prev, report.next_seq) (prev, report.next_seq)
}; };
@@ -359,7 +348,7 @@ impl Writer {
// 10. Hand back the writer. // 10. Hand back the writer.
Ok(Opened { Ok(Opened {
writer: Writer { writer: Writer {
lock_file: lock, _lock: lock,
path: dir.to_path_buf(), path: dir.to_path_buf(),
latest, latest,
prev, prev,
@@ -406,14 +395,6 @@ impl Writer {
} }
} }
impl Drop for Writer {
fn drop(&mut self) {
// This field holds the .lock handle open, so the lock lasts as long as the writer.
let _ = &self.lock_file;
let _ = fs::remove_file(self.path.join(".lock"));
}
}
/// What `open` hands back: the writer plus what it recovered or accepted. /// What `open` hands back: the writer plus what it recovered or accepted.
#[derive(Debug)] #[derive(Debug)]
pub struct Opened { pub struct Opened {
+106
View File
@@ -0,0 +1,106 @@
//! Audit writer edge cases found in the M3a review: a log with no complete record, a file whose
//! name only looks like a log, and the lock file outliving the writer.
#[path = "support/audit_dir.rs"]
mod audit_dir;
use audit_dir::{D1, D2, TempDir, denied, lines, ts};
use brokerd::audit::{Writer, verify_dir};
use proto::{AuditRecord, Hash32};
/// A kill between creating the day's file and writing its first record leaves it empty. It must
/// open like an empty log, not panic.
#[test]
fn one_zero_length_log_file_opens_as_an_empty_log() {
let dir = TempDir::unmade("zero-length");
std::fs::create_dir_all(&dir.path).unwrap();
std::fs::write(dir.path.join(D1), b"").unwrap();
let opened = Writer::open(&dir.path, false).unwrap();
assert!(!opened.recovered);
let mut writer = opened.writer;
assert_eq!(writer.next_seq(), 0);
writer
.append(ts("2026-09-17T08:00:00.000Z"), denied(1))
.unwrap();
let record: AuditRecord = serde_json::from_str(&lines(&dir.path, D1)[0]).unwrap();
assert_eq!((record.seq, record.prev), (0, Hash32::ZERO));
let report = verify_dir(&dir.path).unwrap();
assert_eq!(report.failure, None);
assert_eq!(report.records, 1);
}
/// The same crash, a day later: the older file holds records and the new one is empty.
#[test]
fn a_zero_length_file_after_records_continues_the_chain() {
let dir = TempDir::unmade("zero-length-later");
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
writer
.append(ts("2026-09-17T08:00:00.000Z"), denied(1))
.unwrap();
drop(writer);
std::fs::write(dir.path.join(D2), b"").unwrap();
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
assert_eq!(writer.next_seq(), 1);
writer
.append(ts("2026-09-18T08:00:00.000Z"), denied(2))
.unwrap();
let report = verify_dir(&dir.path).unwrap();
assert_eq!(report.failure, None);
assert_eq!(report.records, 2);
}
/// A crash part-way through the very first record: one file, one torn line, nothing else.
#[test]
fn a_single_torn_first_record_is_recovered() {
let dir = TempDir::unmade("torn-only");
std::fs::create_dir_all(&dir.path).unwrap();
std::fs::write(dir.path.join(D1), br#"{"seq":0,"time":"2026-09-17T08:"#).unwrap();
let opened = Writer::open(&dir.path, false).unwrap();
assert!(opened.recovered);
let report = verify_dir(&dir.path).unwrap();
assert_eq!(report.failure, None);
assert_eq!(report.recoveries.len(), 1);
}
/// `2026-0x-19.jsonl` is not a log file, for `brokerd` as for `bxctl audit verify`: it is neither
/// verified nor written to, and the real log goes on in its own files.
#[test]
fn a_file_that_only_looks_like_a_log_is_not_part_of_it() {
let dir = TempDir::case("good", None);
let odd = dir.path.join("2026-0x-19.jsonl");
std::fs::write(&odd, b"not a record\n").unwrap();
let mut writer = Writer::open(&dir.path, false)
.expect("a stray file does not break the chain")
.writer;
writer
.append(ts("2026-09-18T09:00:00.000Z"), denied(9))
.unwrap();
assert_eq!(
std::fs::read(&odd).unwrap(),
b"not a record\n",
"never written"
);
let report = verify_dir(&dir.path).unwrap();
assert_eq!(report.failure, None);
assert_eq!(
report.records, 11,
"the ten fixture records and the new one"
);
}
/// The lock file is never removed: a `brokerd` holding the old file open could otherwise lock it
/// while a new one creates and locks a fresh file, and both would write.
#[test]
fn the_lock_file_outlives_the_writer() {
let dir = TempDir::unmade("lock-stays");
let writer = Writer::open(&dir.path, false).unwrap().writer;
drop(writer);
assert!(dir.path.join(".lock").exists());
Writer::open(&dir.path, false).expect("the lock was released with the writer");
}
+1 -24
View File
@@ -17,7 +17,7 @@ pub fn run(home: &Path, out: &mut dyn Write) -> std::io::Result<bool> {
Ok(name) => name, Ok(name) => name,
Err(_) => continue, Err(_) => continue,
}; };
if is_audit_log(&name) { if proto::is_audit_log_name(&name) {
names.push(name); names.push(name);
} }
} }
@@ -65,26 +65,3 @@ pub fn run(home: &Path, out: &mut dyn Write) -> std::io::Result<bool> {
} }
Ok(true) Ok(true)
} }
/// True if `name` is a `YYYY-MM-DD.jsonl` audit log: ten characters, digits with `-` at positions
/// 4 and 7, then `.jsonl`.
fn is_audit_log(name: &str) -> bool {
let date = match name.strip_suffix(".jsonl") {
Some(date) => date,
None => return false,
};
if date.len() != 10 {
return false;
}
let bytes = date.as_bytes();
for (i, &b) in bytes.iter().enumerate() {
if i == 4 || i == 7 {
if b != b'-' {
return false;
}
} else if !b.is_ascii_digit() {
return false;
}
}
true
}
+13
View File
@@ -91,3 +91,16 @@ pub struct AuditRecord {
pub prev: Hash32, pub prev: Hash32,
pub event: AuditEvent, pub event: AuditEvent,
} }
/// True if `name` is an audit log file: `YYYY-MM-DD.jsonl`, ASCII digits with `-` at positions 4
/// and 7. `brokerd` and `bxctl audit verify` both decide with this, so they read the same files.
pub fn is_audit_log_name(name: &str) -> bool {
let Some(date) = name.strip_suffix(".jsonl") else {
return false;
};
date.len() == 10
&& date.bytes().enumerate().all(|(i, b)| match i {
4 | 7 => b == b'-',
_ => b.is_ascii_digit(),
})
}
+3 -1
View File
@@ -10,7 +10,9 @@ pub mod ids;
pub mod log; pub mod log;
pub mod wire; pub mod wire;
pub use audit::{ApprovalAnswer, AuditEvent, AuditRecord, DecisionRecord, ResultStatus}; pub use audit::{
ApprovalAnswer, AuditEvent, AuditRecord, DecisionRecord, ResultStatus, is_audit_log_name,
};
pub use chain::{ChainFailure, ChainReport, ChainVerifier, Location, TornTail}; pub use chain::{ChainFailure, ChainReport, ChainVerifier, Location, TornTail};
pub use class::DataClass; pub use class::DataClass;
pub use frame::{FrameError, MAX_FRAME, read_frame, write_frame}; pub use frame::{FrameError, MAX_FRAME, read_frame, write_frame};
+33
View File
@@ -0,0 +1,33 @@
//! Which file names are audit log files. `brokerd` and `bxctl audit verify` both use this one rule,
//! so they always read the same set of files.
use proto::is_audit_log_name;
#[test]
fn a_date_and_jsonl_is_a_log_file() {
for name in ["2026-09-17.jsonl", "0000-00-00.jsonl", "9999-12-31.jsonl"] {
assert!(is_audit_log_name(name), "{name}");
}
}
#[test]
fn every_other_name_is_not() {
for name in [
"",
".lock",
"2026-0x-17.jsonl", // the second month digit
"2026-x9-17.jsonl",
"2026-09-1x.jsonl",
"x026-09-17.jsonl",
"2026_09-17.jsonl",
"2026-09_17.jsonl",
"2026-09-17.json",
"2026-09-17.jsonl.bak",
"2026-9-17.jsonl",
"12026-09-17.jsonl",
"2026-09-17.JSONL",
"026-09-17.jsonl", // a full-width digit is not an ASCII digit
] {
assert!(!is_audit_log_name(name), "{name}");
}
}