use std::sync::Arc;
use std::time::Duration;
use affinidi_did_resolver_cache_sdk::DIDCacheClient;
use affinidi_messaging_didcomm_service::DIDCommService;
use affinidi_tdk::secrets_resolver::secrets::Secret;
use did_hosting_common::server::didcomm_profile::{PeerTransport, TransportFallback};
use did_hosting_common::server::error::AppError;
use did_hosting_common::server::store::{KS_OUTBOUND_QUEUE, KeyspaceHandle, Store};
use did_hosting_common::server::trust_tasks::send::{build_signed_request, send_trust_task};
use serde::{Deserialize, Serialize};
use serde_json::Value;
use tokio::sync::{Notify, watch};
use tracing::{debug, info, warn};
use crate::auth::session::now_epoch;
use crate::server::AppState;
pub const DEFAULT_OUTBOX_TICK: Duration = Duration::from_secs(30);
pub const MAX_ATTEMPTS: u32 = 50;
pub const MAX_AGE_SECS: u64 = 7 * 24 * 60 * 60;
pub const MAX_BACKOFF_SECS: u64 = 5 * 60;
#[derive(Debug, Clone, Serialize, Deserialize, PartialEq, Eq)]
pub struct OutboxEntry {
pub target_did: String,
pub msg_type: String,
pub body: Value,
pub enqueued_at: u64,
pub attempts: u32,
pub next_attempt_at: u64,
pub last_error: Option<String>,
#[serde(default)]
pub awaiting_ack: Option<String>,
}
pub const ACK_TIMEOUT_SECS: u64 = 60;
#[derive(Debug, PartialEq, Eq)]
pub enum HeadAction {
Send,
Wait,
}
pub fn head_action(entry: &OutboxEntry, now: u64) -> HeadAction {
if entry.next_attempt_at > now {
HeadAction::Wait
} else {
HeadAction::Send
}
}
fn outbox_ks(store: &Store) -> Result<KeyspaceHandle, AppError> {
store.keyspace(KS_OUTBOUND_QUEUE)
}
fn outbox_key(target_did: &str, enqueue_micros: u128, uuid_short: &str) -> Vec<u8> {
format!("outbox:{target_did}:{enqueue_micros:020}:{uuid_short}").into_bytes()
}
fn target_prefix(target_did: &str) -> Vec<u8> {
format!("outbox:{target_did}:").into_bytes()
}
fn now_micros() -> u128 {
std::time::SystemTime::now()
.duration_since(std::time::UNIX_EPOCH)
.map(|d| d.as_micros())
.unwrap_or(0)
}
fn truncated(err: &str) -> String {
const MAX: usize = 200;
if err.len() <= MAX {
err.to_string()
} else {
format!("{}…", &err[..MAX])
}
}
fn compute_backoff(attempts: u32) -> u64 {
let secs = 1u64
.checked_shl(attempts.min(10))
.unwrap_or(MAX_BACKOFF_SECS);
secs.min(MAX_BACKOFF_SECS)
}
pub async fn enqueue(
store: &Store,
target_did: &str,
msg_type: &str,
body: Value,
) -> Result<Vec<u8>, AppError> {
let now = now_epoch();
let entry = OutboxEntry {
target_did: target_did.to_string(),
msg_type: msg_type.to_string(),
body,
enqueued_at: now,
attempts: 0,
next_attempt_at: now,
last_error: None,
awaiting_ack: None,
};
let uuid_short = uuid::Uuid::new_v4().simple().to_string();
let key = outbox_key(target_did, now_micros(), &uuid_short[..12]);
outbox_ks(store)?.insert(key.clone(), &entry).await?;
Ok(key)
}
pub async fn enqueue_and_notify(
state: &AppState,
target_did: &str,
msg_type: &str,
body: Value,
) -> Result<Vec<u8>, AppError> {
let key = enqueue(&state.store, target_did, msg_type, body).await?;
state.outbox_notify.notify_one();
Ok(key)
}
pub async fn list_targets(store: &Store) -> Result<Vec<String>, AppError> {
let raw = outbox_ks(store)?
.prefix_iter_raw(b"outbox:".to_vec())
.await?;
let mut targets: Vec<String> = raw
.iter()
.filter_map(|(k, _)| {
let s = std::str::from_utf8(k).ok()?;
let after_prefix = s.strip_prefix("outbox:")?;
let last_colon = after_prefix.rfind(':')?;
let before_uuid = &after_prefix[..last_colon];
let second_last_colon = before_uuid.rfind(':')?;
Some(after_prefix[..second_last_colon].to_string())
})
.collect();
targets.sort();
targets.dedup();
Ok(targets)
}
pub async fn list_pending_for_target(
store: &Store,
target_did: &str,
) -> Result<Vec<(Vec<u8>, OutboxEntry)>, AppError> {
let raw = outbox_ks(store)?
.prefix_iter_raw(target_prefix(target_did))
.await?;
let mut out = Vec::with_capacity(raw.len());
for (k, v) in raw {
match serde_json::from_slice::<OutboxEntry>(&v) {
Ok(e) => out.push((k, e)),
Err(e) => {
warn!(
target_did,
error = %e,
"outbox: dropping malformed entry"
);
let _ = outbox_ks(store)?.remove(k).await;
}
}
}
out.sort_by_key(|(k, _)| k.clone());
Ok(out)
}
pub async fn remove(store: &Store, key: Vec<u8>) -> Result<(), AppError> {
outbox_ks(store)?.remove(key).await
}
static ROW_LOCK: tokio::sync::Mutex<()> = tokio::sync::Mutex::const_new(());
async fn rewrite_if_present(
store: &Store,
key: Vec<u8>,
next: &OutboxEntry,
) -> Result<(), AppError> {
let _guard = ROW_LOCK.lock().await;
let ks = outbox_ks(store)?;
if !ks.contains_key(key.clone()).await? {
return Ok(());
}
ks.insert(key, next).await
}
async fn retire(store: &Store, key: Vec<u8>) -> Result<(), AppError> {
let _guard = ROW_LOCK.lock().await;
remove(store, key).await
}
pub async fn record_failure(
store: &Store,
key: Vec<u8>,
entry: &OutboxEntry,
err: &str,
) -> Result<(), AppError> {
let next = OutboxEntry {
attempts: entry.attempts.saturating_add(1),
last_error: Some(truncated(err)),
next_attempt_at: now_epoch().saturating_add(compute_backoff(entry.attempts + 1)),
awaiting_ack: None,
..entry.clone()
};
rewrite_if_present(store, key, &next).await
}
pub async fn record_sent(
store: &Store,
key: Vec<u8>,
entry: &OutboxEntry,
doc_id: &str,
) -> Result<(), AppError> {
let next = OutboxEntry {
attempts: entry.attempts.saturating_add(1),
next_attempt_at: now_epoch().saturating_add(ACK_TIMEOUT_SECS),
awaiting_ack: Some(doc_id.to_string()),
..entry.clone()
};
rewrite_if_present(store, key, &next).await
}
pub async fn drop_queued(
store: &Store,
target_did: &str,
msg_type: &str,
matches: impl Fn(&Value) -> bool,
) -> Result<usize, AppError> {
let mut dropped = 0;
for (key, entry) in list_pending_for_target(store, target_did).await? {
if entry.msg_type == msg_type && matches(&entry.body) {
retire(store, key).await?;
dropped += 1;
}
}
Ok(dropped)
}
pub async fn acknowledge(store: &Store, signer: &str, doc_id: &str) -> Result<bool, AppError> {
for (key, entry) in list_pending_for_target(store, signer).await? {
if entry.awaiting_ack.as_deref() == Some(doc_id) {
retire(store, key).await?;
return Ok(true);
}
}
Ok(false)
}
pub async fn signed_document(
control_did: &str,
entry: &OutboxEntry,
signer: &Secret,
) -> Result<trust_tasks_rs::TrustTask<Value>, Box<dyn std::error::Error + Send + Sync>> {
build_signed_request(
&entry.msg_type,
control_did,
&entry.target_did,
entry.body.clone(),
signer,
)
.await
}
async fn deliver(
didcomm: &DIDCommService,
control_did: &str,
entry: &OutboxEntry,
signer: &Secret,
fallback: &TransportFallback,
did_resolver: Option<&DIDCacheClient>,
) -> Result<(String, PeerTransport), Box<dyn std::error::Error + Send + Sync>> {
let doc = signed_document(control_did, entry, signer).await?;
let transport = send_trust_task(
didcomm,
"control",
control_did,
&entry.target_did,
&doc,
fallback,
did_resolver,
)
.await?;
Ok((doc.id.clone(), transport))
}
#[derive(Debug, Default, PartialEq, Eq)]
pub struct TickReport {
pub sent: u64,
pub deferred: u64,
pub dropped: u64,
}
pub async fn run_tick(state: &AppState) -> TickReport {
let svc = match state.didcomm_service.get() {
Some(s) => s.clone(),
None => {
debug!("outbox tick: DIDComm service not yet initialised; skipping");
return TickReport::default();
}
};
let control_did = match state.config.server_did.as_deref() {
Some(d) => d.to_string(),
None => {
debug!("outbox tick: control server_did not configured; skipping");
return TickReport::default();
}
};
let targets = match list_targets(&state.store).await {
Ok(t) => t,
Err(e) => {
warn!(error = %e, "outbox tick: list_targets failed");
return TickReport::default();
}
};
let signer = match crate::signing::control_signing_secret(state, &control_did) {
Ok(s) => s,
Err(e) => {
warn!(error = %e, "outbox tick: cannot sign outbound documents; skipping");
return TickReport::default();
}
};
let fallback = TransportFallback::from_config(
state.config.mediator_did.as_deref(),
state.config.features.tsp,
);
let mut report = TickReport::default();
let now = now_epoch();
for target in targets {
let pending = match list_pending_for_target(&state.store, &target).await {
Ok(p) => p,
Err(e) => {
warn!(target_did = %target, error = %e, "outbox tick: list_pending failed");
continue;
}
};
for (key, entry) in pending {
if entry.attempts >= MAX_ATTEMPTS
|| now.saturating_sub(entry.enqueued_at) >= MAX_AGE_SECS
{
warn!(
target_did = %target,
msg_type = %entry.msg_type,
attempts = entry.attempts,
age_secs = now.saturating_sub(entry.enqueued_at),
last_error = entry.last_error.as_deref().unwrap_or(""),
"outbox: dropping entry past retry budget"
);
let _ = remove(&state.store, key).await;
report.dropped += 1;
continue;
}
if head_action(&entry, now) == HeadAction::Wait {
report.deferred += 1;
break;
}
if entry.awaiting_ack.is_some() {
debug!(
target_did = %target,
msg_type = %entry.msg_type,
"outbox: no acknowledgement within the timeout; re-sending"
);
}
match deliver(
&svc,
&control_did,
&entry,
&signer,
&fallback,
state.did_resolver.as_ref(),
)
.await
{
Ok((doc_id, transport)) => {
debug!(
target_did = %target,
msg_type = %entry.msg_type,
attempts = entry.attempts + 1,
%doc_id,
?transport,
"outbox: sent; awaiting acknowledgement"
);
let _ = record_sent(&state.store, key, &entry, &doc_id).await;
report.sent += 1;
if transport == PeerTransport::Https {
match acknowledge(&state.store, &target, &doc_id).await {
Ok(true) => debug!(
target_did = %target,
%doc_id,
"outbox: HTTPS send self-acknowledged"
),
Ok(false) => warn!(
target_did = %target,
%doc_id,
"outbox: HTTPS send succeeded but found no matching \
awaiting_ack row to settle"
),
Err(e) => warn!(
target_did = %target,
%doc_id,
error = %e,
"outbox: failed to self-acknowledge HTTPS send"
),
}
}
}
Err(e) => {
let err_str = e.to_string();
warn!(
target_did = %target,
msg_type = %entry.msg_type,
attempts = entry.attempts + 1,
error = %err_str,
"outbox: delivery failed; will retry after backoff"
);
let _ = record_failure(&state.store, key, &entry, &err_str).await;
report.deferred += 1;
}
}
break;
}
}
report
}
pub async fn run_outbox_loop(
state: AppState,
notify: Arc<Notify>,
mut shutdown: watch::Receiver<bool>,
) {
let mut ticker = tokio::time::interval(DEFAULT_OUTBOX_TICK);
ticker.tick().await;
loop {
tokio::select! {
_ = ticker.tick() => {
let report = run_tick(&state).await;
if report.sent > 0 || report.dropped > 0 {
info!(?report, "outbox tick");
}
}
_ = notify.notified() => {
let report = run_tick(&state).await;
if report.sent > 0 || report.dropped > 0 {
info!(?report, "outbox tick (notified)");
}
}
_ = shutdown.changed() => {
info!("outbox worker shutting down");
return;
}
}
}
}
#[cfg(test)]
mod tests {
use super::*;
use did_hosting_common::server::config::StoreConfig;
use serde_json::json;
async fn fjall_store() -> Store {
let dir = tempfile::tempdir().expect("tempdir");
let cfg = StoreConfig {
data_dir: dir.path().to_path_buf(),
..StoreConfig::default()
};
std::mem::forget(dir);
Store::open(&cfg).await.expect("open fjall")
}
#[tokio::test]
async fn enqueue_then_list_targets_and_pending() {
let store = fjall_store().await;
enqueue(&store, "did:example:a", "ty/1.0", json!({"k":1}))
.await
.unwrap();
enqueue(&store, "did:example:b", "ty/1.0", json!({"k":2}))
.await
.unwrap();
enqueue(&store, "did:example:a", "ty/1.0", json!({"k":3}))
.await
.unwrap();
let mut targets = list_targets(&store).await.unwrap();
targets.sort();
assert_eq!(targets, vec!["did:example:a", "did:example:b"]);
let a = list_pending_for_target(&store, "did:example:a")
.await
.unwrap();
assert_eq!(a.len(), 2);
assert_eq!(a[0].1.body, json!({"k": 1}));
assert_eq!(a[1].1.body, json!({"k": 3}));
}
#[tokio::test]
async fn list_targets_handles_did_with_internal_colons() {
let store = fjall_store().await;
let did = "did:webvh:QmAbc:host.example.com";
enqueue(&store, did, "ty/1.0", json!({})).await.unwrap();
let targets = list_targets(&store).await.unwrap();
assert_eq!(targets, vec![did.to_string()]);
}
#[tokio::test]
async fn record_failure_increments_and_backs_off() {
let store = fjall_store().await;
let key = enqueue(&store, "did:example:a", "ty/1.0", json!({}))
.await
.unwrap();
let pending = list_pending_for_target(&store, "did:example:a")
.await
.unwrap();
let entry = pending[0].1.clone();
assert_eq!(entry.attempts, 0);
record_failure(&store, key, &entry, "boom").await.unwrap();
let after = list_pending_for_target(&store, "did:example:a")
.await
.unwrap();
assert_eq!(after.len(), 1);
assert_eq!(after[0].1.attempts, 1);
assert_eq!(after[0].1.last_error.as_deref(), Some("boom"));
assert!(after[0].1.next_attempt_at >= entry.next_attempt_at);
}
#[tokio::test]
async fn remove_clears_entry() {
let store = fjall_store().await;
let key = enqueue(&store, "did:example:a", "ty/1.0", json!({}))
.await
.unwrap();
remove(&store, key).await.unwrap();
let pending = list_pending_for_target(&store, "did:example:a")
.await
.unwrap();
assert!(pending.is_empty());
}
#[test]
fn backoff_grows_then_caps() {
assert_eq!(compute_backoff(0), 1);
assert_eq!(compute_backoff(1), 2);
assert_eq!(compute_backoff(4), 16);
assert_eq!(compute_backoff(9), 300); assert_eq!(compute_backoff(50), 300); }
#[test]
fn truncated_caps_long_errors() {
let long = "x".repeat(500);
let t = truncated(&long);
assert!(t.ends_with('…'));
assert_eq!(t.chars().count(), 201);
}
#[tokio::test]
async fn a_row_dropped_mid_delivery_is_not_resurrected() {
let store = fjall_store().await;
enqueue(
&store,
"did:example:edge",
"purge",
json!({"domain": "a.example"}),
)
.await
.unwrap();
let (key, entry) = list_pending_for_target(&store, "did:example:edge")
.await
.unwrap()
.remove(0);
let dropped = drop_queued(&store, "did:example:edge", "purge", |_| true)
.await
.unwrap();
assert_eq!(dropped, 1);
record_sent(&store, key.clone(), &entry, "urn:uuid:doc-1")
.await
.unwrap();
record_failure(&store, key, &entry, "boom").await.unwrap();
assert!(
list_pending_for_target(&store, "did:example:edge")
.await
.unwrap()
.is_empty(),
"the dropped purge stays dropped"
);
}
#[tokio::test]
async fn an_entry_is_settled_only_by_its_targets_ack_of_the_sent_document() {
let store = fjall_store().await;
enqueue(&store, "did:example:edge", "ty/1.0", json!({"k": 1}))
.await
.unwrap();
let (key, entry) = list_pending_for_target(&store, "did:example:edge")
.await
.unwrap()
.remove(0);
assert_eq!(head_action(&entry, now_epoch()), HeadAction::Send);
record_sent(&store, key, &entry, "urn:uuid:doc-1")
.await
.unwrap();
let (_, sent) = list_pending_for_target(&store, "did:example:edge")
.await
.unwrap()
.remove(0);
assert_eq!(sent.awaiting_ack.as_deref(), Some("urn:uuid:doc-1"));
assert_eq!(
head_action(&sent, now_epoch()),
HeadAction::Wait,
"a sent entry waits for its ack instead of being removed"
);
assert_eq!(
head_action(&sent, now_epoch() + ACK_TIMEOUT_SECS + 1),
HeadAction::Send,
"no ack in time → re-send"
);
assert!(
!acknowledge(&store, "did:example:other", "urn:uuid:doc-1")
.await
.unwrap()
);
assert!(
!acknowledge(&store, "did:example:edge", "urn:uuid:other")
.await
.unwrap()
);
assert_eq!(
list_pending_for_target(&store, "did:example:edge")
.await
.unwrap()
.len(),
1
);
assert!(
acknowledge(&store, "did:example:edge", "urn:uuid:doc-1")
.await
.unwrap()
);
assert!(
list_pending_for_target(&store, "did:example:edge")
.await
.unwrap()
.is_empty()
);
}
}