Sending bulk email triggers SMTPRecipientsRefused error

@regis

Greetings,

I have this error detected and corrected in the native installation of open edx.

The error happens when the email is formed, when creating the sender it concatenates the course code to the email. So when sending the mail, the function that generates the mail sends this address also as a variable for the smtp connection.

I send you a fragment of the log in tutor version lilac.1 and what file I edit and function I modify to fix this problem (31 line)

The file I edit is:
/edx/app/edxapp/edx-platform/lms/djangoapps/bulk_email/tasks.py

and the line (407 approx) that I edit is

from_addr = format_address (course_title_no_quotes)

and I modify it with:

from_addr = settings.BULK_EMAIL_DEFAULT_FROM_EMAIL

this is my blog (spanish)

But the problem is that I don’t know how to correct it in a tutor or how to fix it, I’m just getting into a tutor.

@sbernesto I moved your response to a new topic, because your error is different from that other one.

I did not observe the same problem when I enabled bulk emails. Can you please describe more precisely how to reproduce? What steps should I follow?

hi,

What I have configured is the following:

  1. plugin to enable sending from an email account
name: email_account
version: 0.1.0
patches:
 lms-env: |
         "EMAIL_HOST_PASSWORD": "PASSWORD",
         "EMAIL_HOST_USER": "sbernesto@mail.com",
         "EMAIL_HOST": "mail.com",
         "EMAIL_PORT": 465,
         "EMAIL_USE_TLS": true
  1. In admin / bulk_email / bulkemailflag I add the active flag

  2. I have this error in the control panel

  3. In the logs i doesn’t have error, i think

