Re: [sympa-fr] Problème de distribution

[Guillaume Laurès <adresse@cachée>]

Hello,

On était peut-être pas sur la bonne piste. Il y a du nouveau, et un élément que je n'ai pas mentionné plus tôt, car je le croyais extérieur, mais il a peut-être eu un impact.

De nouveau : une autre liste quasi identique et avec les même abonnés de départ (il y en a en tout 11 très similaires) ne semble pas présenter le même comportement : les abonnés oubliés hier (et qui se sont manifestés) ont bien reçu le message cette fois-ci.

Par contre mon comptage côté zimbra semble vraiment à côté de la plaque : dans ce cas je compte 2331 traces (au lieu de 4260 précédemment) sur 7725 attendus !...

Sep 23 12:08:28 localhost sympa[9290]: notice List::send_msg() No VERP subscribers left to distribute message from adresse@cachée to list diffusion2
Sep 23 12:08:28 localhost sympa[9290]: info Commands::distribute() Message for diffusion2 from adresse@cachée accepted (5 seconds, 309 sessions, 7724 subscribers), message-id=<adresse@cachée>#012, size=0

De pas mentionné plus tôt : le paramétrage de MySQL était initialement laissé par défaut et ne laissait pas sympa stocker de gros messages :

Sep 22 11:36:17 localhost sympa[9290]: err Bulk::store() Unable to add message in bulkspool_table "INSERT INTO bulkspool_table (messagekey_bulkspool, messageid_bulkspool, message_bulkspool, lock_bulkspool, dkim_d_bulkspool, dkim_i_bulkspool, dkim_selector_bulkspool, dkim_privatekey_bulkspool) VALUES ('0677eda1a90a2cc3dfb239ba89ecfbeb', '<adresse@cachée>', 'TWVzc2FnZS1JZDogPHN5bXBhLjE0MTEzNzg1NzcuOTI5MC42MzRAbGlzdGVzLmNnOTMuZnI+CkRh\ndGU6IE1vbiwgMjIgU2VwIDI', 1, NULL, NULL, NULL, '')"; error :
Sep 22 11:36:17 localhost sympa[9290]: err mail::sending() Failed to store message for list diffusion

En effet le message faisait 3Mo et :

/home/sympa/bin/sympa.pl --test_database_message_buffer -> maximun message size that can be stored in database : 420 Ko

Donc j'ai passé le diff suivant sur /etc/my.cnf
--- /etc/my.cnf.orig 2014-09-04 07:24:05.960993299 +0200
+++ /etc/my.cnf 2014-09-04 07:25:52.062297061 +0200
@@ -4,6 +4,7 @@
user=mysql
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0
+max_allowed_packet=20M

[mysqld_safe]
log-error=/var/log/mysqld.log

+ service mysqld restart

Après coup c'était mieux :

/home/sympa/bin/sympa.pl --test_database_message_buffer -> maximun message size that can be stored in database : 14700 Ko

Sachant que le MTA Zimbra est paramétré à 13Mo et Sympa aussi.

Suite à ça le message a été renvoyé à la liste vers 16H45, puis re-modéré, une deuxième fois donc. C'est à propos de ce deuxième envoi que j'investiguais ce matin. Est-ce que le premier échec a pu laisser des traces et parasiter la deuxième tentative d'envoi ? Pour moi le premier envoi devait échouer à 100% et le deuxième réussir à 100%, non ?

Je vais essayer de trouver une meilleure astuce pour compter les emails sortis de sympa dans les deux cas.

Merci,

G. Laurès

---

De: "Guillaume Laurès" <adresse@cachée>
À: adresse@cachée, "David Verdin" <adresse@cachée>
Envoyé: Mardi 23 Septembre 2014 12:09:54
Objet: Re: [sympa-fr] Problème de distribution

Bonjour David et merci de ton retour rapide !

Cf. ci-dessous

---

De: "David Verdin" <adresse@cachée>
À: adresse@cachée
Envoyé: Mardi 23 Septembre 2014 11:40:27
Objet: Re: [sympa-fr] Problème de distribution

Bonjour Guillaume,

Le 23/09/14 11:20, Guillaume Laurès a écrit :

adresse@cachée">

Bonjour, 

J'ai besoin d'aide pour diagnostiquer un problème de distribution.

Le symptôme : certains abonnés n'ont pas reçu le mail.

Sûr ? C'est pas parti dans un folder spam ou autre ? C'est pas du grey-listing, un serveur SMTP momentanément innacessible ou autre bizarrerie du genre ?

Le dossier SPAM est carrément désactivé pour tous les utilisateurs. Pas de grey-listing ou autres actif à ma connaissance.

