use std::sync::Arc;
use std::time::{Duration, Instant};
use chrono::Utc;
use hmac::{Hmac, KeyInit, Mac};
use sha2::Sha256;
use tokio::sync::Mutex;
use uuid::Uuid;
use super::envelope::{AuditEnvelope, EVENT_VERSION, GENESIS_HASH, SCHEMA_VERSION};
use super::event::AuditEvent;
use super::key_store::AuditKeyStore;
use crate::error::AppError;
use crate::store::{KeyspaceHandle, RawKvPair, ScanOpts};
type HmacSha256 = Hmac<Sha256>;
const HEAD_LOOKBACK: usize = 20;
const HEAD_RECOVERY_RETRY_BACKOFF: Duration = Duration::from_secs(60);
const DEEP_SCAN_PAGE: usize = 500;
pub const AUDIT_CHAIN_RECOVERY_FAILURES: &str = "audit_chain_recovery_failures_total";
#[derive(Clone)]
enum ChainHeadState {
Unknown,
Known([u8; 32]),
Failed {
since: Instant,
cause: String,
},
}
pub fn envelope_storage_key(env: &AuditEnvelope) -> Vec<u8> {
format!("{}:{}", env.timestamp.to_rfc3339(), env.event_id).into_bytes()
}
#[derive(Clone)]
pub struct AuditWriter {
audit_ks: KeyspaceHandle,
key_store: AuditKeyStore,
storage_key: Arc<dyn Fn(&AuditEnvelope) -> Vec<u8> + Send + Sync>,
key_prefix: Vec<u8>,
deep_scan_page: usize,
chain_head: Arc<Mutex<ChainHeadState>>,
}
impl AuditWriter {
pub fn new(audit_ks: KeyspaceHandle, key_store: AuditKeyStore) -> Self {
Self {
audit_ks,
key_store,
storage_key: Arc::new(envelope_storage_key),
key_prefix: Vec::new(),
deep_scan_page: DEEP_SCAN_PAGE,
chain_head: Arc::new(Mutex::new(ChainHeadState::Unknown)),
}
}
#[must_use]
pub fn with_storage_key(
mut self,
f: impl Fn(&AuditEnvelope) -> Vec<u8> + Send + Sync + 'static,
) -> Self {
self.storage_key = Arc::new(f);
self
}
#[must_use]
pub fn with_key_prefix(mut self, prefix: impl Into<Vec<u8>>) -> Self {
self.key_prefix = prefix.into();
self
}
#[cfg(test)]
#[must_use]
fn with_deep_scan_page(mut self, page: usize) -> Self {
self.deep_scan_page = page;
self
}
pub async fn active_key(&self) -> Result<crate::audit::AuditKey, AppError> {
self.key_store.active().await
}
pub async fn write(
&self,
actor_did: &str,
target_did: Option<&str>,
event: AuditEvent,
) -> Result<AuditEnvelope, AppError> {
let key = self.key_store.active().await?;
let actor_did_hash = hmac_did(&key.key, actor_did);
let target_did_hash = target_did.map(|d| hmac_did(&key.key, d));
let mut head = self.chain_head.lock().await;
let current_state = head.clone();
let prev_hash = match current_state {
ChainHeadState::Known(hash) => hash,
ChainHeadState::Unknown => self.recover_chain_head(&mut head).await?,
ChainHeadState::Failed { since, cause } => {
if since.elapsed() < HEAD_RECOVERY_RETRY_BACKOFF {
return Err(AppError::Internal(format!(
"audit chain head unavailable: {cause}"
)));
}
self.recover_chain_head(&mut head).await?
}
};
let mut envelope = AuditEnvelope {
event_id: Uuid::new_v4(),
event_version: EVENT_VERSION,
schema_version: SCHEMA_VERSION,
timestamp: Utc::now(),
audit_key_id: key.key_id,
actor_did_hash,
actor_did_plain: Some(actor_did.to_string()),
target_did_hash,
target_did_plain: target_did.map(str::to_string),
prev_hash,
entry_hash: GENESIS_HASH, event,
};
envelope.entry_hash = envelope.chain_digest();
self.audit_ks
.insert((self.storage_key)(&envelope), &envelope)
.await?;
*head = ChainHeadState::Known(envelope.entry_hash);
Ok(envelope)
}
async fn recover_chain_head(&self, state: &mut ChainHeadState) -> Result<[u8; 32], AppError> {
match self.load_chain_head().await {
Ok(hash) => {
*state = ChainHeadState::Known(hash);
Ok(hash)
}
Err(error) => {
metrics::counter!(AUDIT_CHAIN_RECOVERY_FAILURES).increment(1);
let cause = error.to_string();
tracing::error!(
target: "audit.chain_recovery",
error = %error,
retry_after_secs = HEAD_RECOVERY_RETRY_BACKOFF.as_secs(),
"audit chain head recovery failed"
);
*state = ChainHeadState::Failed {
since: Instant::now(),
cause,
};
Err(error)
}
}
}
async fn load_chain_head(&self) -> Result<[u8; 32], AppError> {
let pairs = self
.audit_ks
.scan_raw(ScanOpts::newest_first(
self.key_prefix.clone(),
HEAD_LOOKBACK,
))
.await?;
if let Some(hash) = newest_envelope_hash(&pairs) {
return Ok(hash);
}
if pairs.len() < HEAD_LOOKBACK {
return Ok(GENESIS_HASH);
}
Box::pin(self.deep_scan_for_chain_head(pairs)).await
}
async fn deep_scan_for_chain_head(
&self,
fast_path: Vec<RawKvPair>,
) -> Result<[u8; 32], AppError> {
let mut cursor = fast_path.into_iter().next_back().map(|(key, _)| key);
loop {
let Some(after) = cursor.take() else {
return Ok(GENESIS_HASH);
};
let page = self
.audit_ks
.scan_raw(
ScanOpts::newest_first(self.key_prefix.clone(), self.deep_scan_page)
.after(after),
)
.await?;
if let Some(hash) = newest_envelope_hash(&page) {
return Ok(hash);
}
if page.len() < self.deep_scan_page {
return Ok(GENESIS_HASH);
}
cursor = page.into_iter().next_back().map(|(key, _)| key);
}
}
pub async fn verify_actor(
&self,
envelope: &AuditEnvelope,
candidate_did: &str,
) -> Result<bool, AppError> {
let key = match self.key_store.fetch(&envelope.audit_key_id).await? {
Some(k) => k,
None => return Ok(false),
};
let recomputed = hmac_did(&key.key, candidate_did);
Ok(constant_time_eq(&recomputed, &envelope.actor_did_hash))
}
pub async fn verify_target(
&self,
envelope: &AuditEnvelope,
candidate_did: &str,
) -> Result<bool, AppError> {
let expected = match envelope.target_did_hash {
Some(h) => h,
None => return Ok(false),
};
let key = match self.key_store.fetch(&envelope.audit_key_id).await? {
Some(k) => k,
None => return Ok(false),
};
let recomputed = hmac_did(&key.key, candidate_did);
Ok(constant_time_eq(&recomputed, &expected))
}
}
fn newest_envelope_hash(pairs: &[RawKvPair]) -> Option<[u8; 32]> {
pairs
.iter()
.find_map(|(_, raw)| serde_json::from_slice::<AuditEnvelope>(raw).ok())
.map(|env| env.entry_hash)
}
fn hmac_did(key: &[u8; 32], did: &str) -> [u8; 32] {
let mut mac = HmacSha256::new_from_slice(key).expect("32-byte HMAC key");
mac.update(did.as_bytes());
mac.finalize().into_bytes().into()
}
fn constant_time_eq(a: &[u8; 32], b: &[u8; 32]) -> bool {
let mut diff = 0u8;
for i in 0..32 {
diff |= a[i] ^ b[i];
}
diff == 0
}
#[cfg(test)]
mod tests {
use super::*;
use crate::audit::key_store::RotationReason;
use crate::audit::verify_chain;
use crate::config::StoreConfig;
use crate::store::Store;
struct Fixture {
writer: AuditWriter,
key_store: AuditKeyStore,
_dir: tempfile::TempDir,
}
fn fixture() -> Fixture {
let dir = tempfile::tempdir().expect("tempdir");
let cfg = StoreConfig {
data_dir: dir.path().to_path_buf(),
};
let store = Store::open(&cfg).expect("store");
let audit_ks = store.keyspace("audit").expect("audit ks");
let key_ks = store.keyspace("audit_key").expect("audit_key ks");
let key_store = AuditKeyStore::new(key_ks);
let writer = AuditWriter::new(audit_ks, key_store.clone());
Fixture {
writer,
key_store,
_dir: dir,
}
}
fn sample_event() -> AuditEvent {
AuditEvent::CommunityProfileUpdated(crate::audit::event::CommunityProfileUpdatedData {
fields_changed: vec!["name".into()],
..Default::default()
})
}
#[tokio::test]
async fn a_pre_chain_row_does_not_break_the_first_write() {
let f = fixture();
f.key_store.ensure_initial(&[0x01; 32]).await.unwrap();
f.writer
.audit_ks
.insert(
b"log:00000000001700000000:11111111-1111-1111-1111-111111111111".to_vec(),
&serde_json::json!({
"id": "11111111-1111-1111-1111-111111111111",
"timestamp": 1_700_000_000u64,
"action": "auth.challenge",
"actor": "did:key:z6MkLegacy",
"outcome": "success",
}),
)
.await
.expect("seed a pre-chain row");
let env = f
.writer
.write("did:key:z6Mk", None, sample_event())
.await
.expect("a pre-chain row must not stop the first chained write");
assert_eq!(
env.prev_hash, GENESIS_HASH,
"the first chained entry anchors at genesis, not at a row that predates the chain"
);
}
#[tokio::test]
async fn prefixed_recovery_ignores_rows_outside_the_log_prefix() {
let f = fixture();
f.key_store.ensure_initial(&[0x0a; 32]).await.unwrap();
f.writer
.audit_ks
.insert(
b"log:00000000001700000000:legacy".to_vec(),
&serde_json::json!({
"id": "legacy",
"timestamp": 1_700_000_000u64,
"action": "auth.challenge",
"actor": "did:key:z6MkLegacy",
"outcome": "success",
}),
)
.await
.unwrap();
f.writer
.audit_ks
.insert(
b"prune:watermark".to_vec(),
&serde_json::json!({
"head": "00",
"prunedEntries": 1,
"prunedAt": "2026-10-13T00:00:00Z",
}),
)
.await
.unwrap();
let env = f
.writer
.clone()
.with_key_prefix("log:")
.write("did:key:z6Mk", None, sample_event())
.await
.unwrap();
assert_eq!(env.prev_hash, GENESIS_HASH);
}
#[cfg(feature = "encryption")]
fn recovery_failures_during<F>(body: F) -> u64
where
F: std::future::Future<Output = ()>,
{
use metrics_util::debugging::{DebugValue, DebuggingRecorder};
let recorder = DebuggingRecorder::new();
let snapshotter = recorder.snapshotter();
metrics::with_local_recorder(&recorder, || {
tokio::runtime::Builder::new_current_thread()
.enable_all()
.build()
.expect("runtime")
.block_on(body);
});
snapshotter
.snapshot()
.into_vec()
.into_iter()
.filter(|(key, _, _, _)| key.key().name() == AUDIT_CHAIN_RECOVERY_FAILURES)
.map(|(_, _, _, value)| match value {
DebugValue::Counter(count) => count,
other => panic!("{AUDIT_CHAIN_RECOVERY_FAILURES} is not a counter: {other:?}"),
})
.sum()
}
async fn seed_legacy_rows(writer: &AuditWriter, count: usize) {
for index in 0..count {
writer
.audit_ks
.insert(
format!("log:{index:020}:legacy"),
&serde_json::json!({
"id": format!("legacy-{index}"),
"timestamp": 1_700_000_000u64 + index as u64,
"action": "auth.challenge",
"actor": "did:key:z6MkLegacy",
"outcome": "success",
}),
)
.await
.unwrap();
}
}
#[cfg(feature = "encryption")]
async fn writer_whose_recovery_read_fails() -> (AuditWriter, tempfile::TempDir) {
let dir = tempfile::tempdir().expect("tempdir");
let store = Store::open(&StoreConfig {
data_dir: dir.path().to_path_buf(),
})
.expect("store");
let plain_ks = store.keyspace("audit").expect("audit ks");
let key_store = AuditKeyStore::new(store.keyspace("audit_key").expect("key ks"));
key_store.ensure_initial(&[0x1b; 32]).await.unwrap();
let seeding_writer = AuditWriter::new(plain_ks.clone(), key_store.clone());
seed_legacy_rows(&seeding_writer, 3).await;
let encrypted_ks = plain_ks.with_encryption([0x1c; 32]);
let writer = AuditWriter::new(encrypted_ks, key_store).with_key_prefix("log:");
(writer, dir)
}
#[cfg(feature = "encryption")]
#[test]
fn a_storage_failure_during_recovery_is_counted_once() {
let count = recovery_failures_during(async {
let (writer, _dir) = writer_whose_recovery_read_fails().await;
writer
.write("did:key:z6Mk", None, sample_event())
.await
.expect_err("a scan that storage refuses must fail closed");
});
assert_eq!(count, 1);
}
#[cfg(feature = "encryption")]
#[test]
fn writes_refused_during_the_backoff_do_not_re_count() {
let count = recovery_failures_during(async {
let (writer, _dir) = writer_whose_recovery_read_fails().await;
for _ in 0..3 {
writer
.write("did:key:z6Mk", None, sample_event())
.await
.expect_err("every write fails while the head is unknown");
}
});
assert_eq!(
count, 1,
"three refused writes, one recovery attempt, one count"
);
}
#[tokio::test]
async fn a_legacy_log_spanning_many_deep_scan_pages_anchors_at_genesis() {
let f = fixture();
f.key_store.ensure_initial(&[0x0b; 32]).await.unwrap();
seed_legacy_rows(&f.writer, HEAD_LOOKBACK + 10 * 7 + 3).await;
let env = f
.writer
.with_key_prefix("log:")
.with_deep_scan_page(10)
.write("did:key:z6Mk", None, sample_event())
.await
.expect("a long legacy log must anchor, not fail closed");
assert_eq!(env.prev_hash, GENESIS_HASH);
}
#[tokio::test]
async fn legacy_log_longer_than_head_lookback_without_envelope_still_anchors_at_genesis() {
let f = fixture();
f.key_store.ensure_initial(&[0x0e; 32]).await.unwrap();
let total_rows = HEAD_LOOKBACK + 10;
for index in 0..total_rows {
f.writer
.audit_ks
.insert(
format!("log:{index:020}:legacy"),
&serde_json::json!({
"id": format!("legacy-{index}"),
"timestamp": 1_700_000_000u64 + index as u64,
"action": "auth.challenge",
"actor": "did:key:z6MkLegacy",
"outcome": "success",
}),
)
.await
.unwrap();
}
let env = f
.writer
.with_key_prefix("log:")
.write("did:key:z6Mk", None, sample_event())
.await
.expect(
"a legacy log longer than HEAD_LOOKBACK but with no envelope must still anchor, \
not fail closed",
);
assert_eq!(
env.prev_hash, GENESIS_HASH,
"the deep scan must prove the prefix envelope-free before anchoring at genesis"
);
}
#[tokio::test]
async fn deep_scan_finds_an_envelope_further_back_than_head_lookback() {
let f = fixture();
f.key_store.ensure_initial(&[0x0f; 32]).await.unwrap();
let anchor = f
.writer
.write("did:key:z6Mk", None, sample_event())
.await
.expect("seed the anchor envelope");
for index in 0..(HEAD_LOOKBACK + 5) {
f.writer
.audit_ks
.insert(
format!("zzz-legacy-{index:020}"),
&serde_json::json!({
"id": format!("legacy-{index}"),
"timestamp": 1_700_000_000u64 + index as u64,
"action": "auth.challenge",
"actor": "did:key:z6MkLegacy",
"outcome": "success",
}),
)
.await
.unwrap();
}
let restarted = AuditWriter::new(f.writer.audit_ks.clone(), f.key_store.clone());
let next = restarted
.write("did:key:z6Mk", None, sample_event())
.await
.expect("an envelope below the fast-path window must still be found");
assert_eq!(
next.prev_hash, anchor.entry_hash,
"the deep-scan fallback must anchor on the buried envelope, not genesis"
);
}
#[cfg(feature = "encryption")]
#[tokio::test]
async fn failed_head_recovery_is_cached_during_backoff() {
let (writer, _dir) = writer_whose_recovery_read_fails().await;
let first = writer
.write("did:key:z6Mk", None, sample_event())
.await
.expect_err("first head recovery must fail");
let second = writer
.write("did:key:z6Mk", None, sample_event())
.await
.expect_err("backoff must keep failing without a storage retry");
assert_eq!(
second.to_string(),
format!("internal error: audit chain head unavailable: {first}")
);
}
#[tokio::test]
async fn a_custom_storage_key_still_recovers_the_head() {
let f = fixture();
f.key_store.ensure_initial(&[0x01; 32]).await.unwrap();
let writer = f.writer.clone().with_storage_key(|env| {
format!(
"log:{:020}:{}",
env.timestamp.timestamp().max(0),
env.event_id
)
.into_bytes()
});
let first = writer
.write("did:key:z6MkA", None, sample_event())
.await
.unwrap();
let restarted = AuditWriter::new(f.writer.audit_ks.clone(), f.key_store.clone())
.with_storage_key(|env| {
format!(
"log:{:020}:{}",
env.timestamp.timestamp().max(0),
env.event_id
)
.into_bytes()
});
let second = restarted
.write("did:key:z6MkB", None, sample_event())
.await
.unwrap();
assert_eq!(
second.prev_hash, first.entry_hash,
"the second entry chains to the first across a restart"
);
assert!(
verify_chain(&[first, second]).is_ok(),
"the pair verifies as a chain"
);
}
#[tokio::test]
async fn write_persists_envelope_and_hashes_actor() {
let f = fixture();
f.key_store.ensure_initial(&[0x01; 32]).await.unwrap();
let env = f
.writer
.write("did:key:z6Mk", None, sample_event())
.await
.unwrap();
assert_eq!(env.event_version, EVENT_VERSION);
assert_eq!(env.schema_version, SCHEMA_VERSION);
assert_eq!(env.actor_did_plain.as_deref(), Some("did:key:z6Mk"));
assert!(env.target_did_hash.is_none());
use sha2::Digest;
let plain_sha: [u8; 32] = sha2::Sha256::digest(b"did:key:z6Mk").into();
assert_ne!(env.actor_did_hash, plain_sha);
}
#[tokio::test]
async fn same_actor_same_key_yields_same_hash() {
let f = fixture();
f.key_store.ensure_initial(&[0x02; 32]).await.unwrap();
let a = f
.writer
.write("did:key:abc", None, sample_event())
.await
.unwrap();
let b = f
.writer
.write("did:key:abc", None, sample_event())
.await
.unwrap();
assert_eq!(a.actor_did_hash, b.actor_did_hash);
assert_eq!(a.audit_key_id, b.audit_key_id);
}
#[tokio::test]
async fn different_actors_yield_different_hashes() {
let f = fixture();
f.key_store.ensure_initial(&[0x03; 32]).await.unwrap();
let a = f
.writer
.write("did:key:alice", None, sample_event())
.await
.unwrap();
let b = f
.writer
.write("did:key:bob", None, sample_event())
.await
.unwrap();
assert_ne!(a.actor_did_hash, b.actor_did_hash);
}
#[tokio::test]
async fn rotation_changes_subsequent_hashes() {
let f = fixture();
f.key_store.ensure_initial(&[0x04; 32]).await.unwrap();
let before = f
.writer
.write("did:key:alice", None, sample_event())
.await
.unwrap();
f.key_store.rotate(RotationReason::Manual).await.unwrap();
let after = f
.writer
.write("did:key:alice", None, sample_event())
.await
.unwrap();
assert_ne!(before.actor_did_hash, after.actor_did_hash);
assert_ne!(before.audit_key_id, after.audit_key_id);
}
#[tokio::test]
async fn verify_actor_walks_history_across_rotation() {
let f = fixture();
f.key_store.ensure_initial(&[0x05; 32]).await.unwrap();
let pre = f
.writer
.write("did:key:alice", None, sample_event())
.await
.unwrap();
f.key_store.rotate(RotationReason::Routine).await.unwrap();
let post = f
.writer
.write("did:key:bob", None, sample_event())
.await
.unwrap();
assert!(f.writer.verify_actor(&pre, "did:key:alice").await.unwrap());
assert!(!f.writer.verify_actor(&pre, "did:key:bob").await.unwrap());
assert!(f.writer.verify_actor(&post, "did:key:bob").await.unwrap());
assert!(!f.writer.verify_actor(&post, "did:key:alice").await.unwrap());
}
async fn read_chain(ks: &KeyspaceHandle) -> Vec<AuditEnvelope> {
let mut pairs = ks.prefix_iter_raw(Vec::new()).await.unwrap();
pairs.sort_by(|(a, _), (b, _)| a.cmp(b));
pairs
.iter()
.map(|(_, v)| serde_json::from_slice(v).unwrap())
.collect()
}
#[tokio::test]
async fn writes_form_a_verifiable_chain() {
use crate::audit::envelope::{GENESIS_HASH, verify_chain};
let f = fixture();
f.key_store.ensure_initial(&[0x07; 32]).await.unwrap();
for i in 0..5u8 {
f.writer
.write(&format!("did:key:actor{i}"), None, sample_event())
.await
.unwrap();
}
let chain = read_chain(&f.writer.audit_ks).await;
assert_eq!(chain.len(), 5);
assert_eq!(chain[0].prev_hash, GENESIS_HASH);
for w in chain.windows(2) {
assert_eq!(w[1].prev_hash, w[0].entry_hash);
}
verify_chain(&chain).expect("chain must verify");
}
#[tokio::test]
async fn tamper_after_write_is_detected() {
use crate::audit::envelope::{ChainBreak, verify_chain};
let f = fixture();
f.key_store.ensure_initial(&[0x08; 32]).await.unwrap();
for i in 0..3u8 {
f.writer
.write(&format!("did:key:a{i}"), None, sample_event())
.await
.unwrap();
}
let mut chain = read_chain(&f.writer.audit_ks).await;
chain[1].event =
AuditEvent::CommunityProfileUpdated(crate::audit::event::CommunityProfileUpdatedData {
fields_changed: vec!["forged".into()],
..Default::default()
});
assert!(matches!(
verify_chain(&chain),
Err(ChainBreak::TamperedEntry { index: 1, .. })
));
}
#[tokio::test]
async fn chain_head_recovers_after_restart() {
use crate::audit::envelope::verify_chain;
let f = fixture();
f.key_store.ensure_initial(&[0x09; 32]).await.unwrap();
f.writer
.write("did:key:before", None, sample_event())
.await
.unwrap();
let restarted = AuditWriter::new(f.writer.audit_ks.clone(), f.key_store.clone());
restarted
.write("did:key:after", None, sample_event())
.await
.unwrap();
let chain = read_chain(&f.writer.audit_ks).await;
assert_eq!(chain.len(), 2);
assert_eq!(chain[1].prev_hash, chain[0].entry_hash);
verify_chain(&chain).expect("chain survives restart");
}
#[tokio::test]
async fn target_hash_set_when_target_supplied() {
let f = fixture();
f.key_store.ensure_initial(&[0x06; 32]).await.unwrap();
let env = f
.writer
.write("did:key:admin", Some("did:key:member"), sample_event())
.await
.unwrap();
assert!(env.target_did_hash.is_some());
assert!(
f.writer
.verify_target(&env, "did:key:member")
.await
.unwrap()
);
assert!(
!f.writer
.verify_target(&env, "did:key:somebody-else")
.await
.unwrap()
);
}
}