Checking for incoming emails on the serverThere are several reasons why an email message that is supposed to have arrived may not be in the user's mailbox. - The message has been blocked by an antispam before arriving on the BlueMind server. In that case, you must check your antispam solution's logs
The message is stuck in the BlueMind server's postfix queue. This typically happens when a user's usage quota is at full capacity. The email will be held in the postfix queue for 3 days. If after 3 days the server hasn't been able to deliver it, a non-delivery message will be sent to the sender. You can check whether the message is in the postfix queue using the command: Bloc de code |
---|
[root@bluemind ~]# postqueue -p
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
4E4D83AF8E 943 Thu Mar 2 07:10:58 full@bluemind.net
(host 192.168.124.72[192.168.124.72] said: 452 4.2.2 Over quota SESSIONID=<cyrus-4311-1488438658-1> (in reply to RCPT TO command))
full@bluemind.net |
To release the message, you can either ask the user to delete some emails or increase their quota, then wait for the message to be delivered or force postfix to try to deliver messages again using the postqueue command -f
If the email message is not stuck, you can find tracks of its arrival in the postfix logs (/var/log/maillog ou /var/log/mail.log): Bloc de code |
---|
Mar 1 20:45:32 bluemind postfix/ |
lmtp16928to=<user@bluemind.net>, relay=192.168.124.72[192.168.124.72]:2400, delay=0.32, delays=0.21/0.02/0.01/0.09, dsn=2.1.5, status=sent (250 2.1.5 Ok SESSIONID=<cyrus-12823-1488397532-1> [bluemind.net!user.user.INBOX () 2294])In this case, you can see that user2@domain.net is the sender of message AM5PR04MB3219A293B59D96973D338B01D2290 and it has been delivered to this user. message-id is the identifier for the message only and it is found in the email header. The number at the end of the lmtp line (2294 in this case) corresponds to the message's id in the user's INBOX folder, you can therefore find it in /var/spool/cyrus/data/b/bluemind_net/b/bluemind.net/u/user/user/2294 . Tracking email movements/deletionsThe operations performed on an email message can be tracked through the bm-ips IMAP proxy logs: /var/log/bm-ips/ips.log Identifying the sourceTo identify the client these operations originate from, look for the client(s) that log(s) into the account by searching for the user's username: Bloc de code |
---|
2019-05-16 12:49:24,715 [vert.x-eventloop-thread-0] n.b.i.i.d.c.l.AbstractLoginCP INFO - [jdoe@bluemind.loc] TBIRD, client: 123a4567-89a1-2345-bed6-789012b34eee, upstream: d123f456-78db-90f1-2f3f-45b66c7eb8c9, tag 283 in 33ms. |
→ in this case, the client is Thunderbird. In core.log, look for the connection at the time indicated: Bloc de code |
---|
2019-05-16 12:49:24,681 [BM-Core17] n.b.a.h.Nginx INFO - [172.16.231.22][imap][jdoe@bluemind.loc] will use cyrus backend 192.168.131.13 using login [pradola@cime.org], done in 21ms.
2019-05-16 12:49:24,704 [BM-Core5] n.b.a.s.Authentication INFO - l: 'jdoe@bluemind.loc', o: 'ips' successfully authentified |
→ The client is connected from the IP address 172.16.231.22 Email movementsYou can find this information by searching the user's login ID or the message ID Bloc de code |
---|
2017-04-28 06:27:46,844 [vert.x-worker-thread-9] n.b.i.m.n.i.ForwardToMQ INFO - [user2@bluemind.net] mails.copied '7120 "Trash"'
2017-04-28 06:27:46,845 [vert.x-worker-thread-9] n.b.i.m.i.MailboxIndexUpdater INFO - [user2@bluemind.net] onMailsCopied: '7120 "Trash"' => 'OK [COPYUID 1489045668 7120 20] Completed'
|
This log line shows that the message with id number C5BF3135FAF has indeed been delivered to the inbox of 'user@bluemind.net' on 1 March at 20:45 hrs. You can find more details about the message, including the sender's address by searching the message-id: Bloc de code |
---|
[root@bluemind ~]# grep C5BF3135FAF /var/log/maillog
Mar 1 20:45:32 bluemind postfix/smtpd[16923]: C5BF3135FAF: client=smtp.domain.net[192.168.120.30]
Mar 1 20:45:32 bluemind postfix/cleanup[16927]: C5BF3135FAF: message-id=<AM5PR04MB3219A293B59D96973D338B01D2290>
Mar 1 20:45:32 bluemind postfix/qmgr[364]: C5BF3135FAF: from=<user2@domain.net>, size=8386, nrcpt=1 (queue active)
Mar 1 20:45:32 bluemind postfix/lmtp[16928]: C5BF3135FAF: to=<user@bluemind.net>, relay=192.168.124.72[192.168.124.72]:2400, delay=0.32, delays=0.21/0.02/0.01/0.09, dsn=2.1.5, status=sent (250 2.1.5 Ok SESSIONID=<cyrus-12823-1488397532-1> [bluemind.net!user.user.INBOX () 2294])
Mar 1 20:45:32 bluemind postfix/qmgr[364]: C5BF3135FAF: removed |
In this case, you can see that user2@domain.net is the sender of message AM5PR04MB3219A293B59D96973D338B01D2290 and it has been delivered to this user. The message-id is the identifier for the message only and it is found in the email header. The number at the end of the lmtp line (2294 in this case) corresponds to the email id in the user's INBOX folder, you can therefore find it in /var/spool/cyrus/data/b/bluemind_net/b/bluemind.net/u/user/user/2294 . Following email movements/deletionsThe operations performed on an email message can be tracked through the bm-ips IMAP proxy logs: /var/log/bm-ips/ips.log Email movementsYou can find this information by searching the user's log in ID or the email ID Bloc de code | 844845 [vert.x-worker-thread-9] n.b.i.m |
.nForwardToMQMailboxIndexUpdater INFO - [user2@bluemind.net] copy |
mails.copied '"Trash"'to Trash/20
2017-04-28 06:27:46, |
845846 [vert.x-worker-thread-9] n.b.i.m.i. |
MailboxIndexUpdaterl.CopyMailRunnable INFO - [user2@bluemind.net] |
onMailsCopied: '7120 "Trash"' => 'OK [COPYUID 1489045668 7120 20] Completed'[mbox.uid user_entity_634] folder lookup: imap://user/scarpentier@bluemind.net/INBOX
2017-04-28 06:27:46, |
845856 [vert.x-worker-thread-9] n.b.i.m.i. |
MailboxIndexUpdateri.CopyMailRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_634] |
copyfrom INBOX/7120 to Trash/20lookup: imap://user/scarpentier@bluemind.net/Trash
2017-04-28 06:27:46, |
846871 [vert.x-worker-thread-9] n.b.i.m. |
i.l.CopyMailRunnable [user2@bluemind.net][mbox.uid user_entity_634] folder lookup: imap://user/scarpentier@bluemind.net/INBOX
source: 236030:7120, dest: 248259:20 |
In this example, you can see that the user user2@bluemind.net has moved the email 7120 from the INBOX folder to the Trash folder and the email message's ID number in the Trash folder now is 20. Email deletionsSimilarly, bm-ips logs allow you to see an email deletion: 062746856worker9miiCopyMailRunnableAbstractLoginCP INFO - [user2@bluemind.net] |
[mbox.uid user_entity_634] folder lookup: imap://user/scarpentier@bluemind.net/Trash ROUNDCUBE srv: 192.168.150.150, tag A0001 in 47ms.
2017-04-28 |
062746871273 [vert.x-worker-thread- |
9MailIndexServicei.MailboxIndexUpdater INFO - |
source: 236030:7120, dest: 248259:20In this example, you can see that the user user2@bluemind.net has moved the email 7120 from the INBOX folder to the Trash folder and the email message's ID number in the Trash folder now is 20. Email deletionsSimilarly, bm-ips logs allow you to see an email deletion: Bloc de code |
---|
[user2@bluemind.net] onFlagsChanged:
2017-04-28 07:51:15, |
257eventloop1d.c.l.AbstractLoginCPi.FlagsChangeRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_23] |
ROUNDCUBE srv: 192.168.150.150, tag A0001 in 47ms. folder lookup: imap://user/user2@bluemind.net/OTB
2017-04-28 07:51:15,284 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - change flags in imap://user/user2@bluemind.net/OTB 42:2818
2017-04-28 07:51:15, |
273284 [vert.x-worker-thread-7] n.b.i.m. |
i.MailboxIndexUpdater[user2@bluemind.net] onFlagsChanged: Bulk START on index mailspool_alias_user_entity_23
2017-04-28 07:51:15, |
277340 [vert.x-worker-thread-7] n.b.i.m |
.i.i.FlagsChangeRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_23] folder lookup: imap://user/user2@bluemind.net/OTB.MailIndexService INFO - Bulk END (1)
2017-04-28 07:51:15, |
284340 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - |
changeflags in imap://user/user2@bluemind.net/OTB 42:2818emails 1
2017-04-28 07:51:15, |
284340 [vert.x-worker-thread-7] n.b.i.m. |
MailIndexServicei.i.FlagsChangeRunnable INFO - |
BulkSTARTon index mailspool_alias_user_entity_23is 56ms.
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.i.i. |
MailIndexServiceFlagsChangeRunnable INFO - |
Bulk END (1) [user2@bluemind.net][OTB] Reindexing done in 67ms.
2017-04-28 07:51:15, |
340worker7mMailIndexServiceupdated emails 1[user2@bluemind.net] imap time: 9ms, total time: 83ms, overhead: 73ms.
2017-04-28 07:51:15, |
340354 [vert.x-worker-thread- |
7i.FlagsChangeRunnableMailboxIndexUpdater INFO - |
Update time is 56ms.[OTB] onMailsExpunged: '2818'
2017-04-28 07:51:15, |
340359 [vert.x-worker-thread- |
7FlagsChangeRunnableUidExpungeRunnable INFO - [user2@bluemind.net][ |
OTBReindexingdone in 67ms.lookup: imap://user/user2@bluemind.net/OTB
2017-04-28 07:51:15, |
347eventloop1vi.RemoteDataHandler [user2@bluemind.net] imap time: 9ms, total time: 83ms, overhead: 73ms. expunge: imap://user/user2@bluemind.net/OTB 2818
2017-04-28 07:51:15, |
354368 [vert.x-worker-thread-17] n.b.i.m. |
i.MailboxIndexUpdater [OTB] onMailsExpunged: '2818' Bulk START on index mailspool_alias_user_entity_23
2017-04-28 07:51:15, |
359376 [vert.x-worker-thread-17] n.b.i.m. |
i.i.UidExpungeRunnable[user2@bluemind.net][mbox.uid user_entity_23] folder lookup: imap://user/user2@bluemind.net/OTBBulk END (1)
2017-04-28 07:51:15, |
368376 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - expunge |
: imap://user/user2@bluemind.net/OTB (2818) : 1 deleted
2017-04-28 07:51:15, |
368376 [vert.x-worker-thread-17] n.b.i.m.i. |
MailIndexServicei.UidExpungeRunnable INFO - |
Bulk START on index mailspool_alias_user_entity_23
2017-04-28 07:51:15,376[user2@bluemind.net][OTB] Reindexing done in 22ms. |
In the case of multiple deletions, the message ID may not appear on its own but may be part of a range, in which case the logs will show: Bloc de code |
---|
2017-07-25 08:22:45,843 [vert.x-worker-thread- |
1710] n.b.i.m.MailIndexService INFO - change flags |
Bulk END (1)
2017-04-28 07:51:15,376 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - expunge imap://user/user2@bluemind.net/OTB (2818) : 1 deleted
2017-04-28 07:51:15,376 [vert.x-worker-thread-17] n.b.i.m.i.i.UidExpungeRunnable INFO - [user2@bluemind.net][OTB] Reindexing done in 22ms.In the case of multiple deletions, the email ID may not appear directly but may be part of a range, in which case the logs will show: Bloc de code | 2017-07-25 08:22:45,843 [vert.x-worker-thread-10] n.b.i.m.MailIndexService INFO - change flags in imap://user_entity_209667 29702:1in imap://user_entity_209667 29702:1:* |
RestaurationFrom version 3.5.11, delayed delete has been set up at the cyrus level. This means that emails are actually deleted from the server after seven days only. In the meantime, they are present on the disk but not visible in IMAP. This deletion mode is laying the groundwork for an upcoming double-bottom trash feature. To list a user's deleted emails, use this command: Bloc de code |
---|
unexpunge -l user/john@domain.net |
To restaure an email message: Bloc de code |
---|
unexpunge -u -d user/john@domain.net 46908 |
46908 being the message id. To restaure all a user's emails: Bloc de code |
---|
unexpunge -a -d user/john@domain.net |
For more information about these commands and how to pass them, please refer to the cyrus documentation: https://www.cyrusimap.org/imap/reference/manpages/systemcommands/unexpunge.html :* |