Projet

Général

Profil

Actions

Demande #3187

fermé

Demande #2979: Améliorer la déliverabilité de nos courriels

Mieux comprendre les erreurs emails

Ajouté par François Poulain il y a plus de 6 ans. Mis à jour il y a plus de 3 ans.

Statut:
Fermé
Priorité:
Normale
Assigné à:
Catégorie:
-
Version cible:
Début:
01/06/2018
Echéance:
% réalisé:

0%

Temps estimé:
Difficulté:
2 Facile

Description

Depuis toujours, même en considérant l'infra correcte, on a énormément de deferred. Il faut étudier pourquoi car ça peut être le symptome d'un soucis.


Demandes liées 1 (0 ouverte1 fermée)

Lié à Admins - Demande #3021: Traiter les erreurs 5xx sur les emails FerméFrançois Poulain14/03/2018

Actions

Mis à jour par François Poulain il y a plus de 6 ans

Cf #3021 pour les exemples.

Mis à jour par François Poulain il y a plus de 6 ans

  • Lié à Demande #3021: Traiter les erreurs 5xx sur les emails ajouté

Mis à jour par François Poulain il y a plus de 6 ans

  • Lié à Demande #3021: Traiter les erreurs 5xx sur les emails ajouté

Mis à jour par François Poulain il y a plus de 6 ans

  • Lié à Demande #3021: Traiter les erreurs 5xx sur les emails supprimé

Mis à jour par François Poulain il y a plus de 6 ans

  • Version cible changé de Backlog à Juin 2018

Mis à jour par Quentin Gibeaux il y a plus de 6 ans

  • Version cible changé de Juin 2018 à Été 2018

Mis à jour par Quentin Gibeaux il y a environ 6 ans

  • Version cible changé de Été 2018 à Septembre 2018

Mis à jour par Quentin Gibeaux il y a environ 6 ans

  • Version cible changé de Septembre 2018 à Octobre 2018

Mis à jour par Quentin Gibeaux il y a environ 6 ans

  • Version cible changé de Octobre 2018 à Novembre 2018

Mis à jour par Quentin Gibeaux il y a presque 6 ans

  • Version cible changé de Novembre 2018 à Backlog

Mis à jour par François Poulain il y a environ 5 ans

Un petit exemple d'analyse des deferred:

