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

Clean up send error handling; fix stalled send queue. #78

Closed
wants to merge 1 commit into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
34 changes: 25 additions & 9 deletions mailer/engine.py
Original file line number Diff line number Diff line change
Expand Up @@ -12,8 +12,7 @@
from django.core.mail.message import make_msgid

from mailer.models import (
Message, MessageLog, RESULT_SUCCESS, RESULT_FAILURE, get_message_id,
)
Message, MessageLog, RESULT_SUCCESS, RESULT_FAILURE, RESULT_ERROR, get_message_id)


# when queue is empty, how long to wait (in seconds) before checking again
Expand Down Expand Up @@ -103,7 +102,7 @@ def release_lock(lock):
logging.debug("released.")


def send_all():
def send_all(): # noqa: C901 # TODO: refactor to reduce complexity
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm personally not that worried about complexity here - I don't think clarity would be increased that much by refactoring it.

"""
Send all eligible messages in the queue.
"""
Expand All @@ -122,6 +121,7 @@ def send_all():
start_time = time.time()

deferred = 0
errored = 0
sent = 0

try:
Expand Down Expand Up @@ -154,19 +154,35 @@ def send_all():
logging.warning("message discarded due to failure in converting from DB. Added on '%s' with priority '%s'" % (message.when_added, message.priority)) # noqa
message.delete()

except (socket_error, smtplib.SMTPSenderRefused,
smtplib.SMTPRecipientsRefused,
smtplib.SMTPDataError,
smtplib.SMTPAuthenticationError) as err:
except (smtplib.SMTPConnectError,
smtplib.SMTPServerDisconnected) as err:
# Connection-related problem -- try again soon:
logging.info("message left queued due to transient failure: %s" % err)
MessageLog.objects.log(message, RESULT_FAILURE, log_message=str(err))
break # connectivity issue; resume batch next time

except (socket_error, # includes smtplib.SMTPException in python3.4+
# TODO: consider handling socket_error/OSError/IOError as "retry soon"???
smtplib.SMTPException) as err:
# Destination/recipient-related problem -- try again later:
message.defer()
logging.info("message deferred due to failure: %s" % err)
MessageLog.objects.log(message, RESULT_FAILURE, log_message=str(err))
deferred += 1
# Get new connection, it case the connection itself has an error.
connection = None

except Exception as err:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

New to the party but why are you deleting these instead of deferring them too? Seems like a harsh thing to force on people not using SMTPlibs.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the "deferring permanent errors isn't helpful, and can lead to other problems" case discussed in #73. IIRC, one of the reasons I didn't follow through with this PR is that it's not at all clear how to reliably distinguish "transient error, should defer and retry later" from "permanent error, retry won't be helpful". More discussion in #73.

If you have an idea for an approach that would work well with a variety of email backends, it'd be awesome to have someone adopt this PR and drive it to completion.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry, missed the "other problems" and that is indeed a concern. Thanks for the update, I had read that you were stepping away from the project so I appreciate the comment.

# Content-specific (or unknown) problem -- don't retry this message:
logging.info("message discarded due to error: %s" % err)
MessageLog.objects.log(message, RESULT_ERROR, log_message=str(err))
message.delete()
errored += 1
# Get new connection, it case the connection itself has an error.
connection = None

# Check if we reached the limits for the current run
if _limits_reached(sent, deferred):
if _limits_reached(sent, deferred): # TODO: add limits for errored???
break

_throttle_emails()
Expand All @@ -175,7 +191,7 @@ def send_all():
release_lock(lock)

logging.info("")
logging.info("%s sent; %s deferred;" % (sent, deferred))
logging.info("%s sent; %s deferred; %s errored" % (sent, deferred, errored))
logging.info("done in %.2f seconds" % (time.time() - start_time))


Expand Down
4 changes: 3 additions & 1 deletion mailer/models.py
Original file line number Diff line number Diff line change
Expand Up @@ -236,11 +236,13 @@ class Meta:
RESULT_SUCCESS = "1"
RESULT_DONT_SEND = "2"
RESULT_FAILURE = "3"
RESULT_ERROR = "4"

