Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Mail loop with sympa-request address because of misconfiguration #957

Closed
jth56000 opened this issue Jun 11, 2020 · 16 comments · Fixed by #1003
Closed

Mail loop with sympa-request address because of misconfiguration #957

jth56000 opened this issue Jun 11, 2020 · 16 comments · Fixed by #1003
Assignees
Labels
Milestone

Comments

@jth56000
Copy link

Since I upgrade my sympa server from 6.2.52 to 6.2.54 I have lots of following messages in sympa log :

Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,8135/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.12@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1
Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,7561/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.952@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1
Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,7330/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.498@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1
Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,3028/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.834@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1

Version

6.2.54

Installation method

RPM package on RedHat 7.6

Expected behavior

THe log should be less verbose, such messages should not appear.

Actual behavior

The log says lots of delivery status notification failed 👍

Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,8135/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.12@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1
Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,7561/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.952@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1
Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,7330/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.498@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1
Jun 11 08:09:20 tcgesympa2 sympa_msg[57145]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <sympa@listes-rec.dsi.cnrs.fr.1591855760.57145,3028/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591855760.57145.834@listes-rec.dsi.cnrs.fr; recipients=sympa-request@listes-rec.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=failed; status=5.1.1

Additional information

@jth56000
Copy link
Author

my mailq indicates multiples mails :
#mailq
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
90E3B239 3524 Thu Jun 11 09:49:24 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

6273D23F* 3553 Thu Jun 11 09:49:24 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

0E8A223B* 3552 Thu Jun 11 09:49:23 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

9AB86242* 3553 Thu Jun 11 09:49:24 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

7A1CC236* 3553 Thu Jun 11 09:49:24 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

1DD8B197* 3552 Thu Jun 11 09:49:23 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

3F09523C* 3553 Thu Jun 11 09:49:24 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

2398622D* 3553 Thu Jun 11 09:49:23 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

CFAA421C 3552 Thu Jun 11 09:49:24 MAILER-DAEMON
sympa-request@listes-rec.dsi.cnrs.fr

-- 33 Kbytes in 9 Requests.

@ikedas
Copy link
Member

ikedas commented Jun 11, 2020

@jth56000 ,
Have you read the chapter "Configure mail server" in the administration manual?
If you have done, please show us all of settings (for Sympa along with mail server) described in corresponding sections of this chapter.

@jth56000
Copy link
Author

jth56000 commented Jun 11, 2020 via email

@ikedas
Copy link
Member

ikedas commented Jun 11, 2020

What is the change in mail server configuration between 6.2.52 and 6.2.54 ? I can provide you my postfix main.cf and master.cf, I did not touch to them during my migration. I can also provide my sympa.conf if that can help.

First of all please show us these: sympa.conf, main.cf and master.cf.

@ikedas
Copy link
Member

ikedas commented Jun 11, 2020

Addition: list_aliases.tt2. And recently added lines of aliases file (the location is speficied by sendmail_aliases parameter).

@jth56000
Copy link
Author

jth56000 commented Jun 11, 2020 via email

@ikedas
Copy link
Member

ikedas commented Jun 11, 2020

Sorry, attachments in e-mail are removed. Can you sign-in to GitHub web UI?

@jth56000
Copy link
Author

sympa.zip
Here are the files.

@ikedas
Copy link
Member

ikedas commented Jun 12, 2020

Also, please show these:

  • The log from when you sent a message to when the first error log was shown.
  • The list you sent the message in above does exist? Or it doesn't exist?
  • The other settings of Postfix: /etc/postfix/mydestination and so on, i.e. the files in /etc/postfix/ directory.

@jth56000
Copy link
Author

jth56000 commented Jun 12, 2020

here is the log from when I sent a message 👍

