Is there a way to filter for long delivery times?

Your question

Under Dashboard → Delivery there is a graph showing delivery times which is annoying me from time to time as there are spikes up to 1-2hrs from time to time. Given my current set-up is still a low throughput server with only a few 100 emails a day, I don’t know whether these long delivery times are just artifacts of DMARC replies sitting in the queue or something directly affecting users.

Before I dive straight into the logs (either on disk or via victorialogs), is there a built-in way in the WebUI to see or dig out what causes these high delivery times, e.g. a query which would give me traceable ids which took longer than 30 minutes to deliver.

I understand that topics in this category are triaged by a bot first but a human reply will follow up. If I’d prefer a human-only reply, I’ll add the no-ai tag to my topic.

on

I have enough now. The Trace object supports filtering by text, timestamp, and queueId (not directly by duration), but the individual delivery.total-time and delivery.attempt-time metrics are captured per trace event as Duration key-values, so a person could inspect specific traces in the History view but there’s no built-in duration threshold filter documented in the JMAP query.

I have enough now to give a grounded answer.

There is no built-in “delivery time > 30 minutes” filter in the dashboard, but Stalwart does keep per-message delivery traces (Enterprise feature) that you can query directly, which is more precise than digging through raw logs.

  • Each delivery is stored as a Trace object (WebUI: Emails → History → Inbound/Outbound Delivery), which links the queue/message id to a full sequence of events (queueing, MX lookup, connection, DSN, etc.) with timestamps. It’s queryable via JMAP x:Trace/query, filterable by text (free text, e.g. an address or queue id), timestamp (date range), or queueId. It doesn’t currently expose a direct “duration greater than X” filter, but each trace’s events carry timestamps (including a delivery.total-time/delivery.attempt-time duration value in its key-value pairs), so you can pull traces for a time window and inspect/sort them by that duration client-side (via CLI/JMAP) rather than scrolling logs by hand.
  • Separately, delivery.total-time and delivery.attempt-time are recorded as histogram metrics, so you can at least confirm from Metrics whether the spikes are broad or occasional outliers, but metrics alone won’t give you the specific message/queue id.
  • Note that Trace objects are an Enterprise-only feature; on Community edition you’re limited to the Log object (queryable by free-text text filter only) and raw log/VictoriaLogs digging, since Log entries don’t carry a structured queryable duration field.

So: if you’re on Enterprise, query Trace objects for the time window in question and look at each trace’s events for the delivery duration key-value to identify the queue/message ids that took long. If you’re on Community, there isn’t a structured way in the WebUI to filter by delivery duration and you’ll need to grep logs (or VictoriaLogs) for delivery.completed / delivery.attempt-time events.

Reference: Management | Stalwart and Trace | Stalwart

This is an automated reply from the Stalwart Help Bot. Other community members may follow up if this answer is incomplete or wrong.

(up front, I have enough now sounds to my German brain like, I’m fed up :wink: )

I do see the “Duration” for each email under Emails → Inbound Delivery, e.g.

image

What I think would be great, if there was a way to get all durations for the past n hours/x hundred emails easily. At the moment, it seems I would need to click through each email.

If this were a property which would not be too costly to display en masse, what about a (selectable) extra column under /account/Management/x:Trace/InboundDelivery (and Outbound) would be great.

(also, making the columns sortable on click and change the pagination size would be great, but for that I have not looked if a similar issue/feature request already exists)

The graph is the time from a message entering the queue to its final completion, retries included, averaged over everything that passes through the queue: local delivery of inbound mail, outbound mail, DSNs and reports. At a few hundred messages a day, one greylisted or deferred message is enough to push a bucket to an hour or two. DMARC reports only count once they are queued for sending, so they only show up there when their own delivery gets deferred.

The Duration in Inbound Delivery is the length of that SMTP session, so a column of it wouldn’t find these. The value on the graph is the elapsed of the delivery.completed event, and each log line of that event also carries the queue id, queue name, sender and recipients. With file logs:

grep -h '(delivery.completed)' /path/to/logs/*.log | awk -F'elapsed = ' '$2+0 > 1800000'

In VictoriaLogs it’s roughly delivery.completed with elapsed above 1800000, since it’s in milliseconds (the field name depends on your ingest mapping). Filter Outbound Delivery by the queue id you find to see each failed attempt and its reason, and the queue name tells you whether it was a report. The delivery history can’t be sorted or filtered by duration, so a duration column, sorting and a page size setting would make a good feature request on GitHub.

thanks for the pointers.

For the proposed grep, I’ve added sed 's/\x1b\[[0-9;]*m//g' to get rid of the color escapes - still not sure whether I should keep those or not.

This month 721 messages clearing the threshold of 30 minutes, 645 dmarc, 41 DSN, some STS/RUA/TLS reports I would need to look up what these were for.

Only 4 messages which affected users remained but there a DNS problem around that time and I’m unsure whether upstream’s server stopped responding - using local unbound now - or whether this was caused by the recently fixed “hickory-resolver race”.

Anyway, I guess, low statistics it is! Thanks!