(April) root@mail:/var/log# zgrep -o 'status=deferred .* (in reply to RCPT TO command)' mail.log.3.gz | sed -e 's/[0-9]\+\.[0-9]\+\.[0-9]\+\.[0-9]\+/42.42.42.42/g' -e 's/\(OverQuotaTemp\|OverReceiveLimit\|ReceivingRate\) [^ ]* /\1 [ -- hashcode -- ] /g' | sort | uniq -c | sort -h
      1 status=deferred (host bouvarel.net[42.42.42.42] said: 450 4.7.1 <vip.april.org>: Helo command rejected: Host not found (in reply to RCPT TO command)
      1 status=deferred (host dice.gorgu.net[42.42.42.42] said: 450 4.7.1 <xavier.brouaux_gnu@m4am.net>: Recipient address rejected: Greylisting in action, please come back later (in reply to RCPT TO command)
      1 status=deferred (host frmug.org[42.42.42.42] said: 450 4.3.2 Service currently unavailable (in reply to RCPT TO command)
      1 status=deferred (host genovagrup.com[42.42.42.42] said: 451 Temporarily unable to process your email. Please try again later. (in reply to RCPT TO command)
      1 status=deferred (host ks.gibeaux.eu[42.42.42.42] said: 450 4.1.8 <admins-auto-owner@april.org>: Sender address rejected: Domain not found (in reply to RCPT TO command)
      1 status=deferred (host ks.gibeaux.eu[42.42.42.42] said: 450 4.1.8 <redmine@april.org>: Sender address rejected: Domain not found (in reply to RCPT TO command)
      1 status=deferred (host mail1.dalibo.net[42.42.42.42] said: 450 4.2.0 <laura.ricci@dalibo.com>: Recipient address rejected: Greylisted, see http://postgrey.schweikert.ch/help/dalibo.com.html (in reply to RCPT TO command)
      1 status=deferred (host mail.dhensa.com[42.42.42.42] said: 450 4.2.0 <gm@dhensa.com>: Recipient address rejected: Greylisted, see http://postgrey.schweikert.ch/help/dhensa.com.html (in reply to RCPT TO command)
      1 status=deferred (host mail.perfscript.fr[42.42.42.42] said: 450 4.7.1 Client host rejected: cannot find your reverse hostname, [42.42.42.42] (in reply to RCPT TO command)
      1 status=deferred (host mail.tedese.fr[42.42.42.42] said: 450 4.2.0 <justine.sauret@tedese.fr>: Recipient address rejected: Greylisted, see http://postgrey.schweikert.ch/help/tedese.fr.html (in reply to RCPT TO command)
      1 status=deferred (host mta6.am0.yahoodns.net[42.42.42.42] said: 450 User is receiving mail too quickly tnmpmscs (in reply to RCPT TO command)
      1 status=deferred (host mx1.antispammg.mg.gov.br[42.42.42.42] said: 450 4.3.2 Service currently unavailable (in reply to RCPT TO command)
      1 status=deferred (host mx1.comcast.net[42.42.42.42] said: 452 4.1.1 <gandg4me@comcast.net> too many recent messages; Try again later (in reply to RCPT TO command)
      1 status=deferred (host mx2.ac-montpellier.fr[42.42.42.42] said: 451 4.7.1 Greylisting in action, please come back later (in reply to RCPT TO command)
      1 status=deferred (host MX5.ARKEA.COM[42.42.42.42] said: 450 4.2.0 <conseiller-credit-agricole@cmb.fr>: Recipient address rejected: Greylisted by Arkea-GreyLister for 60 seconds (in reply to RCPT TO command)
      1 status=deferred (host MX6.ARKEA.COM[42.42.42.42] said: 450 4.2.0 <conseiller-credit-agricole@cmb.fr>: Recipient address rejected: Greylisted by Arkea-GreyLister for 60 seconds (in reply to RCPT TO command)
      1 status=deferred (host us2.mx2.mailhostbox.com[42.42.42.42] said: 454-4.7.1 <shweta@newsteadlab.com>: Relay access denied 454 4.7.1 Please see http://support.mailhostbox.com/email-administrators-guide-error-codes/ for explanation of the problem. (in reply to RCPT TO command)
      2 status=deferred (host alt1.gmail-smtp-in.l.google.com[42.42.42.42] said: 450-4.2.1 The user you are trying to contact is receiving mail too quickly. 450-4.2.1 Please resend your message at a later time. If the user is able to 450-4.2.1 receive mail at that time, your message will be delivered. For more 450-4.2.1 information, please visit 450 4.2.1  https://support.google.com/mail/?p=OverReceiveLimit [ -- hashcode -- ] - gsmtp (in reply to RCPT TO command)
      2 status=deferred (host cultureetliberte-moselle.com[42.42.42.42] said: 454 4.7.1 <contact@cultureetliberte-moselle.com>: Relay access denied (in reply to RCPT TO command)
      2 status=deferred (host mailfilter.webguru.nl[42.42.42.42] said: 454 4.7.1 <cedric.brancourt@simple-system.fr>: Relay access denied (in reply to RCPT TO command)
      2 status=deferred (host mx2.comcast.net[42.42.42.42] said: 452 4.1.1 <gandg4me@comcast.net> too many recent messages; Try again later (in reply to RCPT TO command)
      2 status=deferred (host mx.mailprotect.be[42.42.42.42] said: 450 4.7.1 <merijn.supply@vormingplus.be>: Recipient address rejected: Please try again in a few minutes - http://www.combell.com/en/about-combell/contact (in reply to RCPT TO command)
      2 status=deferred (host us2.mx1.mailhostbox.com[42.42.42.42] said: 454-4.7.1 <shweta@newsteadlab.com>: Relay access denied 454 4.7.1 Please see http://support.mailhostbox.com/email-administrators-guide-error-codes/ for explanation of the problem. (in reply to RCPT TO command)
      3 status=deferred (host funraill.org[42.42.42.42] said: 451 Temporary local problem - please try later (in reply to RCPT TO command)
      3 status=deferred (host mailfilter.webguru.nl[42.42.42.42] said: 454 4.7.1 <contact@simple-system.fr>: Relay access denied (in reply to RCPT TO command)
      3 status=deferred (host mxb.relay.renater.fr[42.42.42.42] said: 450 4.1.1 Not verified (in reply to RCPT TO command)
      8 status=deferred (host mx1.grenode.net[42.42.42.42] said: 450 4.2.0 <faquin@chaussette.sale>: Recipient address rejected: Greylisted, see http://postgrey.schweikert.ch/help/chaussette.sale.html (in reply to RCPT TO command)
     53 status=deferred (host mail-fr.securemail.pro[42.42.42.42] said: 452 4.1.1 <infos@kecetop.fr> 4.2.2 mailbox full (in reply to RCPT TO command)
     98 status=deferred (host acescore.org[42.42.42.42] said: 450 4.1.1 <noreply@acescore.org>: Recipient address rejected: unverified address: mail transport unavailable (in reply to RCPT TO command)
    151 status=deferred (host webarero.fr[42.42.42.42] said: 454 4.7.1 <francois.battail@webarero.fr>: Relay access denied (in reply to RCPT TO command)
   2247 status=deferred (host alt1.gmail-smtp-in.l.google.com[42.42.42.42] said: 450-4.2.1 The user you are trying to contact is receiving mail at a rate that 450-4.2.1 prevents additional messages from being delivered. Please resend your 450-4.2.1 message at a later time. If the user is able to receive mail at that 450-4.2.1 time, your message will be delivered. For more information, please 450-4.2.1 visit 450 4.2.1  https://support.google.com/mail/?p=ReceivingRate [ -- hashcode -- ] - gsmtp (in reply to RCPT TO command)
   2649 status=deferred (host alt1.gmail-smtp-in.l.google.com[42.42.42.42] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2  https://support.google.com/mail/?p=OverQuotaTemp [ -- hashcode -- ] - gsmtp (in reply to RCPT TO command)

=> Le gros gagnant c'est google. Il faut baisser le taux d'envoi.

Mis à jour par François Poulain il y a environ 5 ans

Google nous dit «
"Vous avez atteint la limite d'envoi d'e-mails"

Ce message risque de s'afficher si vous avez envoyé un même message à plus de 500 destinataires, ou si vous avez envoyé plus de 500 e-mails au cours d'une même journée.

Lorsque cette erreur se produit, vous devez normalement pouvoir recommencer à envoyer des messages dans un délai de 1 à 24 heures.

Pour éviter que cette erreur ne se reproduise, essayez de créer un groupe Google englobant tous les destinataires du message et de lui envoyer le message en question.
» https://support.google.com/mail/answer/22839?p=ReceivingRate

Mis à jour par François Poulain il y a environ 5 ans

Ceci étant si on fait un

zgrep '450-4.2.1 The user you are trying to contact is receiving mail' /var/log/mail.log.*.gz | grep -o ' to=<[^@]*@gmail.com>' | sort | uniq -c | sort -h

on a des adresses qui ressembles à des cibles de spam.

Mis à jour par François Poulain il y a environ 5 ans

Exemple

(April) root@mail:~# zgrep '450-4.2.1 The user you are trying to contact is receiving mail' /var/log/mail.log.3.gz | grep -o ' to=<[^@]*@gmail.com>' | sort | uniq -c | sort -h
      2  to=<xxxxxx.xxxxxx@gmail.com>
     48  to=<perryanderson93@gmail.com>
   2199  to=<lmattowen458@gmail.com>

Dans un cas précis qui nous occasion 2000 deferred, c'est sympa la source :

(April) root@sympa:~# zgrep -C3 sympa.1570650956.18561.118@april.org /var/log/sympa.log.18.gz 
Oct  9 21:54:45 sympa wwsympa[18560]: info main::do_arc(2013-12, msg00140.html) [robot april.org] [session 96967344747430] [client 172.16.0.1] [list educ]
Oct  9 21:55:56 sympa wwsympa[18561]: info main::do_subrequest(lmattowen458@gmail.com, ) [robot april.org] [session 68288801828590] [client 172.16.0.1] [list april-actu]
Oct  9 21:55:56 sympa wwsympa[18561]: info main::do_subrequest(lmattowen458@gmail.com, ) [robot april.org] [session 68288801828590] [client 172.16.0.1] [list april-actu]
Oct  9 21:55:56 sympa wwsympa[18561]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@april.org.1570650956.18561,2069/shelved:dkim_sign>; envelope_sender=sympa-request@april.org; message_id=sympa.1570650956.18561.118@april.org; recipients=lmattowen458@gmail.com; sender=sympa@april.org; template=sendpasswd; action=subrequest
Oct  9 21:55:56 sympa wwsympa[18561]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@april.org.1570650956.18561,2069/shelved:dkim_sign>; envelope_sender=sympa-request@april.org; message_id=sympa.1570650956.18561.118@april.org; recipients=lmattowen458@gmail.com; sender=sympa@april.org; template=sendpasswd; action=subrequest
Oct  9 21:55:56 sympa wwsympa[18561]: notice Sympa::Bulk::store() Message Sympa::Message::Template <sympa@april.org.1570650956.18561,2069/shelved:dkim_sign> is stored into bulk spool as <1.5.1570650956.1570650956.214996.sympa@april.org_s,18561,2123>
Oct  9 21:55:56 sympa wwsympa[18561]: notice Sympa::Bulk::store() Message Sympa::Message::Template <sympa@april.org.1570650956.18561,2069/shelved:dkim_sign> is stored into bulk spool as <1.5.1570650956.1570650956.214996.sympa@april.org_s,18561,2123>
Oct  9 21:55:56 sympa bulk[18557]: notice Sympa::Spindle::ProcessOutgoing::_twist() Start sending message Sympa::Message <1.5.1570650956.1570650956.214996.sympa@april.org_s,18561,2123/s/shelved:dkim_sign> to april.org (priority 1) (starting 0 seconds after scheduled expedition date)

Mis à jour par François Poulain il y a environ 5 ans

Et vu l'heure, c'est ça :

(April) root@sympa:~# zgrep '09/Oct/2019:21:55:' /var/log/nginx/listes.april.org.access_log 
172.16.0.1 - - [09/Oct/2019:21:55:56 +0200] "POST /wws/subscribe/april-actu HTTP/1.0" 200 16223 "https://april.org/" "Mozilla/5.0 (Windows NT 6.2; WOW64; rv:31.0) Gecko/20100101 Firefox/31.0" 

Mis à jour par François Poulain il y a environ 5 ans

On voit d'ailleurs qu'on a beaucoup d'amateurs qui souhaitent nous suivre :

(April) root@sympa:~# grep 'Oct/2019.*POST /wws/subscribe' /var/log/nginx/listes.april.org.access_log  | wc -l
1137

Mis à jour par François Poulain il y a environ 5 ans

Le release actuelle de sympa ne contient toujours pas de jeton ou autre mécanisme anti robot.

https://github.com/sympa-community/sympa/blob/sympa-6.2/default/web_tt2/subscribe.tt2

Mis à jour par François Poulain il y a environ 5 ans

Du code récent introduit les jetons (cf patches 2c0e8109c3 36fedef2e4 b30815ce91 ) mais seulement pour un nombre limité d'actions :

our %require_csrftoken = (
    'add'       => 1,
    'del'       => 1,
    'move_user' => 1,
    'savefile'  => 1,
    'setpasswd' => 1,
    'setpref'   => 1,
);

Mis à jour par François Poulain il y a environ 5 ans

Je vais ouvrir un bug upstream. Perso je ne vois pas bien quoi faire de plus.

Mis à jour par François Poulain il y a environ 5 ans

Sinon, sur un an on trouve ça :

(April) root@mail:/var/log# zgrep -h -o 'status=deferred .* (in reply to RCPT TO command)' mail.log.*.gz | sed -e 's/[0-9]\+\.[0-9]\+\.[0-9]\+\.[0-9]\+/42.42.42.42/g' -e 's/\(OverQuotaTemp\|OverReceiveLimit\|ReceivingRate\) [^ ]* /\1 [ -- hashcode -- ] /g' | sort | uniq -c | sort -h
[...]
   1013 status=deferred (host mx1.free.fr[42.42.42.42] said: 450 4.3.2 local delivery server failure (#2) (in reply to RCPT TO command)
   1035 status=deferred (host eforward2.registrar-servers.com[42.42.42.42] said: 451 relay not permitted! (in reply to RCPT TO command)
   1038 status=deferred (host eforward3.registrar-servers.com[42.42.42.42] said: 451 relay not permitted! (in reply to RCPT TO command)
   1151 status=deferred (host oasis-system.com[42.42.42.42] said: 450 4.1.1 <noreply@oasis-system.com>: Recipient address rejected: unverified address: mail transport unavailable (in reply to RCPT TO command)
   1162 status=deferred (host eforward1.registrar-servers.com[42.42.42.42] said: 451 relay not permitted! (in reply to RCPT TO command)
   1268 status=deferred (host mail.partifasli.com[42.42.42.42] said: 450 4.1.1 <noreply@partifasli.com>: Recipient address rejected: unverified address: mail transport unavailable (in reply to RCPT TO command)
   1381 status=deferred (host red.les-plans-voyages.fr[42.42.42.42] said: 454 4.7.1 <apache@red.les-plans-voyages.fr>: Relay access denied (in reply to RCPT TO command)
   1548 status=deferred (host mail-fr.securemail.pro[42.42.42.42] said: 452 4.1.1 <infos@kecetop.fr> 4.2.2 mailbox full (in reply to RCPT TO command)
   1858 status=deferred (host mailfilter.webguru.nl[42.42.42.42] said: 454 4.7.1 <contact@simple-system.fr>: Relay access denied (in reply to RCPT TO command)
   1860 status=deferred (host mx10.yulpa.io[42.42.42.42] said: 451 relay not permitted! (in reply to RCPT TO command)
   1868 status=deferred (host bertel-numerique.re[42.42.42.42] said: 454 4.7.1 <responsable@libre.re>: Relay access denied (in reply to RCPT TO command)
   1899 status=deferred (host mailfilter.webguru.nl[42.42.42.42] said: 454 4.7.1 <yyyyy.xxxxxxxx@simple-system.fr>: Relay access denied (in reply to RCPT TO command)
   1939 status=deferred (host mail.ben-ward.com[42.42.42.42] said: 450 4.1.1 <noreply@ben-ward.com>: Recipient address rejected: unverified address: mail transport unavailable (in reply to RCPT TO command)
   2456 status=deferred (host mx10.mailspamprotection.com[42.42.42.42] said: 451 relay not permitted! (in reply to RCPT TO command)
   3257 status=deferred (host backup.meetingpanel.com[42.42.42.42] said: 454 4.7.1 <april@adminsys.paris>: Relay access denied (in reply to RCPT TO command)
   3568 status=deferred (host alpariblog.com[42.42.42.42] said: 450 4.1.1 <noreply@alpariblog.com>: Recipient address rejected: unverified address: mail transport unavailable (in reply to RCPT TO command)
   3900 status=deferred (host mta6.am0.yahoodns.net[42.42.42.42] said: 450 4.2.2 User is receiving mail too quickly (in reply to RCPT TO command)
   3970 status=deferred (host mta5.am0.yahoodns.net[42.42.42.42] said: 450 4.2.2 User is receiving mail too quickly (in reply to RCPT TO command)
   4023 status=deferred (host mta7.am0.yahoodns.net[42.42.42.42] said: 450 4.2.2 User is receiving mail too quickly (in reply to RCPT TO command)
   4901 status=deferred (host webarero.fr[42.42.42.42] said: 454 4.7.1 <xxx.yyyyy@webarero.fr>: Relay access denied (in reply to RCPT TO command)
   5324 status=deferred (host mcdanielsco.com[42.42.42.42] said: 450 4.1.1 <noreply@mcdanielsco.com>: Recipient address rejected: unverified address: mail transport unavailable (in reply to RCPT TO command)
  18689 status=deferred (host mx-aol.mail.gm0.yahoodns.net[42.42.42.42] said: 450 4.2.2 User is receiving mail too quickly (in reply to RCPT TO command)
  39797 status=deferred (host mx.lautre.net[42.42.42.42] said: 454 4.7.1 <april@xxxxxx.lautre.net>: Relay access denied (in reply to RCPT TO command)
  82873 status=deferred (host alt1.gmail-smtp-in.l.google.com[42.42.42.42] said: 450-4.2.1 The user you are trying to contact is receiving mail at a rate that 450-4.2.1 prevents additional messages from being delivered. Please resend your 450-4.2.1 message at a later time. If the user is able to receive mail at that 450-4.2.1 time, your message will be delivered. For more information, please 450-4.2.1 visit 450 4.2.1  https://support.google.com/mail/?p=ReceivingRate [ -- hashcode -- ] - gsmtp (in reply to RCPT TO command)
 104799 status=deferred (host alt1.gmail-smtp-in.l.google.com[42.42.42.42] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2  https://support.google.com/mail/?p=OverQuotaTemp [ -- hashcode -- ] - gsmtp (in reply to RCPT TO command)

Une grosse partie vient de sympa, notamment from .

Mis à jour par Quentin Gibeaux il y a plus de 3 ans

@françois : l'issue est fermée, le bug est corrigé en prod ?

Mis à jour par François Poulain il y a plus de 3 ans

  • Statut changé de Nouveau à Fermé

Oui. C'est un peu un combat perpetuel mais je ne vois pas de raison de laisser ouvert. Le soucis sympa est certainement plus d'actu.

Actions

Formats disponibles : Atom PDF