nordisk/gunnar

crates/gunnar-grpc/tests/machine_enrolment_audit.rs

//! **Every step of a machine enrolment is audited** (2026-10-05) — its own
//! test binary: `tracing` caches a callsite's interest per process, and a
//! callsite first hit by a concurrent test with no subscriber is never
//! delivered to this one's (MEASURED: only the refusal, which no other test
//! reaches, was captured). Alone here, every line is.

mod machine_enrolment_common;

use std::sync::{Arc, Mutex};

use gunnar_grpc::AUDIT_TARGET;
use gunnar_proto::access_server::Access as _;
use gunnar_proto::*;
use machine_enrolment_common::*;
use tracing_subscriber::layer::SubscriberExt as _;

// ── the audit trail ─────────────────────────────────────────────────────────

#[derive(Clone, Default)]
struct AuditLog(Arc<Mutex<Vec<String>>>);

struct AuditLayer(AuditLog);

impl<S: tracing::Subscriber> tracing_subscriber::Layer<S> for AuditLayer {
    fn on_event(
        &self,
        event: &tracing::Event<'_>,
        _ctx: tracing_subscriber::layer::Context<'_, S>,
    ) {
        if event.metadata().target() != AUDIT_TARGET {
            return;
        }
        struct Visit(String);
        impl tracing::field::Visit for Visit {
            fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
                self.0.push_str(&format!("{}={:?} ", field.name(), value));
            }
        }
        let mut visit = Visit(String::new());
        event.record(&mut visit);
        self.0 .0.lock().unwrap().push(visit.0);
    }
}

/// ★ **Every step is audited**: the request (machine, role, code, key), the
/// approval (by whom, through which door) and the refusal — each its own
/// event on gunnar's audit target.
#[test]
fn every_step_is_audited() {
    let log = AuditLog::default();
    let runtime = tokio::runtime::Builder::new_current_thread()
        .build()
        .expect("runtime");
    let subscriber = tracing_subscriber::registry().with(AuditLayer(log.clone()));
    tracing::subscriber::with_default(subscriber, || {
        runtime.block_on(every_step_is_audited_inner(log.clone()))
    });
}

async fn every_step_is_audited_inner(log: AuditLog) {
    let h = Harness::new();
    let kit = Authenticator::new(9, b"kit-dwarf-key");
    let asked = h.ask(&kit, "kit-dwarf", GrantLevel::Admin).await;
    h.approve(&h.kim, &asked, Some(h.kims_step_up().await))
        .await
        .expect("approved");
    let other = Authenticator::new(10, b"kit-other-key");
    let refused = h.ask(&other, "kit-other", GrantLevel::Write).await;
    h.access()
        .refuse_machine_enrolment(Harness::authed(
            &h.kim,
            RefuseMachineEnrolmentRequest {
                request_id: refused.request_id.clone(),
            },
        ))
        .await
        .expect("refused");

    let lines = log.0.lock().unwrap().clone();
    let find = |event: &str, with: &[&str]| {
        lines
            .iter()
            .find(|l| {
                l.contains(&format!("event=\"{event}\"")) && with.iter().all(|w| l.contains(w))
            })
            .unwrap_or_else(|| panic!("no {event} line with {with:?}; captured {lines:#?}"))
            .clone()
    };
    find(
        "access.machine_enrolment_requested",
        &["kit-dwarf", &asked.code, "admin", "SHA256:"],
    );
    find(
        "access.machine_enrolment_approved",
        &["kit-dwarf", &asked.code, "kim", "step-up"],
    );
    find(
        "access.machine_enrolment_refused",
        &["kit-other", &refused.code, "kim"],
    );
}