lms_1            | 2021-09-06 21:22:08,490 INFO 121 [tracking] [user 3] [ip 172.16.10.1] logger.py:41 - {"name": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/send_email", "context": {"course_id": "course-v1:edX+DemoX+Demo_Course", "course_user_tags": {}, "user_id": 3, "path": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/send_email", "org_id": "edX"}, "username": "sbernesto", "session": "a2e3f66c7ac76edcd1eeb955971f229f", "ip": "172.16.10.1", "agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/93.0.4577.63 Safari/537.36", "host": "edxlilac.bunited.local", "referer": "http://edxlilac.bunited.local/courses/course-v1:edX+DemoX+Demo_Course/instructor", "accept_language": "es-ES,es;q=0.9", "event": "{\"GET\": {}, \"POST\": {\"action\": [\"send\"], \"send_to\": [\"[\\\"myself\\\"]\"], \"subject\": [\"asdasdsadasdasdasdsadasdasdasds\"], \"message\": [\"<pre class=\\\"tw-data-text tw-text-large XcVN5d tw-ta\\\" data-placeholder=\\\"Traducci\\u00f3n\\\" id=\\\"tw-target-text\\\" dir=\\\"ltr\\\" style=\\\"font-family: inherit; unicode-bidi: isolate; font-size: 28px; line-height: 36px; background-color: #f8f9fa; border: none; padding: 2px 0.14em 2px 0px; position: relative; margin-top: -2px; margin-bottom: -2px; resize: none; overflow: hidden; width", "time": "2021-09-06T21:22:08.490065+00:00", "event_type": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/send_email", "event_source": "server", "page": null}
lms_1            | 2021-09-06 21:22:08,546 WARNING 121 [lms.djangoapps.instructor_task.api_helper] [user 3] [ip 172.16.10.1] api_helper.py:89 - No duplicate tasks found: task_type bulk_course_email, task_key e4da3b7fbbce2345d7772b0674a318d5, and most recent task_id = 6
lms_1            | [pid: 121|app: 0|req: 16/194] 172.18.0.16 () {54 vars in 3489 bytes} [Mon Sep  6 21:22:08 2021] POST /courses/course-v1:edX+DemoX+Demo_Course/instructor/api/send_email => generated 71 bytes in 121 msecs (HTTP/1.0 200) 9 headers in 584 bytes (1 switches on core 0)
lms_1            | 2021-09-06 21:22:14,492 INFO 117 [tracking] [user 3] [ip 172.16.10.1] logger.py:41 - {"name": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "context": {"course_id": "course-v1:edX+DemoX+Demo_Course", "course_user_tags": {}, "user_id": 3, "path": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "org_id": "edX"}, "username": "sbernesto", "session": "a2e3f66c7ac76edcd1eeb955971f229f", "ip": "172.16.10.1", "agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/93.0.4577.63 Safari/537.36", "host": "edxlilac.bunited.local", "referer": "http://edxlilac.bunited.local/courses/course-v1:edX+DemoX+Demo_Course/instructor", "accept_language": "es-ES,es;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2021-09-06T21:22:14.492716+00:00", "event_type": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "event_source": "server", "page": null}
lms_1            | [pid: 117|app: 0|req: 17/195] 172.18.0.16 () {52 vars in 3445 bytes} [Mon Sep  6 21:22:14 2021] POST /courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks => generated 17 bytes in 36 msecs (HTTP/1.0 200) 9 headers in 584 bytes (1 switches on core 0)
lms_1            | 2021-09-06 21:22:19,070 INFO 120 [tracking] [user 3] [ip 172.16.10.1] logger.py:41 - {"name": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "context": {"course_id": "course-v1:edX+DemoX+Demo_Course", "course_user_tags": {}, "user_id": 3, "path": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "org_id": "edX"}, "username": "sbernesto", "session": "a2e3f66c7ac76edcd1eeb955971f229f", "ip": "172.16.10.1", "agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/93.0.4577.63 Safari/537.36", "host": "edxlilac.bunited.local", "referer": "http://edxlilac.bunited.local/courses/course-v1:edX+DemoX+Demo_Course/instructor", "accept_language": "es-ES,es;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2021-09-06T21:22:19.070585+00:00", "event_type": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "event_source": "server", "page": null}
lms_1            | [pid: 120|app: 0|req: 16/196] 172.18.0.16 () {52 vars in 3445 bytes} [Mon Sep  6 21:22:19 2021] POST /courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks => generated 17 bytes in 34 msecs (HTTP/1.0 200) 9 headers in 584 bytes (1 switches on core 0)
lms_1            | 2021-09-06 21:22:28,481 INFO 116 [tracking] [user 3] [ip 172.16.10.1] logger.py:41 - {"name": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_background_email_tasks", "context": {"course_id": "course-v1:edX+DemoX+Demo_Course", "course_user_tags": {}, "user_id": 3, "path": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_background_email_tasks", "org_id": "edX"}, "username": "sbernesto", "session": "a2e3f66c7ac76edcd1eeb955971f229f", "ip": "172.16.10.1", "agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/93.0.4577.63 Safari/537.36", "host": "edxlilac.bunited.local", "referer": "http://edxlilac.bunited.local/courses/course-v1:edX+DemoX+Demo_Course/instructor", "accept_language": "es-ES,es;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2021-09-06T21:22:28.481331+00:00", "event_type": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_background_email_tasks", "event_source": "server", "page": null}
lms_1            | [pid: 116|app: 0|req: 16/197] 172.18.0.16 () {52 vars in 3457 bytes} [Mon Sep  6 21:22:28 2021] POST /courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_background_email_tasks => generated 1444 bytes in 83 msecs (HTTP/1.0 200) 9 headers in 586 bytes (1 switches on core 0)
lms_1            | 2021-09-06 21:22:34,496 INFO 7 [tracking] [user 3] [ip 172.16.10.1] logger.py:41 - {"name": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "context": {"course_id": "course-v1:edX+DemoX+Demo_Course", "course_user_tags": {}, "user_id": 3, "path": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "org_id": "edX"}, "username": "sbernesto", "session": "a2e3f66c7ac76edcd1eeb955971f229f", "ip": "172.16.10.1", "agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/93.0.4577.63 Safari/537.36", "host": "edxlilac.bunited.local", "referer": "http://edxlilac.bunited.local/courses/course-v1:edX+DemoX+Demo_Course/instructor", "accept_language": "es-ES,es;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2021-09-06T21:22:34.496076+00:00", "event_type": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "event_source": "server", "page": null}
lms_1            | [pid: 7|app: 0|req: 15/198] 172.18.0.16 () {52 vars in 3445 bytes} [Mon Sep  6 21:22:34 2021] POST /courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks => generated 17 bytes in 44 msecs (HTTP/1.0 200) 9 headers in 584 bytes (1 switches on core 0)
lms_1            | 2021-09-06 21:22:39,088 INFO 118 [tracking] [user 3] [ip 172.16.10.1] logger.py:41 - {"name": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "context": {"course_id": "course-v1:edX+DemoX+Demo_Course", "course_user_tags": {}, "user_id": 3, "path": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "org_id": "edX"}, "username": "sbernesto", "session": "a2e3f66c7ac76edcd1eeb955971f229f", "ip": "172.16.10.1", "agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/93.0.4577.63 Safari/537.36", "host": "edxlilac.bunited.local", "referer": "http://edxlilac.bunited.local/courses/course-v1:edX+DemoX+Demo_Course/instructor", "accept_language": "es-ES,es;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2021-09-06T21:22:39.086132+00:00", "event_type": "/courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks", "event_source": "server", "page": null}
lms_1            | [pid: 118|app: 0|req: 17/199] 172.18.0.16 () {52 vars in 3445 bytes} [Mon Sep  6 21:22:39 2021] POST /courses/course-v1:edX+DemoX+Demo_Course/instructor/api/list_instructor_tasks => generated 17 bytes in 58 msecs (HTTP/1.0 200) 9 headers in 584 bytes (1 switches on core 0)