adresse@cachée">

L'installation : sympa 6.1.22 sur RH6 avec MTA postfix, qui relaie vers un MTA Zimbra 7

Tous les abonnés sont membre du cluster Zimbra. Antispam désactivé (mais pas l'anti-virus).

Les abonnés en question sont bien abonnés, exemple : 
Email 	Domaine 	Avatar 	Nom 	Réception 	Sources 	Abonné depuis 	Mise à jour
adresse@cachée 		  	réception au format HTML uniquement 	subscribed 	15 sept. 2014 	15 sept. 2014 
Le quota de la boite n'est pas atteint.

Ça répond en partie à mes premières questions. Mais j'en ai d'autres. ;)

Est-ce qu'il y a des abonnés dans l'un des cas suivants :
- réception "nomail"
- réception "digest", "digestplain", "notice" ou "summary"
- abonnement suspendu
- réception au format HTML pur ou texte pur (avec un message qui ne contiendrait pas l'un de ces deux formats)

Non tout le monde est sur l'exemple ci-dessus :

mysql> select user_subscriber from subscriber_table where list_subscriber='diffusion' and reception_subscriber not like 'html';
Empty set (0.06 sec)

Avec un email qui a été envoyé en multipart/mixed dont text/plain, text/html et application/pdf.

adresse@cachée">

Le log de sympa a l'air clean : 
Sep 22 16:47:08 localhost sympa[9290]: notice main::DoFile() Processing /adresse@cachée ; sender: EXPEDITEUR Structure <adresse@cachée>#012 ; message-id: <adresse@cachée>#012 
Sep 22 16:47:08 localhost sympa[9290]: info main::DoMessage() Processing message for diffusion with priority 5, <adresse@cachée>#012 
Sep 22 16:47:09 localhost sympa[9290]: info Auth::create_one_time_ticket() Auth::create_one_time_ticket(adresse@cachée,listes.domain.tld,modindex/diffusion,mail) value= 15205934488940 
Sep 22 16:47:09 localhost sympa[9290]: notice List::send_to_editor() ticket : 15205934488940 
Sep 22 16:47:10 localhost sympa[9290]: info main::DoMessage() Key a21bad11df177a3d5b4217a961edf106 for list diffusion from adresse@cachée sent to editors, /adresse@cachée 
Sep 22 16:53:20 localhost sympa[9290]: notice main::DoFile() Processing /adresse@cachée ; sender: adresse@cachée#012 ; message-id: <adresse@cachée>#012 
Sep 22 16:53:20 localhost sympa[9290]: info main::DoSendMessage() Processing web message for adresse@cachée 
Sep 22 16:53:21 localhost sympa[9290]: info main::DoSendMessage() Message for adresse@cachée sent 
Sep 22 16:53:26 localhost sympa[9290]: notice main::DoFile() Processing /adresse@cachée ; sender: adresse@cachée#012 ; message-id: <adresse@cachée>#012 
Sep 22 16:53:26 localhost sympa[9290]: notice Commands::parse() Parsing: 
Sep 22 16:53:26 localhost sympa[9290]: notice Commands::parse() Parsing: QUIET DISTRIBUTE diffusion a21bad11df177a3d5b4217a961edf106 
Sep 22 16:53:32 localhost sympa[9290]: notice List::send_msg() No VERP subscribers left to distribute message from adresse@cachée to list diffusion 
Sep 22 16:53:32 localhost sympa[9290]: info Commands::distribute() Message for diffusion from adresse@cachée accepted (6 seconds, 309 sessions, 7723 subscribers), message-id=<adresse@cachée>#012, size=0 
Sep 22 16:53:32 localhost sympa[9290]: info Commands::distribute() DISTRIBUTE diffusion a21bad11df177a3d5b4217a961edf106 from adresse@cachée accepted (6 seconds) 
Sep 22 16:53:39 localhost bulk[9298]: info Workload increased: 294 packets to process. Creating 2 child bulks to increase sending rate. 
Sep 22 16:53:39 localhost bulk[9298]: info Starting bulk child daemon, pid 26082 
Sep 22 16:53:39 localhost bulk[26082]: info Bulk slave daemon started with pid 26082 
Sep 22 16:53:40 localhost bulk[9298]: info Starting bulk child daemon, pid 26088 
Sep 22 16:53:40 localhost bulk[26088]: info Bulk slave daemon started with pid 26088 
Sep 22 16:54:53 localhost bulk[9298]: notice Done sending message <adresse@cachée> to list adresse@cachée (priority 5) in 81 seconds since scheduled expedition date.

Pendant ce temps dans wwsympa.log :
Sep 22 16:53:34 localhost archived[9316]: notice Archiving adresse@cachée for list adresse@cachée
Sep 22 16:53:54 localhost bounced[9331]: notice main::update_subscriber_bounce_history() Received bounce for email address adresse@cachée, list diffusion
Sep 22 16:53:54 localhost bounced[9331]: notice main::update_subscriber_bounce_history() Received bounce for email address adresse@cachée, list diffusion
Sep 22 16:53:54 localhost bounced[9331]: notice main::update_subscriber_bounce_history() Received bounce for email address adresse@cachée, list diffusion-uns
...

Donc il y a du bounce.

Oui, actuellement je lis 7,8% d'erreurs sur 7718 adresses (certains se sont désabonnés depuis l'envoi du message). Mais les abonnés qui n'ont rien reçu ne sont pas dedans ! au moins deux :-(

