Score:1

How to trace/find "lost" emails with log files and doveadm?

in flag
Sam

One of my clients is missing some emails and I try to find what is going on, but my knowledge is limited. Have asked the server support guys, but they say all is fine and attach just the logs (which I can't read well > ♻️ )

What have I done?.

root@myserver:~# zgrep [email protected] /var/log/mail.log.2.gz

There I see mails, and they get a queue and message ID attached:

Queue-ID: 2125915E4BB, Message-ID: <[email protected]>

Log

root@myserver:~# cat /var/log/mail.* |egrep '4525915E4AA|6B02315A8FE|E511515E3FF' |sort
Nov  2 09:48:40 myserver postfix/cleanup[8085]: 4525915E4AA: message-id=<[email protected]>
Nov  2 09:48:40 myserver postfix/qmgr[9669]: 4525915E4AA: from=<[email protected]>, size=297312, nrcpt=1 (queue active)
Nov  2 09:48:40 myserver postfix/submission/smtpd[8275]: 4525915E4AA: client=myserver.host.com[123.123.123.1], sasl_method=LOGIN, [email protected]
Nov  2 09:48:44 myserver amavis[4102]: (04102-12) Passed CLEAN {RelayedInbound}, [123.123.123.1]:59776 [123.123.123.1] <[email protected]> -> <[email protected]>, Queue-ID: 4525915E4AA, Message-ID: <[email protected]>, mail_id: NfX3Lgs8fYbm, Hits: -1.945, size: 297832, queued_as: A3CC315E4B5, 4282 ms
Nov  2 09:48:44 myserver postfix/qmgr[9669]: 4525915E4AA: removed
Nov  2 09:48:44 myserver postfix/smtp[8276]: 4525915E4AA: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, delay=4.5, delays=0.15/0.02/0/4.3, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as A3CC315E4B5)

# A3CC315E4B5
Nov  2 09:48:44 myserver postfix/smtpd[8094]: A3CC315E4B5: client=localhost.localdomain[127.0.0.1]
Nov  2 09:48:44 myserver postfix/cleanup[8085]: A3CC315E4B5: message-id=<[email protected]>
Nov  2 09:48:44 myserver postfix/qmgr[9669]: A3CC315E4B5: from=<[email protected]>, size=298519, nrcpt=1 (queue active)
Nov  2 09:48:44 myserver amavis[4102]: (04102-12) Passed CLEAN {RelayedInbound}, [123.123.123.1]:59776 [123.123.123.1] <[email protected]> -> <[email protected]>, Queue-ID: 4525915E4AA, Message-ID: <[email protected]>, mail_id: NfX3Lgs8fYbm, Hits: -1.945, size: 297832, queued_as: A3CC315E4B5, 4282 ms
Nov  2 09:48:44 myserver postfix/smtp[8276]: 4525915E4AA: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, delay=4.5, delays=0.15/0.02/0/4.3, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as A3CC315E4B5)
Nov  2 09:48:44 myserver postfix/lmtp[8095]: A3CC315E4B5: to=<[email protected]>, relay=myserver.host.com[private/dovecot-lmtp], delay=0.13, delays=0.06/0/0.01/0.06, dsn=2.0.0, status=sent (250 2.0.0 <[email protected]> uLYULOwuYmNdIAAAPVEKtg Saved)
Nov  2 09:48:44 myserver postfix/qmgr[9669]: A3CC315E4B5: removed

How can I trace where the email has gone? Would it be possible to search for the email with doveadm? Or can I see, in the logs, if the email has been deleted by the user knowingly or unknowingly?

Where can I find more to know how to read those logs and what is going on? I know mail servers are complicated, but I wouldn't like to just tell my client “everything is fine” it is unclear to me why your emails are lost. Isn't much trustworthy, is it?

anx avatar
fr flag
anx
Try to get a more specific description of what the person is missing. There may be a misunderstanding between a) messages never received or b) messages received and then deleted or c) messages stored, just not easy to bring up using an unfamiliar, non-standard and/or deficient search feature.
Sam avatar
in flag
Sam
Yeah, did so, but still waiting for the feedback. Just wanted to have a look what I could find meanwhile.
Score:2
fr flag
anx

Users may sometimes complain that they have lost emails. The problem is almost always that this was done by one of the user’s email clients accidentally. Especially accidentally configuring a “POP3 client” to a new device that deletes the mails after downloading them. -- Dovecot manual: Mail Debugging

There is a chance that you are not logging individual IMAP actions, so might not be able to track which user has removed a message. If you however learn that the missing messages are all older than X days and one user with access has recently setup a mail client with a feature to discard old messages, that would quickly pinpoint a suspect.

How can I trace where the email has gone?

You did, you just have to continue as there are at least four different identifiers.

  1. You got [email protected] indicated in the Message-ID header, that is what the sending software attached.
  2. Postfix first receives this, tracks it as 4525915E4AA.
  3. Postfix hands it for Amavis, which is fine with forwarding it, and hands it back to Postfix. Now Postfix tracks it as A3CC315E4B5.
  4. Postfix must have determined the recipient is local, so it handed it to Dovecot, the IMAP server. Dovecot reported back that it received it fully, is accepting responsibility for not losing it, and will be tracking that message as uLYULOwuYmNdIAAAPVEKtg.

Up until the part that you quoted, the message was not lost - yet. Keep tracking the chain until you reach the end of reported transmissions. Dovecot may or may not have tried to store the message, and may or may not have lost or intentionally deleted on user request later on.

I suspect if you search your logs for the identifier 4, you will find a log entry where Dovecot reports what user and mailbox (namespace/subfolder) the message was stored in, plus another quote of the message-id header.

Would it be possible to search for the email with doveadm?

If Dovecot still has your message, it will be able to locate it. Might want to limit your search to reasonable subsets if the mailboxes are more than a few hundred gigabytes, specifics are detailed in the doveadm search and doveadm search-query manual. Example:

doveadm fetch -u [email protected] 'hdr.date mailbox' HEADER Message-ID '[email protected]'
# if that is appropriate and properly setup, you might even search all users:
doveadm fetch -A 'hdr.date mailbox' HEADER Message-ID '[email protected]'

If the message was delivered, then lost, the type of mail storage and the users with permissions might be relevant in further inquiry. For potential follow-up questions about ways a mailbox might have gotten corrupted or inaccessible, be sure to include relevant configuration, such as dumped by the doveconf -n command.

Sam avatar
in flag
Sam
Thank you very much! This helps a lot. I have searched in the mail.log for uLYULOwuYmNdIAAAPVEKtg and found Nov 2 09:48:44 myserver dovecot: lmtp([email protected]): uLYULOwuYmNdIAAAPVEKtg: sieve: msgid=<[email protected]>: marked message to be discarded if not explicitly delivered (discard action) So, looks like it was a victim to one of the spam rules, isn't it? doveadm wasn't able to find anything.
anx avatar
fr flag
anx
`sieve` refers to the filtering rules (may be setup by the admin, the user via ManageSieve, or both in conjunction). Search your Dovecot configuration for that term, that will tell you at what path you can review the rule files. Yes, very likely it just unconditionally trusted some note that Amavis left in the message headers. Bad idea, moving them to a folder that is setup to be automatically clear messages *after some safety delay* is much nicer for the unavoidable mistakes in the by nature imperfect spam rules.
Sam avatar
in flag
Sam
Indeed, have change discard to fileinto a Junk folder. Thanks again for your help!
I sit in a Tesla and translated this thread with Ai:

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.