Projet

Général

Profil

Actions
Copier le lien

Anomalie #14152

fermé

Script de notification en erreur (relais SMTP)

Ajouté par Henri QUENEAU il y a plus de 4 ans. Mis à jour il y a plus de 3 ans.

Statut:
R&D - Terminé
Priorité:
1-Majeur
Assigné à:
Guillaume HEURTIER
Version cible:
20.10
Début:
05/06/2020
Echéance:

Description

Impossible d'envoyer les notifications :

lors du lancement du script des notifications, les mails ne sont pas délivrés. on obtient les logs:

[2020-06-15 15:02:32] INFO 0 'Load xml config file:/var/www/html/MaarchCourrier/custom/cs_courrier/modules/notifications/batch/config/config.xml'
[2020-06-15 15:02:32] INFO 0 'Load xml config file:/var/www/html/MaarchCourrier/custom/cs_courrier/modules/notifications/batch/config/config.xml'
[2020-06-15 15:02:32] INFO 0 'STATE:LOAD_EMAILS'
[2020-06-15 15:02:32] INFO 0 '11 notification(s) to send.'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 1/11 (TO => robin.saldinger@maarch.org, SUBJECT => Avis : Avis à émettre ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 2/11 (TO => fxlyonnetdumoutier@vincennes.fr, SUBJECT => Courriers à traiter ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 3/11 (TO => jdegouy@vincennes.fr, SUBJECT => Courriers à viser ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 4/11 (TO => stang@vincennes.fr, SUBJECT => Courriers à traiter ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 5/11 (TO => jdegouy@vincennes.fr, SUBJECT => Courriers à viser ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 6/11 (TO => fraymond@vincennes.fr, SUBJECT => Courriers à traiter ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 7/11 (TO => rmubiayi@vincennes.fr, SUBJECT => Courriers à traiter ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 8/11 (TO => fsmaali@vincennes.fr, SUBJECT => Courriers à viser ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 9/11 (TO => fguesdon@vincennes.fr, SUBJECT => Courriers à traiter ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 10/11 (TO => fraymond@vincennes.fr, SUBJECT => Courriers à traiter ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 'sending notification 11/11 (TO => robin.saldinger@maarch.org, SUBJECT => Avis : Avis à émettre ) ...'
[2020-06-15 15:02:32] ERROR 0 'SENDING EMAIL ERROR ! (AUTH command failed: 5.5.1 Error: authentication not enabled)'
[2020-06-15 15:02:32] INFO 0 'STATE:SEND_AN_EMAIL'
[2020-06-15 15:02:32] INFO 0 '0 notification(s) sent'
[2020-06-15 15:02:32] INFO 0 'End of process'

log du serveur smtp:

Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: connect from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: connect from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: connect from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: connect from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: connect from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 14:57:37 sp62 postfix/submission/smtpd[30766]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:01:26 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37142 to [172.27.0.8]:25
Jun 15 15:01:32 sp62 postfix/postscreen[21031]: PASS NEW [192.168.201.34]:37142
Jun 15 15:01:32 sp62 postfix/smtpd[17330]: connect from unknown[192.168.201.34]
Jun 15 15:01:32 sp62 postfix/smtpd[17330]: Anonymous TLS connection established from unknown[192.168.201.34]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
Jun 15 15:01:32 sp62 postfix/smtpd[17330]: NOQUEUE: filter: RCPT from unknown[192.168.201.34]: <ne-pas-repondre@vincennes.fr>: Sender address triggers FILTER smtp-amavis:[127.0.0.1]:10026; from=<ne-pas-repondre@vincennes.fr> to=<henri.queneau@maarch.org> proto=ESMTP helo=<courrier.vincennes.fr>
Jun 15 15:01:32 sp62 postfix/smtpd[17330]: BA0A8760365: client=unknown[192.168.201.34], sasl_method=LOGIN, sasl_username=ne-pas-repondre@vincennes.fr
Jun 15 15:01:32 sp62 postfix/smtpd[17330]: disconnect from unknown[192.168.201.34] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=8
Jun 15 15:01:32 sp62 amavis[31969]: (31969-09) Checking: P8vU6Y-eG_V9 ORIGINATING/MYNETS [192.168.201.34] <ne-pas-repondre@vincennes.fr> -> <henri.queneau@maarch.org>
Jun 15 15:01:32 sp62 amavis[31969]: (31969-09) Passed CLEAN {RelayedOutbound}, ORIGINATING/MYNETS LOCAL [192.168.201.34]:37142 <ne-pas-repondre@vincennes.fr> -> <henri.queneau@maarch.org>, Queue-ID: BA0A8760365, Message-ID: <u9pgmB5HbCX2gGBws4FEOYfP0wqYjFvnc4dvESyWCnw@courrier.vincennes.fr>, mail_id: P8vU6Y-eG_V9, Hits: -, size: 649, queued_as: D8CFD760366, 118 ms
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37166 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37166
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37168 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37168
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37170 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37170
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37172 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37172
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37174 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37174
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37176 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37176
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37178 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37178
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37180 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37180
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37182 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37182
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37184 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37184
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: CONNECT from [192.168.201.34]:37186 to [172.27.0.8]:25
Jun 15 15:02:32 sp62 postfix/postscreen[21031]: PASS OLD [192.168.201.34]:37186
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: connect from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: lost connection after AUTH from unknown[192.168.201.34]
Jun 15 15:02:32 sp62 postfix/smtpd[17335]: disconnect from unknown[192.168.201.34] ehlo=1 auth=0/1 commands=1/2

Pourtant l'envoi de mail depuis l'application fonctonne bien

Fichiers

Télécharger tous les fichiers
Capture d’écran de 2020-06-05 13-16-28.png (28,2 ko) Capture d’écran de 2020-06-05 13-16-28.png Robin SALDINGER, 05/06/2020 13:16
Capture d’écran de 2020-06-12 17-18-40.png (9,15 ko) Capture d’écran de 2020-06-12 17-18-40.png Robin SALDINGER, 12/06/2020 17:19
Capture d’écran de 2020-06-12 17-20-28.png (13,8 ko) Capture d’écran de 2020-06-12 17-20-28.png Robin SALDINGER, 12/06/2020 17:21

Demandes liées 1 (0 ouverte — 1 fermée)

Lié à Backlog Courrier - Fonctionnalité #14158: Refactoring des classes et fichiers pour l'envoi des notificationsR&D - TerminéDamien BUREL16/06/2020Actions
Actions
Copier le lien
 #2

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Statut changé de A qualifier à A traiter
Actions
Copier le lien
 #3

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Statut changé de A traiter à R&D - A planifier
Actions
Copier le lien
 #4

Mis à jour par Alex ORLUC il y a plus de 4 ans

Cela semble plutôt clair,

les infos serveur de mail ne semblent pas être bonnes :

AUTH command failed: 5.5.1 Error: authentication not enabled

et

lost connection after AUTH from unknown[192.168.201.34]

Actions
Copier le lien
 #5

Mis à jour par Henri QUENEAU il y a plus de 4 ans

Les informations d'envois de mail depuis maarch sont les mêmes et ça marche.

Actions
Copier le lien
 #6

Mis à jour par Laurent GIOVANNONI il y a plus de 4 ans

Vous avez essayé cette piste :

https://serverfault.com/questions/712903/503-5-5-1-error-authentication-not-enabled-when-trying-to-connect-to-my-postf

d'après les logs, je comprends que vous utilisez smtpd via un relais postfix ?

si c'est le cas, modifiez postconf :

For enable SASL when receiving email via smtpd, you need to put this parameter

smtpd_sasl_auth_enable = yes

sinon autre piste si souci avec phpmailer :

https://stackoverflow.com/questions/50659028/postfix-php-mail-issue-client-503-5-5-1-error-authentication-not-enabled-smtp

Actions
Copier le lien
 #7

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Statut changé de R&D - A planifier à Complément d'Informations
  • Assigné à changé de EDI PO à Henri QUENEAU
Actions
Copier le lien
 #8

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

Actions
Copier le lien
 #9

Mis à jour par Henri QUENEAU il y a plus de 4 ans

  • Statut changé de Complément d'Informations à A traiter
  • Assigné à changé de Henri QUENEAU à EDI PO

Ajout d'un relai smtp.

activation du mode sendmail (dans la conf du batch des notifications).

obtention de l'erreur:

root@sp78:/var/www/html/MaarchCourrier/custom/cs_courrier/modules/notifications/batch/scripts# php /var/www/html/MaarchCourrier/modules/notifications/batch/process_email_stack.php -c /var/www/html/MaarchCourrier/custom/cs_courrier/modules/notifications/batch/config/config.xml
sh: 1: Syntax error: end of file unexpected
sh: 1: Syntax error: end of file unexpected
sh: 1: Syntax error: end of file unexpected
sh: 1: Syntax error: end of file unexpected
sh: 1: Syntax error: end of file unexpected
sh: 1: Syntax error: end of file unexpected
sh: 1: Syntax error: end of file unexpected

les envois de mail fonctionnent lorsqu'on envoi un mail en ligne de commande.

le problème vient de maarch :

https://labs.maarch.org/maarch/MaarchCourrier/blob/20.03/modules/notifications/batch/process_email_stack.php

Il faut modifier le code en supprimant/commentant les conditions:

            if (empty($email->sender) && !empty((string)$mailerParams->mailfrom)) {
                $email->sender = (string)$mailerParams->mailfrom;
            }

            if (substr($email->sender, 0, 1) != '<') {
                $email->sender = '<' . $email->sender;
            }
            if (substr($email->sender, -1) != '>') {
                $email->sender .= '>';
            }

En commentant ça, les mails partent!

Attention, cet ajout a été fait pour corriger l'envoi de mail d'un autre client.

Le client de vincennes utilise le mode sendmail car ils sont en startTLS.
L'autre client utilise le mode smtp tout simplement.

Il faut ajouter une condition dans le code disant de passer sur les conditions listés ci dessus lorsqu'on n'est pas en mode sendmail

Actions
Copier le lien
 #10

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Sujet changé de Impossible d'envoyer les notifications à Script de notification en erreur (relais SMTP)
  • Statut changé de A traiter à Etude planifiée
Actions
Copier le lien
 #11

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Statut changé de Etude planifiée à R&D - A planifier
  • Priorité changé de 0-Bloquant à 1-Majeur
Actions
Copier le lien
 #12

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Version cible changé de 20.03 (Fin de vie) à 20.10 Develop
Actions
Copier le lien
 #13

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Projet changé de 298 à 299
  • Statut changé de R&D - A planifier à R&D - En cours
Actions
Copier le lien
 #14

Mis à jour par Florian AZIZIAN il y a plus de 4 ans

  • Assigné à EDI PO supprimé
Actions
Copier le lien
 #15

Mis à jour par Guillaume HEURTIER il y a plus de 4 ans

  • Assigné à mis à Guillaume HEURTIER
Actions
Copier le lien
 #16

Mis à jour par Guillaume HEURTIER il y a plus de 4 ans

  • Statut changé de R&D - En cours à R&D - Terminé
Actions
Copier le lien
 #17

Mis à jour par Emmanuel DILLARD il y a plus de 4 ans

  • Projet changé de 299 à 298
Actions
Copier le lien
 #20

Mis à jour par Emmanuel DILLARD il y a plus de 3 ans

  • Projet changé de 298 à Backlog Courrier
  • Version cible changé de 20.10 Develop à 20.10
Actions
Copier le lien

Formats disponibles : Atom PDF