RESULT_CODES = (
(RESULT_SUCCESS, "success"),
(RESULT_DONT_SEND, "don't send"),
(RESULT_FAILURE, "failure"),
(RESULT_FAILURE, "failure (retryable)"),
(RESULT_ERROR, "error (non-retryable)"),
# @@@ other types of failure?
)

Expand Down
64 changes: 62 additions & 2 deletions mailer/tests.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,8 +18,8 @@

import mailer
from mailer import engine
from mailer.models import (PRIORITY_DEFERRED, PRIORITY_HIGH, PRIORITY_LOW,
PRIORITY_MEDIUM, RESULT_FAILURE, RESULT_SUCCESS,
from mailer.models import (PRIORITY_DEFERRED, PRIORITY_HIGH, PRIORITY_LOW, PRIORITY_MEDIUM,
RESULT_FAILURE, RESULT_ERROR, RESULT_SUCCESS,
DontSendEntry, Message, MessageLog, db_to_email,
email_to_db, make_message)

Expand Down Expand Up @@ -105,6 +105,66 @@ def test_retry_deferred(self):
self.assertEqual(len(mail.outbox), 1)
self.assertEqual(Message.objects.count(), 0)

def test_deferrable_send_errors(self):
"""
Test that specific send errors are treated as deferrals
"""
for deferrable_error in [
smtplib.SMTPSenderRefused(530, "Unauthorized sender", "from@example.com"),
smtplib.SMTPRecipientsRefused({"to@example.com": (422, "Mailbox full")}),
smtplib.SMTPDataError(501, "Syntax error"),
smtplib.SMTPAuthenticationError(530, "Invalid username/password"),
]:
with self.settings(MAILER_EMAIL_BACKEND="mailer.tests.FailingMailerEmailBackend"):
with patch("mailer.tests.FailingMailerEmailBackend", side_effect=deferrable_error):
mailer.send_mail("Subject", "Body", "from@example.com", ["to@example.com"])
engine.send_all()

# Should be deferred and logged
self.assertEqual(Message.objects.count(), 1)
self.assertEqual(Message.objects.deferred().count(), 1)
self.assertEqual(MessageLog.objects.count(), 1)

Message.objects.all().delete()
MessageLog.objects.all().delete()

def test_transient_send_errors(self):
"""
Test that temporary errors cleanly exit send, leaving queue intact
"""
with self.settings(MAILER_EMAIL_BACKEND="mailer.tests.FailingMailerEmailBackend"):
with patch("mailer.tests.FailingMailerEmailBackend",
side_effect=smtplib.SMTPConnectError(421, "Down for maintenance")
) as send_patch:
mailer.send_mail("Subject", "Body", "from@example.com", ["to1@example.com"])
mailer.send_mail("Subject", "Body", "from@example.com", ["to2@example.com"])
self.assertEqual(Message.objects.count(), 2)
engine.send_all()
send_patch.assert_called_once()

# Should both still be pending
self.assertEqual(Message.objects.count(), 2)

# And should have logged the failure
self.assertEqual(MessageLog.objects.count(), 1)
self.assertEqual(MessageLog.objects.all()[0].result, RESULT_FAILURE)

def test_unexpected_send_errors(self):
"""
Test that messages with permanent content errors don't stall send queue
"""
with self.settings(MAILER_EMAIL_BACKEND="mailer.tests.FailingMailerEmailBackend"):
with patch("mailer.tests.FailingMailerEmailBackend", side_effect=UnicodeDecodeError):
mailer.send_mail("Subject", "Body", "from@example.com", ["to@example.com"])
engine.send_all()

# Should not be pending or deferred
self.assertEqual(Message.objects.count(), 0)

# But should have logged it as an error
self.assertEqual(MessageLog.objects.count(), 1)
self.assertEqual(MessageLog.objects.all()[0].result, RESULT_ERROR)

def test_purge_old_entries(self):
# Send one successfully
with self.settings(MAILER_EMAIL_BACKEND="django.core.mail.backends.locmem.EmailBackend"):
Expand Down