Comparaison des versions

Légende

  • Ces lignes ont été ajoutées. Ce mot a été ajouté.
  • Ces lignes ont été supprimées. Ce mot a été supprimé.
  • La mise en forme a été modifiée.
Commentaire: Published by Scroll Versions from space DA and version BM-3.5
Sv translation
languagefr

Problèmes connus

Les emails n'arrivent pas sur une adresse existante

Symptômes : les emails ne sont pas délivrés à une adresse pourtant existante et l'expéditeur ne reçoit pas de message d'erreur

Cause : la modification de l'adresse de messagerie (suite à changement de login par exemple) n'a pas été correctement reportée par le système dans les maps postfix

Solution : il faut régénérer les maps Postfix en se rendant dans la console d'administration > Gestions du Système > Maintenance des mails > cliquer sur le bouton "Exécuter" :

Astuce

Il n'est pas nécessaire de redémarrer de service, les changements sont effectifs dès la fin de l'opération.

Si cela ne résout pas le problème, voir les chapitres ci-dessous pour une investigation plus poussée.

Volet

Sommaire

Vérifier qu'un email est bien arrivé sur le serveur

Il peut y avoir plusieurs raisons pour qu'un email supposé arrivé ne soit pas présent dans la boite d'un utilisateur.

  • L'email est bloqué par un antispam avant d'arriver sur le serveur BlueMind, dans ce cas il vous faut regarder dans les logs de votre solutions Antispam
  • L'email est bloqué dans la queue postifx du serveur BlueMind, cela arrive notamment quand un utilisateur a atteint 100% de son quota, l'email sera dans ce cas placé en attente dans postfix pendant 3 jours. Si au bout de 3 jours il n'a toujours pas réussi à délivrer l'email, un message de non-delivery sera envoyé à l'expéditeur. Vous pouvez voir si l'email est présent dans la queue postfix avec la commande :

    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

    Pour débloquer le message, il faut demander à l'utilisateur de supprimer des emails ou augmenter son quota puis attendre que le message soit délivré ou forcer postfix à réessayer de délivrer les emails avec la commande postqueue -f

Si l'email n'est pas bloqué alors vous pouvez trouver les traces de son arrivée dans les logs de postfix (/var/log/maillog ou /var/log/mail.log) :

Bloc de code
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])

Cette ligne de log montre que l'email identifié par l'id C5BF3135FAF a bien été remis dans la boite de réception de l'utilisateur 'user@bluemind.net' le 1 mars à 20:45.

Vous pouvez trouver plus d'information sur l'email, notamment l'adresse de l'expéditeur, en recherchant l'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

On peut voir ici que c'est user2@domain.net qui est l'expéditeur de l'email AM5PR04MB3219A293B59D96973D338B01D2290 et qu'il a bien été délivré à notre utilisateur.

Le message-id est l'identifiant unique du message, celui-ci se trouve dans les en-têtes de l'email

Le dernier nombre de la ligne lmtp (ici 2294) correspond à l'id de l'email dans le dossier INBOX de l'utilisateur, vous pouvez donc trouver l'email dans /var/spool/cyrus/data/b/bluemind_net/b/bluemind.net/u/user/user/2294.

Suivre les déplacements/suppression d'un email

Les opérations effectuées sur un email peuvent être retracées via les logs du proxy IMAP bm-ips : /var/log/bm-ips/ips.log

Identifier l'origine

Pour identifier le client à l'origine des actions, chercher le ou les clients qui se connectent au compte en recherchant le login de l'utilisateur :

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.

→ il s'agit ici du client Thunderbird

Dans le core.log, on cherche alors la connexion à l'heure indiquée :

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

→ Le client s'est connecté depuis l'adresse IP 172.16.231.22

Déplacement d'un mail