root@tcgesympa2:~ [2020/06/12-05:21:03]
#grep jean /var/log/sympa
Jun 12 03:42:18 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() Running task Sympa::Task <date=1591926108;label=INIT;model=sync_include;context=testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr>
Jun 12 03:42:18 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessRequest::_twist() Processing Sympa::Request <action=include;context=testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr;role=member>
Jun 12 03:44:26 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::DataSource::RemoteFile <context=testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr;id=53d5188e;role=member;name=>: 4 included, 0 deleted, 45365 updated, 87 kept
Jun 12 03:44:28 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::Request <action=include;context=testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr;role=member>: 4 included, 1 deleted, 45365 updated
Jun 12 03:44:28 tcgesympa2 task_manager[87274]: notice Sympa::Spool::store() Sympa::Task <date=1591929868;label=INIT;model=sync_include;context=testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr> is stored into Sympa::Spool::Task as <1591929868.INIT.sync_include.testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr>
Jun 12 03:44:28 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::do_next() --> new task Sympa::Task <date=1591929868;label=INIT;model=sync_include;context=testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr>
Jun 12 03:44:28 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() The task Sympa::Task <date=1591926108;label=INIT;model=sync_include;context=testliste_test_jean_thomas@listes-rec.dsi.cnrs.fr> is now useless. Removing it
Jun 12 04:12:33 tcgesympa2 task_manager[87274]: info Sympa::Spindle::ProcessTask::do_eval_bouncers(liste-test-jean-thomas)
Jun 12 04:12:33 tcgesympa2 task_manager[87274]: info Sympa::Spindle::ProcessTask::do_eval_bouncers(liste_test_jean_thomas_9)
Jun 12 04:12:33 tcgesympa2 task_manager[87274]: info Sympa::Spindle::ProcessTask::do_eval_bouncers(liste_test_jean_thomas_moderee)
Jun 12 04:14:05 tcgesympa2 task_manager[87274]: info Sympa::Spindle::ProcessTask::do_eval_bouncers(test-jean)
Jun 12 04:14:05 tcgesympa2 task_manager[87274]: info Sympa::Spindle::ProcessTask::do_eval_bouncers(testliste_test_jean_thomas)
Jun 12 04:31:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() Running task Sympa::Task <date=1591928801;label=INIT;model=sync_include;context=liste-test-jean-thomas@listes-rec.dsi.cnrs.fr>
Jun 12 04:31:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessRequest::_twist() Processing Sympa::Request <action=include;context=liste-test-jean-thomas@listes-rec.dsi.cnrs.fr;role=member>
Jun 12 04:31:29 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::DataSource::File <context=liste-test-jean-thomas@listes-rec.dsi.cnrs.fr;id=4f6c72ab;role=member;name=test-signoff.tx>: 0 included, 0 deleted, 2 updated, 0 kept
Jun 12 04:31:29 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::Request <action=include;context=liste-test-jean-thomas@listes-rec.dsi.cnrs.fr;role=member>: 0 included, 0 deleted, 2 updated
Jun 12 04:31:29 tcgesympa2 task_manager[87274]: notice Sympa::Spool::store() Sympa::Task <date=1591932689;label=INIT;model=sync_include;context=liste-test-jean-thomas@listes-rec.dsi.cnrs.fr> is stored into Sympa::Spool::Task as <1591932689.INIT.sync_include.liste-test-jean-thomas@listes-rec.dsi.cnrs.fr>
Jun 12 04:31:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::do_next() --> new task Sympa::Task <date=1591932689;label=INIT;model=sync_include;context=liste-test-jean-thomas@listes-rec.dsi.cnrs.fr>
Jun 12 04:31:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() The task Sympa::Task <date=1591928801;label=INIT;model=sync_include;context=liste-test-jean-thomas@listes-rec.dsi.cnrs.fr> is now useless. Removing it
Jun 12 04:41:45 tcgesympa2 task_manager[87274]: err main::#148 > Sympa::Spindle::spin#83 > Sympa::Spindle::ProcessTask::_twist#74 > Sympa::Spindle::ProcessTask::_execute#140 > Sympa::Spindle::ProcessTask::_cmd_process#174 > Sympa::Spindle::ProcessTask::do_sync_include#1349 > Sympa::List::sync_include#4798 > Sympa::Spindle::spin#95 > Sympa::Request::Handler::include::_twist#181 > Sympa::Request::Handler::include::_update_users#292 > Sympa::DataSource::next#149 > Sympa::DataSource::File::_next#75 Skip badly formed line: "Chlo▒.noirjean@cnrs.fr"
Jun 12 04:41:54 tcgesympa2 task_manager[87274]: err main::#148 > Sympa::Spindle::spin#83 > Sympa::Spindle::ProcessTask::_twist#74 > Sympa::Spindle::ProcessTask::_execute#140 > Sympa::Spindle::ProcessTask::_cmd_process#174 > Sympa::Spindle::ProcessTask::do_sync_include#1349 > Sympa::List::sync_include#4798 > Sympa::Spindle::spin#95 > Sympa::Request::Handler::include::_twist#181 > Sympa::Request::Handler::include::_update_users#292 > Sympa::DataSource::next#149 > Sympa::DataSource::File::_next#75 Skip badly formed line: "K▒vin.jeanpert@alsace.cnrs.fr"
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() Running task Sympa::Task <date=1591929456;label=INIT;model=sync_include;context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessRequest::_twist() Processing Sympa::Request <action=include;context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr;role=member>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::DataSource::File <context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr;id=4f6c72ab;role=member;name=test-signoff.tx>: 0 included, 0 deleted, 1 updated, 0 kept
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::Request <action=include;context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr;role=member>: 0 included, 0 deleted, 1 updated
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spool::store() Sympa::Task <date=1591933349;label=INIT;model=sync_include;context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> is stored into Sympa::Spool::Task as <1591933349.INIT.sync_include.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::do_next() --> new task Sympa::Task <date=1591933349;label=INIT;model=sync_include;context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() The task Sympa::Task <date=1591929456;label=INIT;model=sync_include;context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> is now useless. Removing it
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() Running task Sympa::Task <date=1591929456;label=INIT;model=sync_include;context=liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessRequest::_twist() Processing Sympa::Request <action=include;context=liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr;role=member>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::DataSource::List <context=liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr;id=645ba8bf;role=member;name=liste_test_jean_thomas_moderee>: 0 included, 0 deleted, 4 updated, 0 kept
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: info Sympa::Request::Handler::include::_twist() Sympa::Request <action=include;context=liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr;role=member>: 0 included, 0 deleted, 4 updated
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spool::store() Sympa::Task <date=1591933349;label=INIT;model=sync_include;context=liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr> is stored into Sympa::Spool::Task as <1591933349.INIT.sync_include.liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::do_next() --> new task Sympa::Task <date=1591933349;label=INIT;model=sync_include;context=liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr>
Jun 12 04:42:29 tcgesympa2 task_manager[87274]: notice Sympa::Spindle::ProcessTask::_execute() The task Sympa::Task <date=1591929456;label=INIT;model=sync_include;context=liste_test_jean_thomas_9@listes-rec.dsi.cnrs.fr> is now useless. Removing it
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ProcessIncoming::_twist() Processing Sympa::Message <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591931998.25172>; envelope_sender=jean.thomas@ext.dsi.cnrs.fr; message_id=E830CF905957404CB59FAEF2A5FD302A181ECF60@CNREXCMBX05P.core-res.rootcore.local; sender=jean.thomas@ext.dsi.cnrs.fr
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: info Sympa::Spindle::DoMessage::_twist() Processing message Sympa::Message <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591931998.25172> for Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> with priority 5, <E830CF905957404CB59FAEF2A5FD302A181ECF60@CNREXCMBX05P.core-res.rootcore.local>
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: notice Sympa::Spool::store() Sympa::Message <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591931998.25172> is stored into Sympa::Spool::Moderation as <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_26216b1acedf5e4602cf5255939a195d>
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932007.87265,2172/shelved:dkim_sign>; envelope_sender=jean-test+ir-04-2-c-owner@listes-rec.dsi.cnrs.fr; message_id=sympa.1591932006.87265.156@listes-rec.dsi.cnrs.fr; recipients=jean.thomas@ext.dsi.cnrs.fr; sender=jean-test+ir-04-2-c-request@listes-rec.dsi.cnrs.fr; template=moderate;
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: notice Sympa::Spool::Outgoing::store() Message Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932007.87265,2172/shelved:dkim_sign> is stored into bulk spool as <5.5.1591932007.1591932006.344114.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,4008>
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: info Sympa::Spindle::ToModeration::_twist() Key 26216b1acedf5e4602cf5255939a195d of message Sympa::Message <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591931998.25172> for list Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> from jean.thomas@ext.dsi.cnrs.fr sent to editors (0.28 seconds)
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932007.87265,2629/shelved:dkim_sign>; envelope_sender=jean-test+ir-04-2-c-owner@listes-rec.dsi.cnrs.fr; message_id=sympa.1591932006.87265.199@listes-rec.dsi.cnrs.fr; recipients=jean.thomas@ext.dsi.cnrs.fr; sender=sympa@listes-rec.dsi.cnrs.fr; template=message_report; type=success
Jun 12 05:20:06 tcgesympa2 sympa_msg[87265]: notice Sympa::Spool::Outgoing::store() Message Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932007.87265,2629/shelved:dkim_sign> is stored into bulk spool as <5.5.1591932007.1591932006.362739.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,4849>
Jun 12 05:20:07 tcgesympa2 bulk[87464]: notice Sympa::Spindle::ProcessOutgoing::_twist() Start sending message Sympa::Message <5.5.1591932007.1591932006.362739.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,4849/s/shelved:dkim_sign> to Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) (starting 0 seconds after scheduled expedition date)
Jun 12 05:20:07 tcgesympa2 bulk[87301]: notice Sympa::Spindle::ProcessOutgoing::_twist() Start sending message Sympa::Message <5.5.1591932007.1591932006.344114.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,4008/s/shelved:dkim_sign> to Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) (starting 0 seconds after scheduled expedition date)
Jun 12 05:20:07 tcgesympa2 bulk[87464]: notice Sympa::Mailer::store() Done sending message Sympa::Message <5.5.1591932007.1591932006.362739.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,4849/s> for Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) in 0 seconds since scheduled expedition date
Jun 12 05:20:07 tcgesympa2 bulk[87301]: notice Sympa::Mailer::store() Done sending message Sympa::Message <5.5.1591932007.1591932006.344114.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,4008/s> for Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) in 0 seconds since scheduled expedition date
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ProcessIncoming::_twist() Processing Sympa::Message <sympa@listes-rec.dsi.cnrs.fr.1591932034.25918>; envelope_sender=jean.thomas@ext.dsi.cnrs.fr; message_id=E830CF905957404CB59FAEF2A5FD302A181ECF7B@CNREXCMBX05P.core-res.rootcore.local; sender=jean.thomas@ext.dsi.cnrs.fr
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Request::Message::__parse() Parsing: DISTRIBUTE jean-test+ir-04-2-c 26216b1acedf5e4602cf5255939a195d
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ProcessMessage::_twist() Processing Sympa::Request <action=distribute;context=jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr>
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932044.87265,7451/shelved:dkim_sign>; envelope_sender=<>; message_id=sympa.1591932044.87265.351@listes-rec.dsi.cnrs.fr; recipients=jean.thomas@ext.dsi.cnrs.fr; sender=sympa-request@listes-rec.dsi.cnrs.fr; template=delivery_status_notification; action=delivered; status=2.1.5
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spool::Outgoing::store() Message Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932044.87265,7451/shelved:dkim_sign> is stored into bulk spool as <5.5.1591932044.1591932044.663451.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,7642>
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spool::Outgoing::store() Message Sympa::Message <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_26216b1acedf5e4602cf5255939a195d/shelved:dkim_sign;merge> is stored into bulk spool as <5.5.1591932044.1591932044.700170.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_z,87265,8438>
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ToList::_send_msg() No VERP subscribers left to distribute message to list Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr>
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spindle::ProcessTemplate::_twist() Processing Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932045.87265,2089/shelved:dkim_sign>; envelope_sender=jean-test+ir-04-2-c-owner@listes-rec.dsi.cnrs.fr; message_id=sympa.1591932044.87265.189@listes-rec.dsi.cnrs.fr; recipients=jean.thomas@ext.dsi.cnrs.fr; sender=sympa@listes-rec.dsi.cnrs.fr; template=message_report; type=success
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: notice Sympa::Spool::Outgoing::store() Message Sympa::Message::Template <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr.1591932045.87265,2089/shelved:dkim_sign> is stored into bulk spool as <5.5.1591932045.1591932044.720253.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,7216>
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: info Sympa::Spindle::ToList::_twist() Message Sympa::Message <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_26216b1acedf5e4602cf5255939a195d/shelved:dkim_sign> for Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> from jean.thomas@ext.dsi.cnrs.fr accepted (0.10 seconds, 1 sessions, 1 subscribers), message ID=E830CF905957404CB59FAEF2A5FD302A181ECF60@CNREXCMBX05P.core-res.rootcore.local, size=11482
Jun 12 05:20:44 tcgesympa2 sympa_msg[87265]: info Sympa::Request::Handler::distribute::_twist() DISTRIBUTE jean-test+ir-04-2-c 26216b1acedf5e4602cf5255939a195d from jean.thomas@ext.dsi.cnrs.fr accepted (0.11 seconds)
Jun 12 05:20:46 tcgesympa2 bulk[87466]: notice Sympa::Spindle::ProcessOutgoing::_twist() Start sending message Sympa::Message <5.5.1591932044.1591932044.663451.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,7642/s/shelved:dkim_sign> to Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) (starting 2 seconds after scheduled expedition date)
Jun 12 05:20:46 tcgesympa2 bulk[87466]: notice Sympa::Mailer::store() Done sending message Sympa::Message <5.5.1591932044.1591932044.663451.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,7642/s> for Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) in 2 seconds since scheduled expedition date
Jun 12 05:20:47 tcgesympa2 bulk[87466]: notice Sympa::Mailer::store() Done sending message Sympa::Message <5.5.1591932044.1591932044.700170.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_z,87265,8438/z> for Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) in 3 seconds since scheduled expedition date
Jun 12 05:20:47 tcgesympa2 bulk[87466]: notice Sympa::Spindle::ProcessOutgoing::_twist() Start sending message Sympa::Message <5.5.1591932045.1591932044.720253.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,7216/s/shelved:dkim_sign> to Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) (starting 2 seconds after scheduled expedition date)
Jun 12 05:20:47 tcgesympa2 bulk[87466]: notice Sympa::Mailer::store() Done sending message Sympa::Message <5.5.1591932045.1591932044.720253.jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr_s,87265,7216/s> for Sympa::List <jean-test+ir-04-2-c@listes-rec.dsi.cnrs.fr> (priority 5) in 2 seconds since scheduled expedition date

