use hkdf::Hkdf;
use hmac::{Hmac, Mac};
use parking_lot::RwLock;
use serde::{Deserialize, Serialize};
use sha2::{Digest, Sha256};
use std::io::BufRead;
use std::io::Write;
use std::path::{Path, PathBuf};
use std::sync::atomic::{AtomicBool, Ordering};
use std::sync::Arc;
use std::time::{SystemTime, UNIX_EPOCH};
use zeroize::Zeroizing;
type HmacSha256 = Hmac<Sha256>;
pub const AUDIT_LOG_FORMAT_VERSION: u32 = 1;
const AUDIT_CHAIN_HKDF_INFO: &[u8] = b"audit-chain";
const AUDIT_CHAIN_INIT_LABEL: &[u8] = b"audit-chain-init";
pub fn derive_audit_chain_key(state_hmac_key: &[u8; 32]) -> Zeroizing<[u8; 32]> {
let hk = Hkdf::<Sha256>::new(None, state_hmac_key);
let mut okm = Zeroizing::new([0u8; 32]);
hk.expand(AUDIT_CHAIN_HKDF_INFO, &mut *okm)
.expect("HKDF-SHA256 expand(32 bytes) cannot fail");
okm
}
fn initial_chain_hash(audit_key: &[u8; 32]) -> [u8; 32] {
let mut mac =
HmacSha256::new_from_slice(audit_key).expect("HMAC-SHA256 accepts any key length");
mac.update(AUDIT_CHAIN_INIT_LABEL);
let tag = mac.finalize().into_bytes();
let mut out = [0u8; 32];
out.copy_from_slice(&tag);
out
}
#[derive(Debug, Clone)]
pub struct AuditEvent {
pub format_version: u32,
pub timestamp: u64,
pub session_handle: u64,
pub operation: AuditOperation,
pub key_id: Option<String>,
pub result: AuditResult,
pub previous_hash: [u8; 32],
}
#[derive(Serialize, Deserialize)]
struct AuditEventDisk {
#[serde(default)]
format_version: u32,
timestamp: u64,
session_handle: u64,
operation: AuditOperation,
key_id: Option<String>,
result: AuditResult,
previous_hash: [u8; 32],
}
impl Serialize for AuditEvent {
fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
where
S: serde::Serializer,
{
use serde::ser::SerializeStruct;
let mut state = serializer.serialize_struct("AuditEvent", 7)?;
state.serialize_field("format_version", &self.format_version)?;
state.serialize_field("timestamp", &self.timestamp)?;
state.serialize_field("session_handle", &self.session_handle)?;
state.serialize_field("operation", &self.operation)?;
state.serialize_field("key_id", &self.key_id)?;
state.serialize_field("result", &self.result)?;
state.serialize_field("previous_hash", &self.previous_hash)?;
state.end()
}
}
impl<'de> Deserialize<'de> for AuditEvent {
fn deserialize<D>(deserializer: D) -> Result<Self, D::Error>
where
D: serde::Deserializer<'de>,
{
let disk = AuditEventDisk::deserialize(deserializer)?;
Ok(AuditEvent {
format_version: disk.format_version,
timestamp: disk.timestamp,
session_handle: disk.session_handle,
operation: disk.operation,
key_id: disk.key_id,
result: disk.result,
previous_hash: disk.previous_hash,
})
}
}
#[derive(Serialize)]
struct AuditEventPayload<'a> {
format_version: u32,
timestamp: u64,
session_handle: u64,
operation: &'a AuditOperation,
key_id: &'a Option<String>,
result: &'a AuditResult,
}
impl AuditEvent {
fn payload(&self) -> AuditEventPayload<'_> {
AuditEventPayload {
format_version: self.format_version,
timestamp: self.timestamp,
session_handle: self.session_handle,
operation: &self.operation,
key_id: &self.key_id,
result: &self.result,
}
}
}
#[derive(Debug, Clone, Serialize, Deserialize)]
pub enum AuditOperation {
Initialize,
Finalize,
OpenSession {
slot_id: u64,
},
CloseSession,
Login {
user_type: u64,
},
Logout,
InitToken {
slot_id: u64,
},
InitPIN {
slot_id: u64,
},
SetPIN,
GenerateKey {
mechanism: u64,
key_length: u32,
fips_approved: bool,
},
GenerateKeyPair {
mechanism: u64,
key_length: u32,
fips_approved: bool,
},
Sign {
mechanism: u64,
fips_approved: bool,
},
Verify {
mechanism: u64,
fips_approved: bool,
},
Encrypt {
mechanism: u64,
fips_approved: bool,
},
Decrypt {
mechanism: u64,
fips_approved: bool,
},
Digest {
mechanism: u64,
fips_approved: bool,
},
CreateObject,
DestroyObject,
GenerateRandom {
length: u32,
},
WrapKey {
mechanism: u64,
fips_approved: bool,
},
UnwrapKey {
mechanism: u64,
fips_approved: bool,
},
DeriveKey {
mechanism: u64,
fips_approved: bool,
},
FindObjects {
result_count: u32,
},
GetAttributeValue,
Zeroize {
key_length: u32,
},
}
#[derive(Debug, Clone, Serialize, Deserialize)]
pub enum AuditResult {
Success,
Failure(u64),
}
enum AuditCommand {
Record {
session_handle: u64,
operation: AuditOperation,
result: AuditResult,
key_id: Option<String>,
done: Option<std::sync::mpsc::SyncSender<Result<(), crate::error::HsmError>>>,
},
Flush {
done: std::sync::mpsc::Sender<()>,
},
}
const MAX_IN_MEMORY_ENTRIES: usize = 100_000;
const MAX_LOG_FILE_BYTES: u64 = 100 * 1024 * 1024;
const MAX_ROTATED_FILES: u32 = 5;
enum ChainRecoveryResult {
NoFile,
Verified([u8; 32]),
Broken(String),
}
struct AuditLogState {
entries: Vec<AuditEvent>,
last_hash: [u8; 32],
tamper_detected: bool,
last_timestamp: u64,
}
pub struct AuditLog {
state: Arc<RwLock<AuditLogState>>,
log_path: Option<PathBuf>,
sender: Option<std::sync::mpsc::Sender<AuditCommand>>,
tamper_flag: Arc<AtomicBool>,
worker: Option<std::thread::JoinHandle<()>>,
audit_chain_key: Arc<Zeroizing<[u8; 32]>>,
}
static GLOBAL_AUDIT_LOG: parking_lot::RwLock<Option<std::sync::Weak<AuditLog>>> =
parking_lot::RwLock::new(None);
impl Default for AuditLog {
fn default() -> Self {
Self::new()
}
}
fn encode_payload_v1(event: &AuditEvent, out: &mut Vec<u8>) {
out.extend_from_slice(&event.format_version.to_le_bytes());
out.extend_from_slice(&event.timestamp.to_le_bytes());
out.extend_from_slice(&event.session_handle.to_le_bytes());
encode_operation_v1(&event.operation, out);
match &event.key_id {
None => out.push(0),
Some(id) => {
out.push(1);
let bytes = id.as_bytes();
let len = u32::try_from(bytes.len()).unwrap_or(u32::MAX);
out.extend_from_slice(&len.to_le_bytes());
out.extend_from_slice(&bytes[..len as usize]);
}
}
match &event.result {
AuditResult::Success => out.push(0),
AuditResult::Failure(rv) => {
out.push(1);
out.extend_from_slice(&rv.to_le_bytes());
}
}
}
fn encode_operation_v1(op: &AuditOperation, out: &mut Vec<u8>) {
fn mech(out: &mut Vec<u8>, tag: u8, mechanism: u64, fips_approved: bool) {
out.push(tag);
out.extend_from_slice(&mechanism.to_le_bytes());
out.push(u8::from(fips_approved));
}
match op {
AuditOperation::Initialize => out.push(1),
AuditOperation::Finalize => out.push(2),
AuditOperation::OpenSession { slot_id } => {
out.push(3);
out.extend_from_slice(&slot_id.to_le_bytes());
}
AuditOperation::CloseSession => out.push(4),
AuditOperation::Login { user_type } => {
out.push(5);
out.extend_from_slice(&user_type.to_le_bytes());
}
AuditOperation::Logout => out.push(6),
AuditOperation::InitToken { slot_id } => {
out.push(7);
out.extend_from_slice(&slot_id.to_le_bytes());
}
AuditOperation::InitPIN { slot_id } => {
out.push(8);
out.extend_from_slice(&slot_id.to_le_bytes());
}
AuditOperation::SetPIN => out.push(9),
AuditOperation::GenerateKey {
mechanism,
key_length,
fips_approved,
} => {
out.push(10);
out.extend_from_slice(&mechanism.to_le_bytes());
out.extend_from_slice(&key_length.to_le_bytes());
out.push(u8::from(*fips_approved));
}
AuditOperation::GenerateKeyPair {
mechanism,
key_length,
fips_approved,
} => {
out.push(11);
out.extend_from_slice(&mechanism.to_le_bytes());
out.extend_from_slice(&key_length.to_le_bytes());
out.push(u8::from(*fips_approved));
}
AuditOperation::Sign {
mechanism,
fips_approved,
} => mech(out, 12, *mechanism, *fips_approved),
AuditOperation::Verify {
mechanism,
fips_approved,
} => mech(out, 13, *mechanism, *fips_approved),
AuditOperation::Encrypt {
mechanism,
fips_approved,
} => mech(out, 14, *mechanism, *fips_approved),
AuditOperation::Decrypt {
mechanism,
fips_approved,
} => mech(out, 15, *mechanism, *fips_approved),
AuditOperation::Digest {
mechanism,
fips_approved,
} => mech(out, 16, *mechanism, *fips_approved),
AuditOperation::CreateObject => out.push(17),
AuditOperation::DestroyObject => out.push(18),
AuditOperation::GenerateRandom { length } => {
out.push(19);
out.extend_from_slice(&length.to_le_bytes());
}
AuditOperation::WrapKey {
mechanism,
fips_approved,
} => mech(out, 20, *mechanism, *fips_approved),
AuditOperation::UnwrapKey {
mechanism,
fips_approved,
} => mech(out, 21, *mechanism, *fips_approved),
AuditOperation::DeriveKey {
mechanism,
fips_approved,
} => mech(out, 22, *mechanism, *fips_approved),
AuditOperation::FindObjects { result_count } => {
out.push(23);
out.extend_from_slice(&result_count.to_le_bytes());
}
AuditOperation::GetAttributeValue => out.push(24),
AuditOperation::Zeroize { key_length } => {
out.push(25);
out.extend_from_slice(&key_length.to_le_bytes());
}
}
}
fn compute_chain_hash_with(
previous_hash: &[u8; 32],
event: &AuditEvent,
scratch: &mut Vec<u8>,
) -> Result<[u8; 32], crate::error::HsmError> {
scratch.clear();
match event.format_version {
0 => {
serde_json::to_writer(&mut *scratch, &event.payload()).map_err(|e| {
tracing::error!("Audit event payload serialization failed: {}", e);
crate::error::HsmError::GeneralError
})?;
}
1 => encode_payload_v1(event, scratch),
other => {
tracing::error!(
"Audit event carries unsupported format_version {} (this build \
writes {} and verifies 0..={})",
other,
AUDIT_LOG_FORMAT_VERSION,
AUDIT_LOG_FORMAT_VERSION,
);
return Err(crate::error::HsmError::AuditChainBroken(format!(
"unsupported audit record format_version {}",
other
)));
}
}
let mut hasher = Sha256::new();
hasher.update(previous_hash);
hasher.update(&*scratch);
let hash = hasher.finalize();
let mut result = [0u8; 32];
result.copy_from_slice(&hash);
Ok(result)
}
fn compute_chain_hash(
previous_hash: &[u8; 32],
event: &AuditEvent,
) -> Result<[u8; 32], crate::error::HsmError> {
let mut scratch = Vec::with_capacity(64);
compute_chain_hash_with(previous_hash, event, &mut scratch)
}
fn validate_log_path(path: &Path) -> Result<PathBuf, crate::error::HsmError> {
if path.exists() {
let meta = std::fs::symlink_metadata(path).map_err(|e| {
tracing::error!(
"Audit log path validation: cannot stat {}: {}",
path.display(),
e,
);
crate::error::HsmError::GeneralError
})?;
if meta.file_type().is_symlink() {
tracing::error!("Audit log path is a symlink, refusing: {}", path.display(),);
return Err(crate::error::HsmError::AuditChainBroken(
"audit log path is a symlink".to_string(),
));
}
if !meta.file_type().is_file() {
tracing::error!("Audit log path is not a regular file: {}", path.display(),);
return Err(crate::error::HsmError::AuditChainBroken(
"audit log path is not a regular file".to_string(),
));
}
}
if let Some(parent) = path.parent() {
if parent.as_os_str().is_empty() {
return Ok(path.to_path_buf());
}
let canonical_parent = parent.canonicalize().map_err(|e| {
tracing::error!(
"Audit log path validation: cannot canonicalize parent {}: {}",
parent.display(),
e,
);
crate::error::HsmError::GeneralError
})?;
if let Some(file_name) = path.file_name() {
Ok(canonical_parent.join(file_name))
} else {
tracing::error!(
"Audit log path has no filename component: {}",
path.display(),
);
Err(crate::error::HsmError::GeneralError)
}
} else {
Ok(path.to_path_buf())
}
}
fn open_audit_file(path: &Path) -> Result<std::fs::File, crate::error::HsmError> {
let mut opts = std::fs::OpenOptions::new();
opts.create(true).append(true);
#[cfg(unix)]
{
use std::os::unix::fs::OpenOptionsExt;
opts.mode(0o600);
}
let file = opts.open(path).map_err(|e| {
tracing::error!("Audit log file open failed: {}", e);
crate::error::HsmError::GeneralError
})?;
#[cfg(windows)]
{
if let Err(e) = crate::platform_acl::restrict_file_to_owner(path) {
tracing::error!(
"Failed to restrict audit log file permissions on {}: {}. \
File may be readable by other users.",
path.display(),
e,
);
}
}
Ok(file)
}
type DoneTx = std::sync::mpsc::SyncSender<Result<(), crate::error::HsmError>>;
struct AuditWorker {
state: Arc<RwLock<AuditLogState>>,
log_path: Option<PathBuf>,
tamper_flag: Arc<AtomicBool>,
last_hash: [u8; 32],
last_timestamp: u64,
file: Option<std::fs::File>,
file_size: u64,
line_buf: Vec<u8>,
hash_buf: Vec<u8>,
batch: Vec<AuditEvent>,
batch_head: [u8; 32],
waiters: Vec<DoneTx>,
}
impl AuditWorker {
fn run(&mut self, receiver: &std::sync::mpsc::Receiver<AuditCommand>) {
loop {
let first = match receiver.recv() {
Ok(cmd) => cmd,
Err(_) => break,
};
let mut flush_acks: Vec<std::sync::mpsc::Sender<()>> = Vec::new();
self.stage(first, &mut flush_acks);
while self.batch.len() < AuditLog::MAX_BATCH {
match receiver.try_recv() {
Ok(cmd) => self.stage(cmd, &mut flush_acks),
Err(_) => break,
}
}
self.commit_batch();
for ack in flush_acks {
let _ = ack.send(());
}
}
}
fn stage(&mut self, cmd: AuditCommand, flush_acks: &mut Vec<std::sync::mpsc::Sender<()>>) {
match cmd {
AuditCommand::Record {
session_handle,
operation,
result,
key_id,
done,
} => match self.chain_event(session_handle, operation, result, key_id) {
Ok(()) => {
if let Some(tx) = done {
self.waiters.push(tx);
}
}
Err(e) => {
if let Some(tx) = done {
let _ = tx.send(Err(e));
}
}
},
AuditCommand::Flush { done } => flush_acks.push(done),
}
}
fn chain_event(
&mut self,
session_handle: u64,
operation: AuditOperation,
result: AuditResult,
key_id: Option<String>,
) -> Result<(), crate::error::HsmError> {
if self.tamper_flag.load(Ordering::Acquire) {
return Err(crate::error::HsmError::AuditChainBroken(
"audit chain tamper previously detected".to_string(),
));
}
let duration = SystemTime::now()
.duration_since(UNIX_EPOCH)
.unwrap_or_default();
let wall_timestamp = u64::try_from(duration.as_nanos()).unwrap_or(u64::MAX);
let timestamp = if wall_timestamp <= self.last_timestamp {
match self.last_timestamp.checked_add(1) {
Some(next) => next,
None => {
tracing::error!(
"Audit timestamp space exhausted (u64::MAX reached). \
Cannot guarantee monotonicity."
);
self.tamper_flag.store(true, Ordering::Release);
return Err(crate::error::HsmError::AuditChainBroken(
"timestamp space exhausted".to_string(),
));
}
}
} else {
wall_timestamp
};
let previous_hash = if self.batch.is_empty() {
self.last_hash
} else {
self.batch_head
};
let event = AuditEvent {
format_version: AUDIT_LOG_FORMAT_VERSION,
timestamp,
session_handle,
operation,
key_id,
result,
previous_hash,
};
let new_head = compute_chain_hash_with(&previous_hash, &event, &mut self.hash_buf)?;
if self.log_path.is_some() {
let mark = self.line_buf.len();
if let Err(e) = serde_json::to_writer(&mut self.line_buf, &event) {
self.line_buf.truncate(mark);
tracing::error!("Audit log serialization failed: {}", e);
return Err(crate::error::HsmError::GeneralError);
}
self.line_buf.push(b'\n');
}
self.last_timestamp = timestamp;
self.batch_head = new_head;
self.batch.push(event);
Ok(())
}
fn commit_batch(&mut self) {
if self.batch.is_empty() {
self.line_buf.clear();
return;
}
if self.log_path.is_some() {
if let Err(e) = self.write_staged() {
tracing::error!("Audit worker: disk I/O failed: {}", e);
self.file = None;
self.batch.clear();
self.line_buf.clear();
self.batch_head = self.last_hash;
for tx in self.waiters.drain(..) {
let _ = tx.send(Err(e.clone()));
}
return;
}
}
self.last_hash = self.batch_head;
{
let mut s = self.state.write();
s.last_hash = self.last_hash;
s.last_timestamp = self.last_timestamp;
s.entries.append(&mut self.batch);
if s.entries.len() > MAX_IN_MEMORY_ENTRIES {
let excess = s.entries.len() - MAX_IN_MEMORY_ENTRIES;
s.entries.drain(..excess);
}
}
self.batch.clear();
self.line_buf.clear();
for tx in self.waiters.drain(..) {
let _ = tx.send(Ok(()));
}
}
fn write_staged(&mut self) -> Result<(), crate::error::HsmError> {
let path = match &self.log_path {
Some(p) => p.clone(),
None => return Ok(()),
};
if self.file.is_none() {
let f = open_audit_file(&path)?;
self.file_size = f.metadata().map(|m| m.len()).unwrap_or(0);
self.file = Some(f);
}
if self.file_size >= MAX_LOG_FILE_BYTES {
self.file = None;
AuditLog::rotate_log_files(&path)?;
let f = open_audit_file(&path)?;
self.file_size = f.metadata().map(|m| m.len()).unwrap_or(0);
self.file = Some(f);
}
let file = self
.file
.as_mut()
.expect("file handle is opened immediately above");
let bytes = self.line_buf.as_slice();
file.write_all(bytes).map_err(|e| {
tracing::error!("Audit log write failed: {}", e);
crate::error::HsmError::GeneralError
})?;
file.sync_all().map_err(|e| {
tracing::error!("Audit log fsync failed: {}", e);
crate::error::HsmError::GeneralError
})?;
self.file_size += bytes.len() as u64;
Ok(())
}
}
impl AuditLog {
const MAX_BATCH: usize = 1024;
fn spawn_worker(
state: Arc<RwLock<AuditLogState>>,
log_path: Option<PathBuf>,
tamper_flag: Arc<AtomicBool>,
receiver: std::sync::mpsc::Receiver<AuditCommand>,
initial_hash: [u8; 32],
initial_timestamp: u64,
) -> std::thread::JoinHandle<()> {
std::thread::Builder::new()
.name("audit-worker".to_string())
.spawn(move || {
let mut worker = AuditWorker {
state,
log_path,
tamper_flag,
last_hash: initial_hash,
last_timestamp: initial_timestamp,
file: None,
file_size: 0,
line_buf: Vec::new(),
hash_buf: Vec::with_capacity(64),
batch: Vec::new(),
batch_head: initial_hash,
waiters: Vec::new(),
};
worker.run(&receiver);
})
.expect("failed to spawn audit worker thread")
}
pub fn new() -> Self {
let state = Arc::new(RwLock::new(AuditLogState {
entries: Vec::new(),
last_hash: [0u8; 32],
tamper_detected: false,
last_timestamp: 0,
}));
let tamper_flag = Arc::new(AtomicBool::new(false));
let (sender, receiver) = std::sync::mpsc::channel();
let worker = Self::spawn_worker(
Arc::clone(&state),
None,
Arc::clone(&tamper_flag),
receiver,
[0u8; 32],
0,
);
Self {
state,
log_path: None,
sender: Some(sender),
tamper_flag,
worker: Some(worker),
audit_chain_key: Arc::new(Zeroizing::new([0u8; 32])),
}
}
pub fn new_with_path(path: PathBuf) -> Result<Self, crate::error::HsmError> {
let path = validate_log_path(&path)?;
let (recovered_hash, tampered) = match Self::recover_chain_from_file(&path) {
ChainRecoveryResult::NoFile => ([0u8; 32], false),
ChainRecoveryResult::Verified(hash) => (hash, false),
ChainRecoveryResult::Broken(reason) => {
tracing::error!(
"Audit chain integrity check FAILED for {}: {}. \
Tamper flag set — record() will refuse new events.",
path.display(),
reason,
);
([0u8; 32], true)
}
};
let state = Arc::new(RwLock::new(AuditLogState {
entries: Vec::new(),
last_hash: recovered_hash,
tamper_detected: tampered,
last_timestamp: 0,
}));
let tamper_flag = Arc::new(AtomicBool::new(tampered));
let (sender, receiver) = std::sync::mpsc::channel();
let worker = Self::spawn_worker(
Arc::clone(&state),
Some(path.clone()),
Arc::clone(&tamper_flag),
receiver,
recovered_hash,
0,
);
Ok(Self {
state,
log_path: Some(path),
sender: Some(sender),
tamper_flag,
worker: Some(worker),
audit_chain_key: Arc::new(Zeroizing::new([0u8; 32])),
})
}
pub fn is_tamper_detected(&self) -> bool {
self.tamper_flag.load(Ordering::Acquire)
}
fn recover_chain_from_file(path: &Path) -> ChainRecoveryResult {
let file = match std::fs::File::open(path) {
Ok(f) => f,
Err(e) => {
if e.kind() == std::io::ErrorKind::NotFound {
return ChainRecoveryResult::NoFile;
}
return ChainRecoveryResult::Broken(format!(
"could not open log file {}: {}",
path.display(),
e,
));
}
};
let reader = std::io::BufReader::new(file);
let mut running_hash = [0u8; 32];
let mut scratch = Vec::with_capacity(64);
for (line_num, line_result) in reader.lines().enumerate() {
let line = match line_result {
Ok(l) => l,
Err(e) => {
return ChainRecoveryResult::Broken(format!(
"I/O error at line {}: {}",
line_num + 1,
e,
));
}
};
let trimmed = line.trim();
if trimmed.is_empty() {
continue;
}
let event: AuditEvent = match serde_json::from_str(trimmed) {
Ok(ev) => ev,
Err(e) => {
return ChainRecoveryResult::Broken(format!(
"failed to deserialize line {}: {}",
line_num + 1,
e,
));
}
};
if event.previous_hash != running_hash {
return ChainRecoveryResult::Broken(format!(
"TAMPER DETECTED at line {}: expected previous_hash {:02x?}, found {:02x?}",
line_num + 1,
&running_hash[..8],
&event.previous_hash[..8],
));
}
match compute_chain_hash_with(&running_hash, &event, &mut scratch) {
Ok(h) => running_hash = h,
Err(_) => {
return ChainRecoveryResult::Broken(format!(
"serialization failed at line {}",
line_num + 1,
));
}
}
}
if running_hash == [0u8; 32] {
ChainRecoveryResult::NoFile
} else {
tracing::info!(
"Audit chain recovery: restored and verified chain from {}",
path.display(),
);
ChainRecoveryResult::Verified(running_hash)
}
}
fn rotate_log_files(path: &Path) -> Result<(), crate::error::HsmError> {
tracing::info!(
"Audit log rotation: {} exceeds {} bytes, rotating.",
path.display(),
MAX_LOG_FILE_BYTES,
);
for gen in (1..MAX_ROTATED_FILES).rev() {
let from = rotated_path(path, gen);
let to = rotated_path(path, gen + 1);
if from.exists() {
if let Err(e) = std::fs::rename(&from, &to) {
tracing::error!(
"Audit log rotation: failed to rename {} -> {}: {}",
from.display(),
to.display(),
e,
);
return Err(crate::error::HsmError::GeneralError);
}
}
}
let gen1 = rotated_path(path, 1);
std::fs::rename(path, &gen1).map_err(|e| {
tracing::error!("Audit log rotation: rename failed: {}", e);
crate::error::HsmError::GeneralError
})?;
Ok(())
}
pub fn record(
&self,
session_handle: u64,
operation: AuditOperation,
result: AuditResult,
key_id: Option<String>,
) -> crate::error::HsmResult<()> {
self.record_internal(session_handle, operation, result, key_id, None)
}
pub fn record_sync(
&self,
session_handle: u64,
operation: AuditOperation,
result: AuditResult,
key_id: Option<String>,
) -> crate::error::HsmResult<()> {
let (tx, rx) = std::sync::mpsc::sync_channel::<Result<(), crate::error::HsmError>>(1);
self.record_internal(session_handle, operation, result, key_id, Some(tx))?;
match rx.recv() {
Ok(result) => result,
Err(_) => {
tracing::error!(
"Audit worker disconnected before acknowledging record_sync — \
event durability cannot be guaranteed."
);
Err(crate::error::HsmError::GeneralError)
}
}
}
fn record_internal(
&self,
session_handle: u64,
operation: AuditOperation,
result: AuditResult,
key_id: Option<String>,
done: Option<std::sync::mpsc::SyncSender<Result<(), crate::error::HsmError>>>,
) -> crate::error::HsmResult<()> {
if self.tamper_flag.load(Ordering::Acquire) {
return Err(crate::error::HsmError::AuditChainBroken(
"refusing to record: audit chain tamper previously detected".to_string(),
));
}
let key_id = key_id.map(|s| sanitize_audit_field(&s));
if let Some(sender) = &self.sender {
sender
.send(AuditCommand::Record {
session_handle,
operation,
result,
key_id,
done,
})
.map_err(|_| crate::error::HsmError::GeneralError)?;
}
Ok(())
}
pub fn flush(&self) -> crate::error::HsmResult<()> {
if let Some(sender) = &self.sender {
let (tx, rx) = std::sync::mpsc::channel();
sender.send(AuditCommand::Flush { done: tx }).map_err(|_| {
tracing::error!("Audit flush: worker channel closed");
crate::error::HsmError::GeneralError
})?;
rx.recv_timeout(std::time::Duration::from_secs(5))
.map_err(|e| {
tracing::error!(
"Audit flush: worker did not acknowledge within timeout: {}",
e
);
crate::error::HsmError::GeneralError
})?;
}
Ok(())
}
pub fn entry_count(&self) -> usize {
self.state.read().entries.len()
}
pub fn get_entries(&self) -> Vec<AuditEvent> {
self.state.read().entries.clone()
}
pub fn get_recent_entries(&self, n: usize) -> Vec<AuditEvent> {
let state = self.state.read();
let start = state.entries.len().saturating_sub(n);
state.entries[start..].to_vec()
}
pub fn get_entries_paginated(&self, offset: usize, limit: usize) -> Vec<AuditEvent> {
let state = self.state.read();
let end = (offset + limit).min(state.entries.len());
if offset >= state.entries.len() {
return Vec::new();
}
state.entries[offset..end].to_vec()
}
pub fn export_json(&self) -> String {
let entries = self.state.read().entries.clone();
serde_json::to_string_pretty(&entries).unwrap_or_else(|_| "[]".to_string())
}
pub fn export_ndjson(&self) -> String {
let entries = self.state.read().entries.clone();
entries
.iter()
.map(|e| {
serde_json::to_string(e).unwrap_or_else(|err| {
tracing::error!(
"Audit export: failed to serialize event (session={}, ts={}): {}",
e.session_handle,
e.timestamp,
err,
);
format!(
"{{\"error\":\"serialization_failed\",\"session_handle\":{},\"timestamp\":{}}}",
e.session_handle, e.timestamp
)
})
})
.collect::<Vec<_>>()
.join("\n")
}
pub fn export_syslog(&self) -> Vec<String> {
let entries = self.state.read().entries.clone();
entries
.iter()
.map(|e| {
let severity = match &e.result {
AuditResult::Success => 6, AuditResult::Failure(_) => 4, };
let facility = 10; let priority = facility * 8 + severity;
let timestamp = format_rfc3339(e.timestamp);
let op_name = format_operation_name(&e.operation);
let result_str = match &e.result {
AuditResult::Success => "SUCCESS".to_string(),
AuditResult::Failure(rv) => format!("FAILURE(0x{:08X})", rv),
};
let key_str = e.key_id.as_deref().unwrap_or("-");
let sd = format!(
"[hsm@0 session=\"{}\" op=\"{}\" result=\"{}\" key=\"{}\"]",
e.session_handle,
escape_sd_value(op_name),
escape_sd_value(&result_str),
escape_sd_value(key_str),
);
let msg = format!(
"session={} op={} result={} key={}",
e.session_handle,
sanitize_syslog_msg_value(op_name),
sanitize_syslog_msg_value(&result_str),
sanitize_syslog_msg_value(key_str),
);
format!(
"<{}>1 {} craton_hsm craton_hsm - - {} {}",
priority, timestamp, sd, msg
)
})
.collect()
}
pub fn verify_chain(&self) -> Result<usize, usize> {
verify_chain_entries(&self.state.read().entries)
}
}
pub fn load_entries_from_file(path: &Path) -> Result<Vec<AuditEvent>, crate::error::HsmError> {
let file = std::fs::File::open(path).map_err(|e| {
tracing::error!("Audit log load: cannot open {}: {}", path.display(), e);
crate::error::HsmError::AuditChainBroken(format!(
"could not open log file {}: {}",
path.display(),
e,
))
})?;
let reader = std::io::BufReader::new(file);
let mut entries = Vec::new();
for (line_num, line_result) in reader.lines().enumerate() {
let line = line_result.map_err(|e| {
crate::error::HsmError::AuditChainBroken(format!(
"I/O error at line {}: {}",
line_num + 1,
e,
))
})?;
let trimmed = line.trim();
if trimmed.is_empty() {
continue;
}
let event: AuditEvent = serde_json::from_str(trimmed).map_err(|e| {
crate::error::HsmError::AuditChainBroken(format!(
"failed to deserialize line {}: {}",
line_num + 1,
e,
))
})?;
entries.push(event);
}
Ok(entries)
}
pub fn verify_chain_entries(entries: &[AuditEvent]) -> Result<usize, usize> {
let mut expected_hash = [0u8; 32];
let mut scratch = Vec::with_capacity(64);
for (i, entry) in entries.iter().enumerate() {
if entry.previous_hash != expected_hash {
return Err(i);
}
match compute_chain_hash_with(&expected_hash, entry, &mut scratch) {
Ok(h) => expected_hash = h,
Err(_) => return Err(i),
}
}
Ok(entries.len())
}
impl AuditLog {
pub fn register_global_logger(self: &Arc<Self>) {
*GLOBAL_AUDIT_LOG.write() = Some(Arc::downgrade(self));
}
}
impl Drop for AuditLog {
fn drop(&mut self) {
self.sender.take();
if let Some(handle) = self.worker.take() {
let _ = handle.join();
}
}
}
fn rotated_path(base: &Path, generation: u32) -> PathBuf {
let mut name = base.as_os_str().to_os_string();
name.push(format!(".{}", generation));
PathBuf::from(name)
}
fn format_rfc3339(nanos: u64) -> String {
let secs = nanos / 1_000_000_000;
let subsec = nanos % 1_000_000_000;
let days_since_epoch = secs / 86400;
let time_of_day = secs % 86400;
let hours = time_of_day / 3600;
let minutes = (time_of_day % 3600) / 60;
let seconds = time_of_day % 60;
let (year, month, day) = days_to_ymd(days_since_epoch);
format!(
"{:04}-{:02}-{:02}T{:02}:{:02}:{:02}.{:06}Z",
year,
month,
day,
hours,
minutes,
seconds,
subsec / 1000
)
}
fn days_to_ymd(days: u64) -> (u64, u64, u64) {
let z = days + 719468;
let era = z / 146097;
let doe = z - era * 146097;
let yoe = (doe - doe / 1460 + doe / 36524 - doe / 146096) / 365;
let y = yoe + era * 400;
let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
let mp = (5 * doy + 2) / 153;
let d = doy - (153 * mp + 2) / 5 + 1;
let m = if mp < 10 { mp + 3 } else { mp - 9 };
let y = if m <= 2 { y + 1 } else { y };
(y, m, d)
}
fn sanitize_audit_field(s: &str) -> String {
s.chars().filter(|c| !c.is_control()).take(256).collect()
}
fn escape_sd_value(s: &str) -> String {
let mut out = String::with_capacity(s.len());
for c in s.chars() {
match c {
'"' | '\\' | ']' => {
out.push('\\');
out.push(c);
}
_ => out.push(c),
}
}
out
}
fn sanitize_syslog_msg_value(s: &str) -> String {
s.chars()
.filter(|c| !c.is_control() && *c != '<' && *c != '>')
.collect()
}
fn format_operation_name(op: &AuditOperation) -> &'static str {
match op {
AuditOperation::Initialize => "Initialize",
AuditOperation::Finalize => "Finalize",
AuditOperation::OpenSession { .. } => "OpenSession",
AuditOperation::CloseSession => "CloseSession",
AuditOperation::Login { .. } => "Login",
AuditOperation::Logout => "Logout",
AuditOperation::InitToken { .. } => "InitToken",
AuditOperation::InitPIN { .. } => "InitPIN",
AuditOperation::SetPIN => "SetPIN",
AuditOperation::GenerateKey { .. } => "GenerateKey",
AuditOperation::GenerateKeyPair { .. } => "GenerateKeyPair",
AuditOperation::Sign { .. } => "Sign",
AuditOperation::Verify { .. } => "Verify",
AuditOperation::Encrypt { .. } => "Encrypt",
AuditOperation::Decrypt { .. } => "Decrypt",
AuditOperation::Digest { .. } => "Digest",
AuditOperation::CreateObject => "CreateObject",
AuditOperation::DestroyObject => "DestroyObject",
AuditOperation::GenerateRandom { .. } => "GenerateRandom",
AuditOperation::WrapKey { .. } => "WrapKey",
AuditOperation::UnwrapKey { .. } => "UnwrapKey",
AuditOperation::DeriveKey { .. } => "DeriveKey",
AuditOperation::FindObjects { .. } => "FindObjects",
AuditOperation::GetAttributeValue => "GetAttributeValue",
AuditOperation::Zeroize { .. } => "Zeroize",
}
}
pub fn record_zeroization(key_size: usize) {
if let Some(weak) = &*GLOBAL_AUDIT_LOG.read() {
if let Some(logger) = weak.upgrade() {
let _ = logger.record(
0, AuditOperation::Zeroize {
key_length: key_size as u32,
},
AuditResult::Success,
None,
);
}
}
}
#[cfg(test)]
mod codec_tests {
use super::*;
fn event(operation: AuditOperation, key_id: Option<&str>, result: AuditResult) -> AuditEvent {
AuditEvent {
format_version: AUDIT_LOG_FORMAT_VERSION,
timestamp: 1_700_000_000_000_000_000,
session_handle: 7,
operation,
key_id: key_id.map(str::to_string),
result,
previous_hash: [0xAB; 32],
}
}
fn encode(ev: &AuditEvent) -> Vec<u8> {
let mut buf = Vec::new();
encode_payload_v1(ev, &mut buf);
buf
}
#[test]
fn every_operation_variant_encodes_distinctly() {
let variants = vec![
AuditOperation::Initialize,
AuditOperation::Finalize,
AuditOperation::OpenSession { slot_id: 1 },
AuditOperation::CloseSession,
AuditOperation::Login { user_type: 1 },
AuditOperation::Logout,
AuditOperation::InitToken { slot_id: 1 },
AuditOperation::InitPIN { slot_id: 1 },
AuditOperation::SetPIN,
AuditOperation::GenerateKey {
mechanism: 1,
key_length: 1,
fips_approved: true,
},
AuditOperation::GenerateKeyPair {
mechanism: 1,
key_length: 1,
fips_approved: true,
},
AuditOperation::Sign {
mechanism: 1,
fips_approved: true,
},
AuditOperation::Verify {
mechanism: 1,
fips_approved: true,
},
AuditOperation::Encrypt {
mechanism: 1,
fips_approved: true,
},
AuditOperation::Decrypt {
mechanism: 1,
fips_approved: true,
},
AuditOperation::Digest {
mechanism: 1,
fips_approved: true,
},
AuditOperation::CreateObject,
AuditOperation::DestroyObject,
AuditOperation::GenerateRandom { length: 1 },
AuditOperation::WrapKey {
mechanism: 1,
fips_approved: true,
},
AuditOperation::UnwrapKey {
mechanism: 1,
fips_approved: true,
},
AuditOperation::DeriveKey {
mechanism: 1,
fips_approved: true,
},
AuditOperation::FindObjects { result_count: 1 },
AuditOperation::GetAttributeValue,
AuditOperation::Zeroize { key_length: 1 },
];
assert_eq!(
variants.len(),
25,
"add the new AuditOperation variant to this list and give it a tag",
);
let mut seen: std::collections::HashMap<Vec<u8>, usize> = std::collections::HashMap::new();
for (i, op) in variants.into_iter().enumerate() {
let bytes = encode(&event(op, None, AuditResult::Success));
if let Some(prev) = seen.insert(bytes, i) {
panic!("operation variants {} and {} encode identically", prev, i);
}
}
}
#[test]
fn operation_fields_affect_the_encoding() {
let a = encode(&event(
AuditOperation::Sign {
mechanism: 0x40,
fips_approved: true,
},
None,
AuditResult::Success,
));
let mechanism_changed = encode(&event(
AuditOperation::Sign {
mechanism: 0x41,
fips_approved: true,
},
None,
AuditResult::Success,
));
let flag_changed = encode(&event(
AuditOperation::Sign {
mechanism: 0x40,
fips_approved: false,
},
None,
AuditResult::Success,
));
assert_ne!(a, mechanism_changed, "mechanism must be encoded");
assert_ne!(a, flag_changed, "fips_approved must be encoded");
}
#[test]
fn key_id_is_length_prefixed() {
let short = encode(&event(
AuditOperation::Logout,
Some("ab"),
AuditResult::Success,
));
let long = encode(&event(
AuditOperation::Logout,
Some("abc"),
AuditResult::Success,
));
let none = encode(&event(AuditOperation::Logout, None, AuditResult::Success));
assert_ne!(short, long, "key_id contents must be encoded");
assert_ne!(short, none, "presence of key_id must be encoded");
assert!(none.len() < short.len());
}
#[test]
fn result_variants_encode_distinctly() {
let ok = encode(&event(AuditOperation::Logout, None, AuditResult::Success));
let fail_a = encode(&event(
AuditOperation::Logout,
None,
AuditResult::Failure(0x30),
));
let fail_b = encode(&event(
AuditOperation::Logout,
None,
AuditResult::Failure(0x31),
));
assert_ne!(ok, fail_a, "success and failure must differ");
assert_ne!(fail_a, fail_b, "the failure code must be encoded");
}
#[test]
fn header_fields_affect_the_encoding() {
let base = event(AuditOperation::Logout, None, AuditResult::Success);
let baseline = encode(&base);
let mut other = base.clone();
other.timestamp += 1;
assert_ne!(baseline, encode(&other), "timestamp must be encoded");
let mut other = base.clone();
other.session_handle += 1;
assert_ne!(baseline, encode(&other), "session_handle must be encoded");
let mut other = base.clone();
other.format_version = 0;
assert_ne!(
baseline,
encode(&other),
"format_version must be encoded so a downgrade rewrite is detected",
);
}
#[test]
fn chain_hash_dispatches_on_format_version() {
let prev = [0u8; 32];
let mut v1 = event(AuditOperation::Logout, None, AuditResult::Success);
v1.format_version = 1;
let mut v0 = v1.clone();
v0.format_version = 0;
let h1 = compute_chain_hash(&prev, &v1).expect("v1 hashes");
let h0 = compute_chain_hash(&prev, &v0).expect("v0 hashes");
assert_ne!(h0, h1, "v0 and v1 encodings must produce different links");
}
#[test]
fn unknown_format_version_is_rejected() {
let mut ev = event(AuditOperation::Logout, None, AuditResult::Success);
ev.format_version = 99;
assert!(
compute_chain_hash(&[0u8; 32], &ev).is_err(),
"an unrecognised format_version must not verify",
);
}
#[test]
fn scratch_buffer_reuse_does_not_leak_between_events() {
let long = event(
AuditOperation::Logout,
Some("a-considerably-longer-key-identifier"),
AuditResult::Success,
);
let short = event(AuditOperation::Logout, None, AuditResult::Success);
let prev = [0u8; 32];
let mut scratch = Vec::new();
let _ = compute_chain_hash_with(&prev, &long, &mut scratch).expect("long hashes");
let reused = compute_chain_hash_with(&prev, &short, &mut scratch).expect("short hashes");
let fresh = compute_chain_hash(&prev, &short).expect("short hashes standalone");
assert_eq!(
reused, fresh,
"a reused scratch buffer must produce the same hash as a fresh one",
);
}
}