Il est possible de retrouver ces informations en recherchant le login de l'utilisateur ou l'id de l'email

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'
2017-04-28 06:27:46,845 [vert.x-worker-thread-9] n.b.i.m.i.MailboxIndexUpdater INFO - [user2@bluemind.net] copy from INBOX/7120 to Trash/20
2017-04-28 06:27:46,846 [vert.x-worker-thread-9] n.b.i.m.i.l.CopyMailRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_634] folder lookup: imap://user/scarpentier@bluemind.net/INBOX
2017-04-28 06:27:46,856 [vert.x-worker-thread-9] n.b.i.m.i.i.CopyMailRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_634] folder lookup: imap://user/scarpentier@bluemind.net/Trash
2017-04-28 06:27:46,871 [vert.x-worker-thread-9] n.b.i.m.MailIndexService INFO - source: 236030:7120, dest: 248259:20

On voit ici que l'utilisateur user2@bluemind.net a déplacé l'email 7120 du dossier INBOX vers le dossier Trash et l'email dans le dossier Trash porte maintenant l'id 20

Suppression d'un email

De la même manière, les logs de bm-ips permettent de voir la suppression d'un email :

Bloc de code
2017-04-28 07:51:15,257 [vert.x-eventloop-thread-1] n.b.i.i.d.c.l.AbstractLoginCP INFO - [user2@bluemind.net] ROUNDCUBE srv: 192.168.150.150, tag A0001 in 47ms.
2017-04-28 07:51:15,273 [vert.x-worker-thread-7] n.b.i.m.i.MailboxIndexUpdater INFO - [user2@bluemind.net] onFlagsChanged: 
2017-04-28 07:51:15,277 [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
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,284 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - Bulk START on index mailspool_alias_user_entity_23
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - Bulk END (1)
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - updated emails 1
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.i.i.FlagsChangeRunnable INFO - Update time is 56ms.
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.i.i.FlagsChangeRunnable INFO - [user2@bluemind.net][OTB] Reindexing done in 67ms.
2017-04-28 07:51:15,347 [vert.x-eventloop-thread-1] n.b.i.v.i.RemoteDataHandler INFO - [user2@bluemind.net] imap time: 9ms, total time: 83ms, overhead: 73ms.
2017-04-28 07:51:15,354 [vert.x-worker-thread-17] n.b.i.m.i.MailboxIndexUpdater INFO - [OTB] onMailsExpunged: '2818'
2017-04-28 07:51:15,359 [vert.x-worker-thread-17] n.b.i.m.i.i.UidExpungeRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_23] folder lookup: imap://user/user2@bluemind.net/OTB
2017-04-28 07:51:15,368 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - expunge: imap://user/user2@bluemind.net/OTB 2818
2017-04-28 07:51:15,368 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - Bulk START on index mailspool_alias_user_entity_23
2017-04-28 07:51:15,376 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - 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.

Dans le cas d'une suppression multiple il est possible que l'id du mail n'apparaissent pas directement mais qu'il soit inclue dans un range, dans ce cas les logs montreront :

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:1:*

Il est possible de voir les suppressions de dossiers IMAP avec le log suivant dans le mail.log (ou maillog en fonction de l'OS) :

Bloc de code
Apr 16 11:58:38 staging35 cyrus/imap[12116]: Deleted mailbox blue-mind.net!user.john^doe.test.big.big.big2
Remarque

A noter que les heures diffèrent suivant les fichiers de logs, le maillog utilise l'heure système alors que les logs BM sont en UTC

Restauration

À partir de la version 3.5.11 la suppression en mode delayed a été mise en place au niveau de cyrus. Cela signifie que les mails ne sont réellement supprimés du serveur qu'au bout de 7 jours. Pendant ce laps de temps ils sont présents sur le disque mais non visible en IMAP.
Ce mode de suppression prépare la future fonctionnalité de corbeille à double fond.

Pour lister les mails supprimés d'un utilisateur ou d'une boite partagée il faut utiliser la commande :

Bloc de code
unexpunge -l user/john@domain.net
unexpunge -l mailshare@domain.net

Pour restaurer un mail :

Bloc de code
unexpunge -u -d user/john@domain.net 46908
unexpunge -u -d mailshare@domain.net 678

où 46908 est l'id du message pour l'utilisateur, 678 est l'id du message pour la boite partagée.

Pour restaurer tous les emails de l'utilisateur ou de la boite partagée :

Bloc de code
unexpunge -a -d user/john@domain.net
unexpunge -a -d mailshare@domain.net

Pour plus d'informations sur ces commandes et la façon de les passer, veuillez consulter la documentation cyrus : https://www.cyrusimap.org/imap/reference/manpages/systemcommands/unexpunge.html

Sv translation
languageen

Known issues

Emails are not delivered to an existing address

Symptoms: emails are not delivered to an existing address and the sender does not receive any error messages

Cause: a change in the email address (e.g. after a username has been changed) has not been correctly reported by the system in the postfix maps

Solution: you need to regenerate the Postfix maps by going to the admin console > System Management > Manage messaging system > click "Execute":

Astuce

There is no need to restart the service, changes are effective immediately.

If this doesn't solve the problem, see the paragraphs below for further investigations.

Volet

Sommaire

Checking for incoming emails on the server

There are several reasons why an email message may not make it to a 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 full. 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 and deliver messages again using the postqueue command -f

If the email message is not stuck, you can find traces 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/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])

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.

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/deletions