The list exist, messages are correctly transmitted but I have some error message described in "Actual behavior" that I don't understand and are verbose in the sympa log.

postfix.tar.gz

Attache file : content of postfix directory.

The all thing was working in 6.2.52.

@jth56000
Copy link
Author

In /var/spool/postfix/maildrop I have a lot of messages like 👍

T1591933637 432325Arewrite_context=localFSR$sympa-request@listes-rec.dsi.cnrs.frMNGDKIM-Signature: v=1; a=rsa-sha256; c=relaxed; d=listes-rec.dsi.cnrs.fr;N( h=message-id:date:to:from:mime-versionNA :content-transfer-encoding:content-type:subject; s=lists; bh=mRsNA hggdgSkVPKbd1a1hsuHD0PKXtJmNIHevX6vvaYFc=; b=E5Oas2NOIBxWB+H2V8xNA jgirULPrBUgKgHpiksHpUjSEXNoVeEAAk2Qn6iqc9fhjoJJY1z9FCQXlt8CuseAINA FHaTjkY0VhzzzCjtSbJMSIh0DNqahGLEidUo8YtuYa99FUsFSJbYqk6zbk/2HNimN v/LQ7kwbUdsUO8pUjXbcL8Dk=N?Message-Id: sympa.1591933636.43368.550@listes-rec.dsi.cnrs.frN%Date: Fri, 12 Jun 2020 05:47:16 +0200N(To: sympa-request@listes-rec.dsi.cnrs.frN4From: "SYMPA" sympa-request@listes-rec.dsi.cnrs.frNMIME-Version: 1.0NContent-Transfer-Encoding: 8bitNAuto-Submitted: auto-repliedN=Content-Type: multipart/report; report-type=delivery-status; NK boundary="----------=sympa.1591933636.43368.957@listes-rec.dsi.cnrs.fr"NSubject: Liste inconnueN$X-Loop: sympa@listes-rec.dsi.cnrs.frNX-Mailer: Sympa 6.2.54NN$This is a MIME-encapsulated message.NNA------------=sympa.1591933636.43368.957@listes-rec.dsi.cnrs.frNontent-Disposition: inlineN!Content-Description: NotificationN)Content-Type: TEXT/PLAIN; charset="UTF-8"N+Content-Transfer-Encoding: QUOTED-PRINTABLENMIME-Version: 1.0NContent-length: 461NN?Ceci est une r=C3=A9ponse automatique du robot de listes Sympa.N9Probl=C3=A8me de diffusion de votre message pour la listeN('sympa-request@listes-rec.dsi.cnrs.fr' :NN/L'adresse suivante n'est pas une liste connue :NN% sympa-request@listes-rec.dsi.cnrs.frNNHPour chercher l'adresse de la liste, consultez la liste des listes de ceNserveur :NN4 mailto:sympa@listes-rec.dsi.cnrs.fr?subject=3DWHICHNNFPour plus de d=C3=A9tails, contactez listmaster@listes-rec.dsi.cnrs.frNNA------------=sympa.1591933636.43368.957@listes-rec.dsi.cnrs.frN%Content-Type: message/delivery-statusNN*Reporting-MTA: dns; listes-rec.dsi.cnrs.frN-Arrival-Date: Fri, 12 Jun 2020 05:47:16 +0200NN=Final-Recipient: rfc822; sympa-request@lisStatus: 5.1.1N'Remote-MTA: dns; listes-rec.dsi.cnrs.frN9Diagnostic-Code: X-Sympa; Bad destination mailbox addressNNA------------=sympa.1591933636.43368.957@listes-rec.dsi.cnrs.frN5Content-Type: text/rfc822-headers; charset="US-ASCII"Nontent-Disposition: inlineNContent-Transfer-Encoding: 7BITNMIME-Version: 1.0NContent-length: 1018NN>Received: by tcgesympa2.dsi.cnrs.fr (Postfix, from userid 503)N4 id AE83A1F3; Fri, 12 Jun 2020 05:47:01 +0200 (CEST)NGDKIM-Signature: v=1; a=rsa-sha256; c=relaxed; d=listes-rec.dsi.cnrs.fr;N( h=message-id:date:to:from:mime-versionNA :content-transfer-encoding:content-type:subject; s=lists; bh=1xwNA d+VfOkv3diefdHO10e76yN7S5jB3h8zNVWDgZf1Y=; b=CItUz6HQZUnZ92KTUBRNA Zt5NJxG2X73C4UaxKIeHgWeM/EVvAJPSEiXHlInWExDgsSfJEIPZF4Mv/X/xbnKDNA yWCR9stedVCuG9hUC/nJ9z+Cus/JOaLWLWchu53WUZmDzx4iNvmiuEUIley7VDN/N iq8vT64oAzSJekwhFZL6hxb0=N?Message-Id: sympa.1591933620.43368.169@listes-rec.dsi.cnrs.frN%Date: Fri, 12 Jun 2020 05:47:00 +0200N(To: sympa-request@listes-rec.dsi.cnrs.frN4From: "SYMPA" sympa-request@listes-rec.dsi.cnrs.frNMIME-Version: 1.0NContent-Transfer-Encoding: 8bitNAuto-Submitted: auto-repliedN=Content-Type: multipart/report; report-type=delivery-status; NK boundary="----------=sympa.1591933620.43368.970@listes-rec.dsi.cnrs.fr"NSubject: Liste inconnueN$X-Loop: sympa@listes-rec.dsi.cnrs.frNX-Mailer: Sympa 6.2.54NNNC------------=sympa.1591933636.43368.957@listes-rec.dsi.cnrs.fr--XE

@ikedas
Copy link
Member

ikedas commented Jun 13, 2020

@jth56000 , the log in June 12 indicates no problem. It is not what I asked.

Please try following things:

  1. Stop sympa and postfix services.
  2. Clear messages in Sympa' s incoming spool ($SPOOLDIR/msg), outgoing spool ($SPOOLDIR/bulk/msg & $SPOOLDIR/bulk/pct) and Postfix's queue.
  3. Start postfix and sympa services.
  4. Post a message to the list.
  5. Check if problematic logs are shown.
  6. Show us Sympa's log during 3. to 5. above.

@jth56000
Copy link
Author

jth56000 commented Jun 15, 2020 via email

@ikedas
Copy link
Member

ikedas commented Jun 16, 2020

@jth56000 ,

There seems a message that triggered some sort of mail looping (one message leads Sympa to send another message, and they are repeated). When you observe flood of messages, please show us the log from the beginning of mail looping to some minutes after.

@jth56000
Copy link
Author

jth56000 commented Jun 16, 2020 via email

@ikedas ikedas added bug and removed question labels Sep 17, 2020
@ikedas ikedas added this to the 6.2.58 milestone Sep 17, 2020
@ikedas ikedas self-assigned this Sep 17, 2020
@ikedas ikedas changed the title Issue when upgrade from 6.2.52 to 6.2.54 : Mail loop with sympa-request address because of misconfiguration Sep 17, 2020
ikedas added a commit to ikedas/sympa that referenced this issue Sep 19, 2020
…pa-community#957)

<sympa-request> address should not be forwarded to any functions of Sympa.  To avoid mail loop by such misconfiguration, discard messages bound for this address.
@ikedas
Copy link
Member

ikedas commented Sep 19, 2020

@jth56000 , could you please apply this patch and check if the problem will be dissaolved?
(Or, please check the next beta released in the next week.)

@ikedas ikedas added the ready A PR is waiting to be merged. Close to be solved label Sep 19, 2020
ikedas added a commit to ikedas/sympa that referenced this issue Sep 19, 2020
…pa-community#957)

<sympa-request> address should not be forwarded to any functions of Sympa.  To avoid mail loop by such misconfiguration, discard messages bound for this address.
ikedas added a commit that referenced this issue Sep 22, 2020
Mail loop with sympa-request address because of misconfiguration (#957)
@ikedas ikedas removed the ready A PR is waiting to be merged. Close to be solved label Sep 22, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants