259 lines
8.7 KiB
Rust
259 lines
8.7 KiB
Rust
//! The audit writer: the chain it writes, the lock, rollover, and stopping after a failed
|
|
//! write. Do not edit. Startup checks, recovery and accepted breaks are in `audit_startup.rs`.
|
|
|
|
#[path = "support/audit_dir.rs"]
|
|
mod audit_dir;
|
|
|
|
use std::os::unix::fs::PermissionsExt;
|
|
|
|
use audit_dir::{D1, D2, TempDir, denied, lines, ts};
|
|
use brokerd::audit::{AuditError, RECOVERED_NOTICE, Writer, verify_dir};
|
|
use proto::{AuditRecord, Hash32, sha256};
|
|
|
|
fn mode(path: &std::path::Path) -> u32 {
|
|
std::fs::metadata(path).unwrap().permissions().mode() & 0o777
|
|
}
|
|
|
|
#[test]
|
|
fn the_first_record_starts_the_chain() {
|
|
let dir = TempDir::unmade("first");
|
|
let opened = Writer::open(&dir.path, false).unwrap();
|
|
assert!(!opened.recovered);
|
|
assert!(opened.accepted.is_none());
|
|
let mut writer = opened.writer;
|
|
assert_eq!(writer.next_seq(), 0);
|
|
|
|
let seq = writer
|
|
.append(ts("2026-09-17T08:00:00.000Z"), denied(1))
|
|
.unwrap();
|
|
assert_eq!(seq, 0);
|
|
assert_eq!(writer.next_seq(), 1);
|
|
|
|
let text = std::fs::read_to_string(dir.path.join(D1)).unwrap();
|
|
assert!(text.ends_with('\n'), "a record is one line and its newline");
|
|
assert_eq!(text.lines().count(), 1);
|
|
let record: AuditRecord = serde_json::from_str(text.lines().next().unwrap()).unwrap();
|
|
assert_eq!((record.seq, record.prev), (0, Hash32::ZERO));
|
|
assert_eq!(record.time, ts("2026-09-17T08:00:00.000Z"));
|
|
assert_eq!(record.event, denied(1));
|
|
|
|
assert_eq!(mode(&dir.path), 0o700, "the directory open() made");
|
|
assert_eq!(mode(&dir.path.join(D1)), 0o600);
|
|
}
|
|
|
|
#[test]
|
|
fn the_chain_runs_across_a_day_boundary() {
|
|
let dir = TempDir::unmade("days");
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
let times = [
|
|
"2026-09-17T23:59:58.000Z",
|
|
"2026-09-17T23:59:59.999Z",
|
|
"2026-09-18T00:00:00.000Z",
|
|
"2026-09-18T00:00:01.000Z",
|
|
];
|
|
for (i, time) in times.iter().enumerate() {
|
|
assert_eq!(writer.append(ts(time), denied(i as u64)).unwrap(), i as u64);
|
|
}
|
|
let (day1, day2) = (lines(&dir.path, D1), lines(&dir.path, D2));
|
|
assert_eq!((day1.len(), day2.len()), (2, 2));
|
|
|
|
// seq goes on across files, and the new file chains from the last line of the old one.
|
|
let first: AuditRecord = serde_json::from_str(&day2[0]).unwrap();
|
|
assert_eq!(first.seq, 2);
|
|
assert_eq!(first.prev, sha256(day1[1].as_bytes()).unwrap());
|
|
|
|
let report = verify_dir(&dir.path).unwrap();
|
|
assert_eq!(report.failure, None);
|
|
assert_eq!((report.records, report.next_seq), (4, 4));
|
|
assert!(report.clock_warnings.is_empty());
|
|
}
|
|
|
|
#[test]
|
|
fn reopening_continues_the_chain() {
|
|
let dir = TempDir::unmade("reopen");
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
writer
|
|
.append(ts("2026-09-17T08:00:00.000Z"), denied(1))
|
|
.unwrap();
|
|
writer
|
|
.append(ts("2026-09-17T08:00:01.000Z"), denied(2))
|
|
.unwrap();
|
|
drop(writer);
|
|
|
|
// One file: the whole of it is checked.
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
assert_eq!(writer.next_seq(), 2);
|
|
assert_eq!(
|
|
writer
|
|
.append(ts("2026-09-18T08:00:00.000Z"), denied(3))
|
|
.unwrap(),
|
|
2
|
|
);
|
|
drop(writer);
|
|
|
|
// Two files: the latest is checked, resumed from the last line of the one before.
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
assert_eq!(writer.next_seq(), 3);
|
|
assert_eq!(
|
|
writer
|
|
.append(ts("2026-09-18T08:00:01.000Z"), denied(4))
|
|
.unwrap(),
|
|
3
|
|
);
|
|
drop(writer);
|
|
|
|
let report = verify_dir(&dir.path).unwrap();
|
|
assert_eq!(report.failure, None);
|
|
assert_eq!(report.records, 4);
|
|
}
|
|
|
|
#[test]
|
|
fn an_empty_latest_file_gets_the_next_record_as_its_first_line() {
|
|
let dir = TempDir::case("empty-latest", None);
|
|
let opened = Writer::open(&dir.path, false).unwrap();
|
|
assert!(!opened.recovered);
|
|
let mut writer = opened.writer;
|
|
assert_eq!(
|
|
writer
|
|
.append(ts("2026-09-18T08:00:00.000Z"), denied(9))
|
|
.unwrap(),
|
|
5
|
|
);
|
|
|
|
let day2 = lines(&dir.path, D2);
|
|
assert_eq!(day2.len(), 1);
|
|
let record: AuditRecord = serde_json::from_str(&day2[0]).unwrap();
|
|
assert_eq!(
|
|
record.prev,
|
|
sha256(lines(&dir.path, D1)[4].as_bytes()).unwrap()
|
|
);
|
|
assert_eq!(verify_dir(&dir.path).unwrap().failure, None);
|
|
}
|
|
|
|
#[test]
|
|
fn a_second_writer_is_refused() {
|
|
let dir = TempDir::unmade("lock");
|
|
let first = Writer::open(&dir.path, false).unwrap();
|
|
let error = Writer::open(&dir.path, false).unwrap_err();
|
|
assert!(matches!(error, AuditError::Locked), "{error}");
|
|
let text = error.to_string();
|
|
assert!(text.starts_with("brokerd is already running"), "{text}");
|
|
assert!(
|
|
text.ends_with("see docs/runbook.md#brokerd-already-running"),
|
|
"{text}"
|
|
);
|
|
|
|
// The lock goes when the writer goes, however that happens.
|
|
drop(first);
|
|
assert!(Writer::open(&dir.path, false).is_ok());
|
|
}
|
|
|
|
#[test]
|
|
fn the_writer_never_goes_back_to_an_earlier_file() {
|
|
let dir = TempDir::unmade("clock");
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
writer
|
|
.append(ts("2026-09-18T00:00:05.000Z"), denied(1))
|
|
.unwrap();
|
|
// The clock is stepped back over midnight.
|
|
writer
|
|
.append(ts("2026-09-17T23:59:50.000Z"), denied(2))
|
|
.unwrap();
|
|
|
|
assert!(
|
|
!dir.path.join(D1).exists(),
|
|
"a record went into an earlier file"
|
|
);
|
|
assert_eq!(lines(&dir.path, D2).len(), 2);
|
|
let report = verify_dir(&dir.path).unwrap();
|
|
assert_eq!(report.failure, None);
|
|
assert_eq!(report.clock_warnings.len(), 1);
|
|
|
|
// It holds across a restart too.
|
|
drop(writer);
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
writer
|
|
.append(ts("2026-09-17T23:59:55.000Z"), denied(3))
|
|
.unwrap();
|
|
assert!(!dir.path.join(D1).exists());
|
|
assert_eq!(verify_dir(&dir.path).unwrap().failure, None);
|
|
}
|
|
|
|
#[test]
|
|
fn files_that_are_not_log_files_are_ignored() {
|
|
let dir = TempDir::case("good", None);
|
|
std::fs::write(dir.path.join("notes.txt"), "not a log\n").unwrap();
|
|
std::fs::write(dir.path.join("2026-09-19.jsonl.bak"), "not a log\n").unwrap();
|
|
std::fs::write(dir.path.join("latest.jsonl"), "not a log\n").unwrap();
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
assert_eq!(writer.next_seq(), 10);
|
|
writer
|
|
.append(ts("2026-09-18T10:00:00.000Z"), denied(9))
|
|
.unwrap();
|
|
assert_eq!(verify_dir(&dir.path).unwrap().records, 11);
|
|
}
|
|
|
|
/// After one failed write the writer writes nothing more, even when the cause has gone: part of
|
|
/// a line may be on disk, and only the next start deals with that.
|
|
#[test]
|
|
fn a_failed_write_stops_the_writer() {
|
|
let dir = TempDir::unmade("sticky");
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
writer
|
|
.append(ts("2026-09-17T08:00:00.000Z"), denied(1))
|
|
.unwrap();
|
|
|
|
// A new day needs a new file, and the directory no longer allows one.
|
|
std::fs::set_permissions(&dir.path, std::fs::Permissions::from_mode(0o500)).unwrap();
|
|
if std::fs::write(dir.path.join("probe"), "").is_ok() {
|
|
eprintln!("skipped: this user can write to a read-only directory (root?)");
|
|
std::fs::set_permissions(&dir.path, std::fs::Permissions::from_mode(0o700)).unwrap();
|
|
return;
|
|
}
|
|
let error = writer
|
|
.append(ts("2026-09-18T08:00:00.000Z"), denied(2))
|
|
.unwrap_err();
|
|
assert!(matches!(error, AuditError::Io { .. }), "{error}");
|
|
assert!(
|
|
error
|
|
.to_string()
|
|
.ends_with("see docs/runbook.md#audit-unavailable"),
|
|
"{error}"
|
|
);
|
|
|
|
std::fs::set_permissions(&dir.path, std::fs::Permissions::from_mode(0o700)).unwrap();
|
|
for time in ["2026-09-18T08:00:01.000Z", "2026-09-17T08:00:02.000Z"] {
|
|
let error = writer.append(ts(time), denied(3)).unwrap_err();
|
|
assert!(matches!(error, AuditError::Stopped), "{error}");
|
|
assert!(
|
|
error
|
|
.to_string()
|
|
.ends_with("see docs/runbook.md#audit-unavailable"),
|
|
"{error}"
|
|
);
|
|
}
|
|
assert_eq!(
|
|
lines(&dir.path, D1).len(),
|
|
1,
|
|
"a stopped writer wrote something"
|
|
);
|
|
assert!(!dir.path.join(D2).exists());
|
|
|
|
// A restart puts it right.
|
|
drop(writer);
|
|
let mut writer = Writer::open(&dir.path, false).unwrap().writer;
|
|
assert_eq!(
|
|
writer
|
|
.append(ts("2026-09-18T08:00:03.000Z"), denied(4))
|
|
.unwrap(),
|
|
1
|
|
);
|
|
assert_eq!(verify_dir(&dir.path).unwrap().failure, None);
|
|
}
|
|
|
|
#[test]
|
|
fn the_recovered_notice_names_its_runbook_entry() {
|
|
assert!(RECOVERED_NOTICE.starts_with("audit: recovered a torn final line"));
|
|
assert!(RECOVERED_NOTICE.ends_with("see docs/runbook.md#audit-recovered"));
|
|
}
|