jcoffey-dev
86bf2432a2
The server sets a deferred recipient's next retry from its clock when the attempt defers, in whole seconds. The test subtracted its own clock taken when the loop next saw the message, after saving and reporting, so whenever that lag crossed a second boundary the 2 s retry measured 1 s and the test failed. Under load, after the other SMTP tests, that was most runs. It now measures from when the test started the attempt, which the server's deferral can only follow, by under a second: each retry is its interval or one more. Each position is still checked against its own interval, so a wrong schedule still fails.
339 lines
12 KiB
Rust
339 lines
12 KiB
Rust
/*
|
|
* SPDX-FileCopyrightText: 2020 Stalwart Labs LLC <[email protected]>
|
|
*
|
|
* SPDX-License-Identifier: AGPL-3.0-only OR LicenseRef-SEL
|
|
*
|
|
* Modified by Coffey Labs in 2026 for INBUXA.
|
|
*/
|
|
|
|
use crate::{
|
|
smtp::{
|
|
inbound::{TestMessage, TestQueueEvent},
|
|
session::{TestSession, VerifyResponse},
|
|
},
|
|
utils::server::TestServerBuilder,
|
|
};
|
|
use ahash::{AHashMap, AHashSet};
|
|
use common::{
|
|
config::smtp::queue::QueueName,
|
|
ipc::{QueueEvent, QueueEventStatus},
|
|
};
|
|
use registry::{
|
|
schema::structs::{
|
|
Expression, ExpressionMatch, MtaDeliveryExpiration, MtaDeliveryExpirationTtl,
|
|
MtaDeliverySchedule, MtaDeliveryScheduleInterval, MtaDeliveryScheduleIntervals,
|
|
MtaDeliveryScheduleIntervalsOrDefault, MtaExtensions, MtaOutboundStrategy, MtaVirtualQueue,
|
|
},
|
|
types::list::List,
|
|
};
|
|
use smtp::queue::spool::{QUEUE_REFRESH, SmtpSpool};
|
|
use std::time::Duration;
|
|
use store::write::now;
|
|
|
|
#[tokio::test]
|
|
async fn queue_retry() {
|
|
let mut local = TestServerBuilder::new("smtp_queue_retry")
|
|
.await
|
|
.with_http_listener(19041)
|
|
.await
|
|
.disable_services()
|
|
.capture_queue()
|
|
.build()
|
|
.await;
|
|
|
|
let local_admin = local.account("admin");
|
|
local_admin.mta_allow_relaying().await;
|
|
local_admin.mta_allow_non_fqdn().await;
|
|
local_admin.mta_no_auth().await;
|
|
local_admin
|
|
.registry_create_object(MtaOutboundStrategy {
|
|
schedule: Expression {
|
|
match_: List::from_iter([ExpressionMatch {
|
|
if_: "sender_domain == 'test.org'".into(),
|
|
then: "'sender-test'".into(),
|
|
}]),
|
|
else_: "'sender-default'".into(),
|
|
},
|
|
..Default::default()
|
|
})
|
|
.await;
|
|
local_admin
|
|
.registry_create_object(MtaExtensions {
|
|
deliver_by: Expression {
|
|
else_: "1h".into(),
|
|
..Default::default()
|
|
},
|
|
future_release: Expression {
|
|
else_: "1h".into(),
|
|
..Default::default()
|
|
},
|
|
..Default::default()
|
|
})
|
|
.await;
|
|
let queue_id = local_admin
|
|
.registry_create_object(MtaVirtualQueue {
|
|
name: "default".into(),
|
|
threads_per_node: 25,
|
|
description: None,
|
|
})
|
|
.await;
|
|
local_admin
|
|
.registry_create_object(MtaDeliverySchedule {
|
|
name: "sender-default".into(),
|
|
retry: MtaDeliveryScheduleIntervalsOrDefault::Custom(MtaDeliveryScheduleIntervals {
|
|
intervals: List::from_iter([
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 1_000u64.into(),
|
|
},
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 2_000u64.into(),
|
|
},
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 3_000u64.into(),
|
|
},
|
|
]),
|
|
}),
|
|
notify: MtaDeliveryScheduleIntervalsOrDefault::Custom(MtaDeliveryScheduleIntervals {
|
|
intervals: List::from_iter([MtaDeliveryScheduleInterval {
|
|
duration: (15 * 60 * 60 * 1000u64).into(),
|
|
}]),
|
|
}),
|
|
expiry: MtaDeliveryExpiration::Ttl(MtaDeliveryExpirationTtl {
|
|
expire: 86_400_000u64.into(),
|
|
}),
|
|
queue_id,
|
|
description: None,
|
|
})
|
|
.await;
|
|
local_admin
|
|
.registry_create_object(MtaDeliverySchedule {
|
|
name: "sender-test".into(),
|
|
retry: MtaDeliveryScheduleIntervalsOrDefault::Custom(MtaDeliveryScheduleIntervals {
|
|
intervals: List::from_iter([
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 1_000u64.into(),
|
|
},
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 2_000u64.into(),
|
|
},
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 3_000u64.into(),
|
|
},
|
|
]),
|
|
}),
|
|
notify: MtaDeliveryScheduleIntervalsOrDefault::Custom(MtaDeliveryScheduleIntervals {
|
|
intervals: List::from_iter([
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 1_000u64.into(),
|
|
},
|
|
MtaDeliveryScheduleInterval {
|
|
duration: 2_000u64.into(),
|
|
},
|
|
]),
|
|
}),
|
|
expiry: MtaDeliveryExpiration::Ttl(MtaDeliveryExpirationTtl {
|
|
expire: 6_000u64.into(),
|
|
}),
|
|
queue_id,
|
|
description: None,
|
|
})
|
|
.await;
|
|
local_admin.reload_settings().await;
|
|
local.reload_core();
|
|
local.expect_reload_settings().await;
|
|
|
|
let mut session = local.new_mta_session();
|
|
session.data.remote_ip_str = "10.0.0.1".into();
|
|
session.eval_session_params().await;
|
|
session.ehlo("mx.test.org").await;
|
|
session
|
|
.send_message("[email protected]", &["[email protected]"], "test:no_dkim", "250")
|
|
.await;
|
|
let attempt = local.expect_message_for_queue_then_deliver("default").await;
|
|
|
|
// Expect a failed DSN
|
|
attempt.try_deliver(local.server.clone());
|
|
let message = local.expect_message().await;
|
|
assert_eq!(message.message.return_path.as_ref(), "");
|
|
assert_eq!(
|
|
message.message.recipients.first().unwrap().address(),
|
|
"[email protected]"
|
|
);
|
|
message
|
|
.read_lines(&local)
|
|
.await
|
|
.assert_contains("Content-Type: multipart/report")
|
|
.assert_contains("Final-Recipient: rfc822;[email protected]")
|
|
.assert_contains("Action: failed");
|
|
local.read_event().await.assert_done();
|
|
local.clear_queue().await;
|
|
|
|
// Expect a failed DSN for foobar.org, followed by two delayed DSN and
|
|
// a final failed DSN for _dns_error.org.
|
|
session
|
|
.send_message(
|
|
"[email protected]",
|
|
&["[email protected]", "jane@_dns_error.org"],
|
|
"test:no_dkim",
|
|
"250",
|
|
)
|
|
.await;
|
|
let mut in_fight = AHashSet::new();
|
|
let attempt = local.expect_message_for_queue_then_deliver("default").await;
|
|
let mut dsn = Vec::new();
|
|
let mut retries = Vec::new();
|
|
// inbuxa: when each attempt started, by test clock. The server sets the
|
|
// next retry from its clock when the attempt defers, which is at or after
|
|
// this and under a second later, so due - started is the interval or one
|
|
// more. Measuring from when the loop next sees the message instead made
|
|
// the result shrink by however long saving and reporting took, and it
|
|
// failed whenever that crossed a second boundary (under load, often).
|
|
let mut started = AHashMap::new();
|
|
in_fight.insert(attempt.queue_id);
|
|
started.insert(attempt.queue_id, now());
|
|
attempt.try_deliver(local.server.clone());
|
|
|
|
loop {
|
|
match local.try_read_event().await {
|
|
Some(QueueEvent::WorkerDone {
|
|
queue_id, status, ..
|
|
}) => {
|
|
in_fight.remove(&queue_id);
|
|
match &status {
|
|
QueueEventStatus::Completed | QueueEventStatus::Deferred => (),
|
|
_ => panic!("unexpected status {queue_id}: {status:?}"),
|
|
}
|
|
}
|
|
Some(QueueEvent::Refresh) | Some(QueueEvent::ReloadSettings) => (),
|
|
None | Some(QueueEvent::Stop) | Some(QueueEvent::Paused(_)) => break,
|
|
}
|
|
|
|
let now = now();
|
|
let mut events = local.all_queued_messages().await;
|
|
if events.messages.is_empty() {
|
|
if events.next_refresh < now + QUEUE_REFRESH {
|
|
tokio::time::sleep(Duration::from_secs(events.next_refresh - now)).await;
|
|
events = local.all_queued_messages().await;
|
|
} else if in_fight.is_empty() {
|
|
break;
|
|
}
|
|
}
|
|
|
|
for event in events.messages {
|
|
if in_fight.contains(&event.queue_id) {
|
|
continue;
|
|
}
|
|
|
|
let message = local
|
|
.server
|
|
.read_message(event.queue_id, QueueName::default())
|
|
.await
|
|
.unwrap();
|
|
if message.message.return_path.is_empty() {
|
|
message
|
|
.clone()
|
|
.remove(&local.server, event.due.into())
|
|
.await;
|
|
dsn.push(message);
|
|
} else {
|
|
retries.push(event.due.saturating_sub(started[&event.queue_id]));
|
|
in_fight.insert(event.queue_id);
|
|
started.insert(event.queue_id, store::write::now());
|
|
event.try_deliver(local.server.clone());
|
|
tokio::time::sleep(Duration::from_millis(100)).await;
|
|
}
|
|
}
|
|
}
|
|
local.assert_queue_is_empty().await;
|
|
assert_eq!(retries.len(), 3, "retries: {retries:?}");
|
|
for (retry, interval) in retries.iter().zip([1, 2, 3]) {
|
|
assert!(
|
|
(interval..=interval + 1).contains(retry),
|
|
"retry after {retry}s where the schedule says {interval}s: {retries:?}"
|
|
);
|
|
}
|
|
assert_eq!(dsn.len(), 4);
|
|
let mut dsn = dsn.into_iter();
|
|
|
|
dsn.next()
|
|
.unwrap()
|
|
.read_lines(&local)
|
|
.await
|
|
.assert_contains("<[email protected]> (failed to lookup 'foobar.org'")
|
|
.assert_contains("Final-Recipient: rfc822;[email protected]")
|
|
.assert_contains("Action: failed");
|
|
|
|
dsn.next()
|
|
.unwrap()
|
|
.read_lines(&local)
|
|
.await
|
|
.assert_contains("<jane@_dns_error.org> (failed to lookup '_dns_error.org'")
|
|
.assert_contains("Final-Recipient: rfc822;jane@_dns_error.org")
|
|
.assert_contains("Action: delayed");
|
|
|
|
dsn.next()
|
|
.unwrap()
|
|
.read_lines(&local)
|
|
.await
|
|
.assert_contains("<jane@_dns_error.org> (failed to lookup '_dns_error.org'")
|
|
.assert_contains("Final-Recipient: rfc822;jane@_dns_error.org")
|
|
.assert_contains("Action: delayed");
|
|
|
|
dsn.next()
|
|
.unwrap()
|
|
.read_lines(&local)
|
|
.await
|
|
.assert_contains("<jane@_dns_error.org> (failed to lookup '_dns_error.org'")
|
|
.assert_contains("Final-Recipient: rfc822;jane@_dns_error.org")
|
|
.assert_contains("Action: failed");
|
|
|
|
// Test FUTURERELEASE + DELIVERBY (RETURN)
|
|
session.data.remote_ip_str = "10.0.0.2".into();
|
|
session.eval_session_params().await;
|
|
session
|
|
.send_message(
|
|
"<[email protected]> HOLDFOR=60 BY=3600;R",
|
|
&["[email protected]"],
|
|
"test:no_dkim",
|
|
"250",
|
|
)
|
|
.await;
|
|
let now_ = now();
|
|
let message = local.expect_message().await;
|
|
assert!([59, 60].contains(&(local.message_due(message.queue_id).await - now_)));
|
|
assert!([59, 60].contains(&(message.message.next_delivery_event(None).unwrap() - now_)));
|
|
assert!(
|
|
[3599, 3600].contains(
|
|
&(message
|
|
.message
|
|
.recipients
|
|
.first()
|
|
.unwrap()
|
|
.expiration_time(message.message.created)
|
|
.unwrap()
|
|
- now_)
|
|
)
|
|
);
|
|
assert!(
|
|
[54059, 54060].contains(&(message.message.recipients.first().unwrap().notify.due - now_)),
|
|
"diff: {}",
|
|
message.message.recipients.first().unwrap().notify.due - now_
|
|
);
|
|
|
|
// Test DELIVERBY (NOTIFY)
|
|
session
|
|
.send_message(
|
|
"<[email protected]> BY=3600;N",
|
|
&["[email protected]"],
|
|
"test:no_dkim",
|
|
"250",
|
|
)
|
|
.await;
|
|
let schedule = local.expect_message().await;
|
|
assert!(
|
|
[3599, 3600].contains(&(schedule.message.recipients.first().unwrap().notify.due - now())),
|
|
"diff: {}",
|
|
schedule.message.recipients.first().unwrap().notify.due - now()
|
|
);
|
|
}
|