Tutor version tutor, version 12.0.4

What I see that in this version I no longer see the same error in the log, but the capture shows, error when sending the mail.

This is not the right way to configure a different smtp server in Tutor. Please check the docs: Configuration and customisation — Tutor documentation Also, check other topics in this forum.

Hello there,
I have followed the pages and settings you mentioned to me, but I still have that error. The weirdest thing is that if I do the command

local tutor logs lms -f

I don’t see the error, I only managed to see the error if I went directly to the container and opened the log file.

I am attaching a fragment of the error and if you can see the same error that I put in the first post, which attaches the email address and the course id

2021-09-07 15:48:19,284 INFO 108 [edx.celery.task] [user None] [ip None] tasks.py:466 - BulkEmail ==> Task: 2cdd2a05-c299-4f11-aebd-396423d37a9b, SubTask: c4cf1575-a79f-40a3-9c5b-b2afa82e07bd, EmailId: 8, TotalRecipients: 1
2021-09-07 15:48:19,907 INFO 108 [edx.celery.task] [user None] [ip None] tasks.py:570 - BulkEmail ==> Task: 2cdd2a05-c299-4f11-aebd-396423d37a9b, SubTask: c4cf1575-a79f-40a3-9c5b-b2afa82e07bd, EmailId: 8, Recipient num: 1/1,                     Recipient name: Ernesto Sánchez Benitez, Email address: sbernesto@bunited.mx
2021-09-07 15:48:20,174 ERROR 108 [edx.celery.task] [user None] [ip None] tasks.py:699 - Task c4cf1575-a79f-40a3-9c5b-b2afa82e07bd: email with id 8 caused send_course_email task to fail with u"fatal" exception.  1 emails unsent.
Traceback (most recent call last):
  File "/openedx/edx-platform/lms/djangoapps/bulk_email/tasks.py", line 581, in _send_course_email
    connection.send_messages([email_msg])
  File "/openedx/venv/lib/python3.8/site-packages/django/core/mail/backends/smtp.py", line 110, in send_messages
    sent = self._send(message)
  File "/openedx/venv/lib/python3.8/site-packages/django/core/mail/backends/smtp.py", line 126, in _send
    self.connection.sendmail(from_email, recipients, message.as_bytes(linesep='\r\n'))
  File "/opt/pyenv/versions/3.8.6/lib/python3.8/smtplib.py", line 885, in sendmail
    raise SMTPRecipientsRefused(senderrs)