adresse@cachée">

Par contre une estimation grossière des emails envoyés confirme qu'il en manque (pas d'autre liste utilisée dans le même intervalle de temps): 
[root@serveur_sympa ~]# grep " to=<" /var/log/maillog | wc -l
6882

Je ne sais pas si postfix log comme sendmail, mais n'oublions pas que Sympa fait du bulk mailing : s'il peut grouper plusieurs abonnés dans une seule session, il le fait. Dans ce cas, le log sendmail resemble à ça :

Sep 23 11:31:50 listes sendmail-bd[25054]: s8N9Vm8G025034: to=<adresse@cachée>,<adresse@cachée>,[...],<adresse@cachée>, delay=00:00:01, xdelay=00:00:01, mailer=esmtp, pri=750192, relay=smtp1.cru.fr. [195.220.94.131], dsn=2.0.0, stat=Sent (s8N9Vn5P010911 Message accepted for delivery)
Donc ton grep renvoie une seule ligne pour x adresses email destinataires.
À moins que ta liste soit à 100% de VERP ou en mode merge, tu auras toujours moins de ligne de log de messagerie que de destinataires. En fait les résultats de ta commande te donne le nombre de sessions, pas le nombre de destinataires.

C'est vrai. J'ai trouvé un peu mieux : une requête zimbra qui me permet de tracer les emails d'après les enveloppes je crois. On se situe en aval de sympa et son postfix donc. Provenant de adresse@cachée sur la plage horaire 1630 - 1730 je ne trouve que 4260 destinataires (j'ai le contenu des sessions qui font 24 destinataires chaque fois). Il m'en manque peut-être ?

adresse@cachée">

Dans quelle direction puis-je continuer les investigations pour déterminer combien d'abonnés sont concernés et pourquoi ? 

L'analyse des bounces, déjà. Tous ceux qui ont bouncé n'ont pas reçu le message. Si tu as l'adresse d'une personne qui n'a pas reçu le message, cherche-la dans les logs de bounced.

Déjà fait avec mon adresse@cachée : nope

grep bounce /var/log/wwsympa.log | grep blabla

Si le message s'est fait jeter par un antispam, tu n'as pas forcément de bounce. Le rejet peut être silencieux pour éviter le backscattering.

Je vais re-vérifier cette hypothèse d'antispam. Il y a une appliance externe à Zimbra (Sympa cause direct à Zimbra), c'est pourquoi il est désactivé normalement. Mais il ne l'est peut-être pas tout-à-fait ?

Voilà, bon courage !

Merci merci

David

adresse@cachée">

Merci de votre aide,

Cordialement - best Regards 
Guillaume Laurès 

Yaziba, la solution Collaborative hébergée / http://www.yaziba.net 
Netixia, nos dernières références / http://www.netixia.fr/references 

Chef de Projet NETIXIA 
Email : adresse@cachée 
Fixe : 02 47 64 64 64 - poste 506 

---------------------------------------------- 
Note de confidentialité : Les informations contenues dans ce document peuvent présenter un caractère confidentiel et sont couvertes par le secret professionnel. 
Leur utilisation par toute autre personne que le destinataire est strictement interdite. En cas d'erreur, merci de nous prévenir immédiatement par téléphone au 02 47 05 78 50. 
Confidentiality note : This message and any supporting information is confidential and privileged. If you are not the intended recipient, please be notified that disclosing or making use of the contents without permission is prohibited. If you receive this message erroneously please contact us immediately with the following telephone number +33 2 47 05 78 50. 

--
A bug in Sympa? Quick! To the bug tracker!

David Verdin Études et projets applicatifs
Tél : +33 2 23 23 69 71 Fax : +33 2 23 23 71 21   www.renater.fr	RENATER 263 Avenue du Gal Leclerc 35042 Rennes Cedex