"""The outbox: queue, send, retry, rate limit and restart safety (AD-11).""" import logging from datetime import timedelta import pytest from django.core.management import call_command from django.db import transaction from django.utils import timezone from portal.mailer import services from portal.mailer.models import OutboxMail pytestmark = pytest.mark.django_db(transaction=True) Status = OutboxMail.Status def queue(recipient="lena@example.test", n=1): return [services.enqueue("test", recipient) for _ in range(n)][-1] # -- queueing ----------------------------------------- def test_enqueue_renders_the_mail_in_formal_german(): mail = queue() assert mail.status == Status.QUEUED and mail.attempts == 0 assert mail.subject == "Test-E-Mail vom Portal" assert "Wenn Sie sie lesen können" in mail.body_text def test_the_language_of_the_request_does_not_change_the_mail(): from django.utils import translation with translation.override("en"): assert queue().subject == "Test-E-Mail vom Portal" @pytest.mark.parametrize( "address", ["", "nobody", "a@b", "a b@example.test", "a@example.test\r\nBcc: x@evil.test", ""], ) def test_an_unusable_address_is_refused_and_nothing_is_queued(address): with pytest.raises(ValueError, match="e-mail address"): services.enqueue("test", address) assert OutboxMail.objects.count() == 0 def test_a_rolled_back_change_queues_nothing(): with pytest.raises(RuntimeError), transaction.atomic(): queue() raise RuntimeError("the change failed") assert OutboxMail.objects.count() == 0 # -- sending ----------------------------------------- def test_flush_sends_a_queued_mail_and_removes_its_text(adapters): mail = queue() result = services.flush() mail.refresh_from_db() assert (result.sent, result.retried, result.failed) == (1, 0, 0) assert mail.status == Status.SENT and mail.sent_at and mail.attempts == 1 assert mail.body_text == "" # a one-time link must not stay in the database sent = adapters.mailer.sent[0] assert sent.recipient == "lena@example.test" and sent.sender == "Portal " assert "Test-E-Mail" in sent.subject and "Test-E-Mail" in sent.body_text def test_a_mail_is_never_sent_twice(adapters): queue() services.flush() services.flush() services.flush(timezone.now() + timedelta(days=1)) assert len(adapters.mailer.sent) == 1 def test_a_mail_that_is_not_due_yet_waits(adapters): mail = queue() later = timezone.now() + timedelta(hours=1) OutboxMail.objects.filter(pk=mail.pk).update(next_attempt_at=later) services.flush() assert adapters.mailer.sent == [] def test_mails_are_sent_in_the_order_they_were_queued(adapters): for name in ("a", "b", "c"): queue(f"{name}@example.test") services.flush() assert [m.recipient for m in adapters.mailer.sent] == [f"{n}@example.test" for n in "abc"] # -- failures ----------------------------------------- def test_a_temporary_failure_is_retried_later_with_a_growing_wait(adapters): mail = queue() adapters.mailer.unavailable = True now = timezone.now() waits = [] for attempt in range(1, 5): result = services.flush(now) mail.refresh_from_db() assert result.retried == 1 and mail.status == Status.QUEUED and mail.attempts == attempt assert mail.last_error waits.append(mail.next_attempt_at - now) now = mail.next_attempt_at assert waits == [timedelta(seconds=s) for s in services.BACKOFF_SECONDS] assert waits == sorted(waits) def test_a_retry_before_the_wait_is_over_does_nothing(adapters): mail = queue() adapters.mailer.unavailable = True now = timezone.now() services.flush(now) attempts = adapters.mailer.attempts services.flush(now + timedelta(seconds=30)) assert adapters.mailer.attempts == attempts mail.refresh_from_db() assert mail.attempts == 1 def test_a_mail_that_works_on_a_retry_is_sent(adapters): mail = queue() adapters.mailer.unavailable = True now = timezone.now() services.flush(now) adapters.mailer.unavailable = False mail.refresh_from_db() result = services.flush(mail.next_attempt_at) mail.refresh_from_db() assert result.sent == 1 and mail.status == Status.SENT and mail.attempts == 2 def test_after_the_last_attempt_the_mail_is_failed_and_kept_for_the_admin(adapters): mail = queue() adapters.mailer.unavailable = True now = timezone.now() for _ in range(services.MAX_ATTEMPTS): services.flush(now) mail.refresh_from_db() now = mail.next_attempt_at assert mail.status == Status.FAILED and mail.attempts == services.MAX_ATTEMPTS assert mail.recipient == "lena@example.test" and mail.last_error and mail.body_text == "" attempts = adapters.mailer.attempts services.flush(now + timedelta(days=1)) assert adapters.mailer.attempts == attempts # no further tries def test_a_permanent_refusal_fails_at_once_without_retries(adapters): mail = queue("gone@example.test") adapters.mailer.rejected.add("gone@example.test") result = services.flush() mail.refresh_from_db() assert result.failed == 1 and mail.status == Status.FAILED and mail.attempts == 1 assert "550" in mail.last_error def test_one_refused_mail_does_not_block_the_others(adapters): queue("gone@example.test") queue("lena@example.test") adapters.mailer.rejected.add("gone@example.test") result = services.flush() assert (result.sent, result.failed) == (1, 1) def test_a_dead_server_is_not_tried_for_every_mail_in_the_queue(adapters): for i in range(10): queue(f"u{i}@example.test") adapters.mailer.unavailable = True services.flush() assert adapters.mailer.attempts == services.STOP_AFTER_CONSECUTIVE_OUTAGES # -- rate limit ----------------------------------------- def test_no_more_than_the_rate_limit_is_sent_per_minute(adapters): for i in range(services.RATE_PER_MINUTE + 5): queue(f"u{i}@example.test") now = timezone.now() assert services.flush(now).sent == services.RATE_PER_MINUTE assert services.flush(now + timedelta(seconds=30)).sent == 0 assert services.flush(now + timedelta(seconds=61)).sent == 5 assert len(adapters.mailer.sent) == services.RATE_PER_MINUTE + 5 # -- restarts ----------------------------------------- def test_a_mail_cut_off_while_sending_is_given_up_not_sent_again(adapters): mail = queue() now = timezone.now() OutboxMail.objects.filter(pk=mail.pk).update( status=Status.SENDING, claimed_at=now - timedelta(seconds=services.LEASE_SECONDS + 1) ) result = services.flush(now) mail.refresh_from_db() assert mail.status == Status.FAILED and "unknown" in mail.last_error assert result.sent == 0 and adapters.mailer.sent == [] def test_a_mail_being_sent_right_now_is_left_alone(adapters): mail = queue() now = timezone.now() OutboxMail.objects.filter(pk=mail.pk).update(status=Status.SENDING, claimed_at=now) services.flush(now) mail.refresh_from_db() assert mail.status == Status.SENDING and adapters.mailer.sent == [] def test_a_row_taken_by_another_run_is_skipped(adapters, monkeypatch): mail = queue() real = OutboxMail.objects.filter def take_first(*args, **kwargs): # The moment the claim is attempted, another run has already taken the row. if kwargs.get("pk") == mail.pk: real(pk=mail.pk).update(status=Status.SENDING) return real(*args, **kwargs) monkeypatch.setattr(OutboxMail.objects, "filter", take_first) assert services.flush().sent == 0 assert adapters.mailer.sent == [] # -- privacy ----------------------------------------- def test_logs_name_the_row_but_not_the_recipient_or_text(adapters, caplog): queue("secret.person@example.test") adapters.mailer.unavailable = True with caplog.at_level(logging.DEBUG): services.flush() assert "not sent" in caplog.text assert "secret.person" not in caplog.text and "Test-E-Mail" not in caplog.text # -- the test command ----------------------------------------- def test_the_test_command_sends_a_mail_now(adapters, capsys): call_command("send_test_mail", "lena@example.test") assert "sent" in capsys.readouterr().out assert [m.recipient for m in adapters.mailer.sent] == ["lena@example.test"] def test_the_test_command_reports_a_failure(adapters, capsys): adapters.mailer.unavailable = True with pytest.raises(SystemExit) as stop: call_command("send_test_mail", "lena@example.test") assert stop.value.code == 1 assert "retried" in capsys.readouterr().out def test_the_test_command_refuses_a_bad_address(adapters): from django.core.management.base import CommandError with pytest.raises(CommandError): call_command("send_test_mail", "not-an-address")