nats nak w/ shared retry_backoff, exhausted log; no 'will retry' lie
This commit is contained in:
@@ -5,7 +5,7 @@ use async_nats::{
|
|||||||
use async_trait::async_trait;
|
use async_trait::async_trait;
|
||||||
use domain::{
|
use domain::{
|
||||||
errors::DomainError,
|
errors::DomainError,
|
||||||
events::{AckHandle, DomainEvent, EventEnvelope, EventId},
|
events::{AckHandle, DomainEvent, EventEnvelope, EventId, retry_backoff},
|
||||||
ports::EventConsumer,
|
ports::EventConsumer,
|
||||||
};
|
};
|
||||||
use futures::{
|
use futures::{
|
||||||
@@ -21,6 +21,23 @@ use crate::{config::NatsConfig, payload::NatsEventMessage, subject::consumer_sub
|
|||||||
|
|
||||||
struct NatsJetStreamAckHandle {
|
struct NatsJetStreamAckHandle {
|
||||||
message: async_nats::jetstream::Message,
|
message: async_nats::jetstream::Message,
|
||||||
|
event_id: Option<EventId>,
|
||||||
|
max_deliver: i64,
|
||||||
|
}
|
||||||
|
|
||||||
|
/// How to nak a failed delivery: the same backoff schedule as the SQLite
|
||||||
|
/// queue, keyed by JetStream's delivery count (1 on first delivery).
|
||||||
|
struct NakPlan {
|
||||||
|
delay: std::time::Duration,
|
||||||
|
/// This was the last delivery `max_deliver` allows.
|
||||||
|
exhausted: bool,
|
||||||
|
}
|
||||||
|
|
||||||
|
fn nak_plan(delivered: i64, max_deliver: i64) -> NakPlan {
|
||||||
|
NakPlan {
|
||||||
|
delay: retry_backoff(u32::try_from(delivered.max(0)).unwrap_or(u32::MAX)),
|
||||||
|
exhausted: max_deliver > 0 && delivered >= max_deliver,
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
#[async_trait]
|
#[async_trait]
|
||||||
@@ -38,13 +55,29 @@ impl AckHandle for NatsJetStreamAckHandle {
|
|||||||
}
|
}
|
||||||
|
|
||||||
async fn nack(&self) -> Result<(), DomainError> {
|
async fn nack(&self) -> Result<(), DomainError> {
|
||||||
tracing::debug!(
|
let info = self
|
||||||
"negatively acknowledging message with sequence {}",
|
.message
|
||||||
self.message.info().unwrap().stream_sequence
|
.info()
|
||||||
|
.map_err(|e| DomainError::InfrastructureError(e.to_string()))?;
|
||||||
|
let plan = nak_plan(info.delivered, self.max_deliver);
|
||||||
|
if plan.exhausted {
|
||||||
|
tracing::error!(
|
||||||
|
event_id = ?self.event_id.map(|id| id.value()),
|
||||||
|
sequence = info.stream_sequence,
|
||||||
|
delivered = info.delivered,
|
||||||
|
"event exhausted max deliveries; it remains in the stream — see JetStream max-deliveries advisory"
|
||||||
);
|
);
|
||||||
|
} else {
|
||||||
|
tracing::debug!(
|
||||||
|
sequence = info.stream_sequence,
|
||||||
|
delivered = info.delivered,
|
||||||
|
"nak with backoff {:?}",
|
||||||
|
plan.delay
|
||||||
|
);
|
||||||
|
}
|
||||||
|
|
||||||
self.message
|
self.message
|
||||||
.ack_with(AckKind::Nak(None))
|
.ack_with(AckKind::Nak(Some(plan.delay)))
|
||||||
.await
|
.await
|
||||||
.map_err(|e| DomainError::InfrastructureError(e.to_string()))
|
.map_err(|e| DomainError::InfrastructureError(e.to_string()))
|
||||||
}
|
}
|
||||||
@@ -94,12 +127,19 @@ fn decode_message(bytes: &[u8]) -> Result<(Option<EventId>, DomainEvent), Domain
|
|||||||
Ok((id, DomainEvent::try_from(message.payload)?))
|
Ok((id, DomainEvent::try_from(message.payload)?))
|
||||||
}
|
}
|
||||||
|
|
||||||
fn decode_js(msg: async_nats::jetstream::Message) -> Result<EventEnvelope, DomainError> {
|
fn decode_js(
|
||||||
|
msg: async_nats::jetstream::Message,
|
||||||
|
max_deliver: i64,
|
||||||
|
) -> Result<EventEnvelope, DomainError> {
|
||||||
let (id, event) = decode_message(&msg.payload)?;
|
let (id, event) = decode_message(&msg.payload)?;
|
||||||
Ok(EventEnvelope::new(
|
Ok(EventEnvelope::new(
|
||||||
id,
|
id,
|
||||||
event,
|
event,
|
||||||
Box::new(NatsJetStreamAckHandle { message: msg }),
|
Box::new(NatsJetStreamAckHandle {
|
||||||
|
message: msg,
|
||||||
|
event_id: id,
|
||||||
|
max_deliver,
|
||||||
|
}),
|
||||||
))
|
))
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -227,6 +267,7 @@ impl NatsJetStreamConsumer {
|
|||||||
|
|
||||||
let (tx, rx) = mpsc::channel(128);
|
let (tx, rx) = mpsc::channel(128);
|
||||||
|
|
||||||
|
let max_deliver = cfg.max_deliver;
|
||||||
tokio::spawn(async move {
|
tokio::spawn(async move {
|
||||||
loop {
|
loop {
|
||||||
let mut messages = match consumer.messages().await {
|
let mut messages = match consumer.messages().await {
|
||||||
@@ -243,7 +284,7 @@ impl NatsJetStreamConsumer {
|
|||||||
while let Some(result) = messages.next().await {
|
while let Some(result) = messages.next().await {
|
||||||
let envelope = result
|
let envelope = result
|
||||||
.map_err(|e| DomainError::InfrastructureError(e.to_string()))
|
.map_err(|e| DomainError::InfrastructureError(e.to_string()))
|
||||||
.and_then(decode_js);
|
.and_then(|m| decode_js(m, max_deliver));
|
||||||
|
|
||||||
if tx.send(envelope).await.is_err() {
|
if tx.send(envelope).await.is_err() {
|
||||||
tracing::info!("consumer channel closed, stopping message processing");
|
tracing::info!("consumer channel closed, stopping message processing");
|
||||||
|
|||||||
@@ -91,3 +91,18 @@ fn consumer_max_deliver_drift_is_updated() {
|
|||||||
};
|
};
|
||||||
assert!(consumer_config_update(&same, 5).is_none());
|
assert!(consumer_config_update(&same, 5).is_none());
|
||||||
}
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn nak_delay_follows_the_shared_backoff_by_delivery_count() {
|
||||||
|
let secs = |d| nak_plan(d, 5).delay.as_secs();
|
||||||
|
assert_eq!((secs(1), secs(2), secs(3), secs(4)), (10, 20, 40, 80));
|
||||||
|
assert_eq!(nak_plan(50, 100).delay.as_secs(), 300);
|
||||||
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn only_the_final_delivery_is_exhausted() {
|
||||||
|
assert!(!nak_plan(4, 5).exhausted);
|
||||||
|
assert!(nak_plan(5, 5).exhausted);
|
||||||
|
assert!(nak_plan(6, 5).exhausted);
|
||||||
|
assert!(!nak_plan(1_000, -1).exhausted, "-1 means unlimited");
|
||||||
|
}
|
||||||
|
|||||||
@@ -119,7 +119,7 @@ async fn dispatch(
|
|||||||
}
|
}
|
||||||
Err(e) => {
|
Err(e) => {
|
||||||
// Running anyway could repeat a side effect; retry the delivery instead.
|
// Running anyway could repeat a side effect; retry the delivery instead.
|
||||||
tracing::warn!(handler = name, "ledger claim failed, will retry: {e}");
|
tracing::warn!(handler = name, "ledger claim failed, nacking delivery: {e}");
|
||||||
any_transient = true;
|
any_transient = true;
|
||||||
continue;
|
continue;
|
||||||
}
|
}
|
||||||
@@ -146,7 +146,10 @@ async fn dispatch(
|
|||||||
tracing::warn!(handler = name, "releasing ledger claim failed: {le}");
|
tracing::warn!(handler = name, "releasing ledger claim failed: {le}");
|
||||||
}
|
}
|
||||||
if e.is_transient() {
|
if e.is_transient() {
|
||||||
tracing::warn!(handler = name, "transient handler error, will retry: {e}");
|
tracing::warn!(
|
||||||
|
handler = name,
|
||||||
|
"transient handler error, nacking delivery (the backend logs if attempts are exhausted): {e}"
|
||||||
|
);
|
||||||
any_transient = true;
|
any_transient = true;
|
||||||
} else {
|
} else {
|
||||||
tracing::warn!(
|
tracing::warn!(
|
||||||
|
|||||||
@@ -155,6 +155,14 @@ pub trait AckHandle: Send + Sync {
|
|||||||
async fn defer(&self, delay: std::time::Duration) -> Result<(), DomainError>;
|
async fn defer(&self, delay: std::time::Duration) -> Result<(), DomainError>;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Wait before retrying an event whose `attempt`-th delivery just failed:
|
||||||
|
/// 5s doubling per attempt, capped at 5 minutes. Every backend (SQLite queue,
|
||||||
|
/// JetStream nak, outbox relay) uses this one schedule.
|
||||||
|
pub fn retry_backoff(attempt: u32) -> std::time::Duration {
|
||||||
|
let secs = 5u64 * (1u64 << attempt.min(6));
|
||||||
|
std::time::Duration::from_secs(secs.min(300))
|
||||||
|
}
|
||||||
|
|
||||||
/// Stable identity of one queued event; the key for de-duplicating deliveries.
|
/// Stable identity of one queued event; the key for de-duplicating deliveries.
|
||||||
#[derive(Clone, Copy, Debug, PartialEq, Eq, Hash)]
|
#[derive(Clone, Copy, Debug, PartialEq, Eq, Hash)]
|
||||||
pub struct EventId(uuid::Uuid);
|
pub struct EventId(uuid::Uuid);
|
||||||
|
|||||||
@@ -53,3 +53,13 @@ fn follow_requested_with_handle() {
|
|||||||
}
|
}
|
||||||
));
|
));
|
||||||
}
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn retry_backoff_doubles_from_ten_seconds_and_caps_at_five_minutes() {
|
||||||
|
use domain::events::retry_backoff;
|
||||||
|
use std::time::Duration;
|
||||||
|
let secs: Vec<u64> = (1..=8).map(|n| retry_backoff(n).as_secs()).collect();
|
||||||
|
assert_eq!(secs, [10, 20, 40, 80, 160, 300, 300, 300]);
|
||||||
|
assert_eq!(retry_backoff(0), Duration::from_secs(5));
|
||||||
|
assert_eq!(retry_backoff(u32::MAX), Duration::from_secs(300));
|
||||||
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user