smtplib.SMTPRecipientsRefused: {'sbernesto@bunited.mx': (550, b'Verification failed for <BU-001-sbernesto@bunited.mx>\nNo Such User Here\nSender verify failed')}
2021-09-07 15:48:20,264 INFO 108 [edx.celery.task] [user None] [ip None] tasks.py:304 - BulkEmail ==> _send_course_email completed in : 0.9805021286010742 for task : c4cf1575-a79f-40a3-9c5b-b2afa82e07bd with recipient count: 1
2021-09-07 15:48:20,264 ERROR 108 [edx.celery.task] [user None] [ip None] tasks.py:332 - Send-email task c4cf1575-a79f-40a3-9c5b-b2afa82e07bd for email 8: failed: {'sbernesto@bunited.mx': (550, b'Verification failed for <BU-001-sbernesto@bunited.mx>\nNo Such User Here\nSender verify failed')}
2021-09-07 15:48:20,265 INFO 108 [edx.celery.task] [user None] [ip None] subtasks.py:520 - Preparing to update status for subtask c4cf1575-a79f-40a3-9c5b-b2afa82e07bd for instructor task 10 with status SubtaskStatus<{'task_id': 'c4cf1575-a79f-40a3-9c5b-b2afa82e07bd', 'attempted': 1, 'succeeded': 0, 'failed': 1, 'skipped': 0, 'retried_nomax': 0, 'retried_withmax': 0, 'state': 'FAILURE'}>
2021-09-07 15:48:20,270 INFO 108 [edx.celery.task] [user None] [ip None] subtasks.py:576 - Task output updated to {"action_name": "emailed", "attempted": 1, "failed": 1, "skipped": 0, "succeeded": 0, "total": 1, "duration_ms": 1024, "start_time": 1631029699.2427282} for subtask c4cf1575-a79f-40a3-9c5b-b2afa82e07bd of instructor task 10
2021-09-07 15:48:20,275 ERROR 108 [celery.app.trace] [user None] [ip None] trace.py:255 - Task lms.djangoapps.bulk_email.tasks.send_course_email[c4cf1575-a79f-40a3-9c5b-b2afa82e07bd] raised unexpected: SMTPRecipientsRefused({'sbernesto@bunited.mx': (550, b'Verification failed for <BU-001-sbernesto@bunited.mx>\nNo Such User Here\nSender verify failed')})
Traceback (most recent call last):
  File "/openedx/venv/lib/python3.8/site-packages/celery/app/trace.py", line 412, in trace_task
    R = retval = fun(*args, **kwargs)
  File "/openedx/venv/lib/python3.8/site-packages/celery/app/trace.py", line 704, in __protected_call__
    return self.run(*args, **kwargs)
  File "/openedx/venv/lib/python3.8/site-packages/edx_django_utils/monitoring/internal/code_owner/utils

I do not know what settings you should use for your specific SMTP provider (bunited.mx) so I am unable to help you further here :-/

This problem occurs regardless of the smtp service provider be it gmail or gsuite, office365, etc. I have only had no problems if I use a specialized service like turbosmtp.

Looks like the problem comes from your destination email address: the “sbernesto@bunited.mx” address triggers the “No Such User Here” error. You should try with a different email address.

The problem I see is that when it generates the sender it is generated in the following way: course_name + from_email, then somewhere in the code.

User authentication is lost because it uses this variable format_address(course_title_no_quotes) instead of using settings.BULK_EMAIL_DEFAULT_FROM_EMAIL, this problem is more explicit if you use an smtp that is not because in this it shows you that the mail does not exist

(550, b’Verification failed for BU-001-sbernesto@bunited.mx \ nNo Such User Here \ nSender verify failed ')}

Since when using outlook or gmail smtp they only log the authentication error and it does not show that the function is trying to authenticate with a user that does not exist, as it does with a third-party smtp.

About the configuration, I am using the configuration that comes in the documentation that you shared with me.

Right! I finally understand your problem. Sorry it took me such a long while to understand your explanations.

To recap, when I tested the bulk email feature locally, in the demo course, I received an email from “DemoX-contact@local.overhang.io”. This sender is obviously going to fail user verification in many cases. (in particular when using a custom SMTP server)

I see the following piece of code in edx-platform:

# If EMAIL_USE_DEFAULT_FROM_FOR_BULK is True, use the default email from address.
# Otherwise compute a custom from address
if is_email_use_default_from_bulk_enabled():
    from_addr = settings.DEFAULT_FROM_EMAIL
else:
    # use the email from address in the CourseEmail, if it is present, otherwise compute it.
    from_addr = course_email.from_addr or _get_source_address(course_email.course_id, course_title, course_language)

Thus, a temporary fix would be for you to enable the EMAIL_USE_DEFAULT_FROM_FOR_BULK toggle. In that case, the “from” address will correspond to settings.DEFAULT_FROM_EMAIL.

Still, I believe that there is an upstream bug in edx-platform:

  1. The EMAIL_USE_DEFAULT_FROM_FOR_BULK toggle should default to True, because this is what most people need.
  2. When this toggle is True, the “from” address should default to settings.DEFAULT_FROM_EMAIL only if settings.BULK_EMAIL_DEFAULT_FROM_EMAIL is undefined. In other words:
if is_email_use_default_from_bulk_enabled():
    from_addr = settings.BULK_EMAIL_DEFAULT_FROM_EMAIL or settings.DEFAULT_FROM_EMAIL
else:
    ...

I’ll open an issue in the BTR Board.

EDIT: here is the issue Bulk course emails are rejected by email server because of an invalid "from" address · Issue #102 · openedx/build-test-release-wg · GitHub