The operations performed on an email message can be tracked through the bm-ips IMAP proxy logs: /var/log/bm-ips/ips.log

Identifying the source

To 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 movements

You 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'
2017-04-28 06:27:46,845 [vert.x-worker-thread-9] n.b.i.m.i.MailboxIndexUpdater INFO - [user2@bluemind.net] copy from INBOX/7120 to Trash/20
2017-04-28 06:27:46,846 [vert.x-worker-thread-9] n.b.i.m.i.l.CopyMailRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_634] folder lookup: imap://user/scarpentier@bluemind.net/INBOX
2017-04-28 06:27:46,856 [vert.x-worker-thread-9] n.b.i.m.i.i.CopyMailRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_634] folder lookup: imap://user/scarpentier@bluemind.net/Trash
2017-04-28 06:27:46,871 [vert.x-worker-thread-9] n.b.i.m.MailIndexService INFO - 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 deletions

Similarly, bm-ips logs allow you to see an email deletion:

Bloc de code
2017-04-28 07:51:15,257 [vert.x-eventloop-thread-1] n.b.i.i.d.c.l.AbstractLoginCP INFO - [user2@bluemind.net] ROUNDCUBE srv: 192.168.150.150, tag A0001 in 47ms.
2017-04-28 07:51:15,273 [vert.x-worker-thread-7] n.b.i.m.i.MailboxIndexUpdater INFO - [user2@bluemind.net] onFlagsChanged: 
2017-04-28 07:51:15,277 [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
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,284 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - Bulk START on index mailspool_alias_user_entity_23
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - Bulk END (1)
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.MailIndexService INFO - updated emails 1
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.i.i.FlagsChangeRunnable INFO - Update time is 56ms.
2017-04-28 07:51:15,340 [vert.x-worker-thread-7] n.b.i.m.i.i.FlagsChangeRunnable INFO - [user2@bluemind.net][OTB] Reindexing done in 67ms.
2017-04-28 07:51:15,347 [vert.x-eventloop-thread-1] n.b.i.v.i.RemoteDataHandler INFO - [user2@bluemind.net] imap time: 9ms, total time: 83ms, overhead: 73ms.
2017-04-28 07:51:15,354 [vert.x-worker-thread-17] n.b.i.m.i.MailboxIndexUpdater INFO - [OTB] onMailsExpunged: '2818'
2017-04-28 07:51:15,359 [vert.x-worker-thread-17] n.b.i.m.i.i.UidExpungeRunnable INFO - [user2@bluemind.net][mbox.uid user_entity_23] folder lookup: imap://user/user2@bluemind.net/OTB
2017-04-28 07:51:15,368 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - expunge: imap://user/user2@bluemind.net/OTB 2818
2017-04-28 07:51:15,368 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - Bulk START on index mailspool_alias_user_entity_23
2017-04-28 07:51:15,376 [vert.x-worker-thread-17] n.b.i.m.MailIndexService INFO - 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 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-10] n.b.i.m.MailIndexService INFO - change flags in imap://user_entity_209667 29702:1:*

Restoration

From 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 restore an email message:

Bloc de code
unexpunge -u -d user/john@domain.net 46908

46908 being the message id.

To restore 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