From 631b97b3780d12ff8553608975bdd0ef718f160f Mon Sep 17 00:00:00 2001 From: Karl Engelhardt Date: Wed, 30 Nov 2022 17:02:50 +0100 Subject: [PATCH] =?UTF-8?q?=E2=99=BB=EF=B8=8F=20Use=20new=20delivery=20rep?= =?UTF-8?q?orter?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- froide/conftest.py | 29 +-- froide/foirequest/delivery.py | 183 ------------------ .../0064_foimessage_confirmation_sent.py | 17 ++ froide/foirequest/models/message.py | 2 + froide/foirequest/signals.py | 102 +++++----- froide/foirequest/tests/test_api.py | 11 -- .../foirequest/tests/test_delivery_report.py | 42 ---- froide/foirequest/tests/test_request.py | 62 +++--- froide/settings.py | 1 - pytest.ini | 2 + 10 files changed, 127 insertions(+), 324 deletions(-) delete mode 100644 froide/foirequest/delivery.py create mode 100644 froide/foirequest/migrations/0064_foimessage_confirmation_sent.py delete mode 100644 froide/foirequest/tests/test_delivery_report.py diff --git a/froide/conftest.py b/froide/conftest.py index f73445d62..302546fb0 100644 --- a/froide/conftest.py +++ b/froide/conftest.py @@ -7,8 +7,8 @@ from pytest_factoryboy import register from froide.account.factories import UserFactory -from froide.foirequest import delivery -from froide.foirequest.delivery import DeliveryReport +from froide.foirequest.models import FoiMessage, FoiRequest +from froide.foirequest.signals import email_left_queue from froide.foirequest.tests.factories import ( FoiMessageFactory, FoiProjectFactory, @@ -85,13 +85,20 @@ def email_always_send(monkeypatch, request): """Instantly mark all messages as delivered""" if "no_delivery_mock" in request.keywords: return - monkeypatch.setattr( - delivery, - "get_delivery_report", - lambda *_args, **_kwargs: DeliveryReport( - log="loglines", - time_diff=None, + + def deliver_send_messages(sender, message: FoiMessage, **kwargs): + email_left_queue.send( + sender=sender, + to=message.recipient_email, + from_address=message.sender_email, + message_id=message.email_message_id, status="sent", - message_id="message_id", - ), - ) + log=[], + ) + + FoiRequest.message_sent.connect(deliver_send_messages) + + def remove_signal_handler(): + FoiRequest.message_sent.disconnect(deliver_send_messages) + + request.addfinalizer(remove_signal_handler) diff --git a/froide/foirequest/delivery.py b/froide/foirequest/delivery.py deleted file mode 100644 index 339d3012b..000000000 --- a/froide/foirequest/delivery.py +++ /dev/null @@ -1,183 +0,0 @@ -import gzip -import io -import logging -import os -import re -import time -from collections import defaultdict, namedtuple -from datetime import datetime - -from django.utils import timezone - -from froide.helper.utils import get_module_attr_from_dotted_path - - -def get_delivery_report(sender, recipient, timestamp, extended=False): - reporter = get_delivery_reporter() - if reporter: - return reporter.find(sender, recipient, timestamp, extended=extended) - else: - return - - -def get_delivery_reporter(): - from django.conf import settings - - reporter_path = settings.FROIDE_CONFIG.get("delivery_reporter", None) - if not reporter_path: - return - - reporter_klass = get_module_attr_from_dotted_path(reporter_path) - reporter = reporter_klass(timezone=timezone.get_current_timezone()) - return reporter - - -DeliveryReport = namedtuple( - "DeliveryReport", ["log", "time_diff", "status", "message_id"] -) - - -class PostfixDeliveryReporter(object): - SENDER_RE = r"\s(?P\w+): from=<{sender}" - MESSAGE_ID_RE = r"{mail_id}: message-id=<(?P[^>]+)>" - ALL_RE = r" {mail_id}: " - RECIPIENT_RE = r"{mail_id}: to=<{recipient}" - STATUS_RE = re.compile(r"status=(\w+)") - MAIL_ID_DELIMITER = re.compile(r"(: removed)") - TIMESTAMP_RE = re.compile(r"\w{3}\s+\d+\s+\d+:\d+:\d+") - TIME_PARSE_STR = "%b %d %H:%M:%S" - - LOG_FILES = [ - "/var/log/mail.log", - "/var/log/mail.log.1", - ] - LOG_FILES_EXTENDED = ["/var/log/mail.log.%d.gz" % i for i in range(2, 12)] - - def __init__(self, timezone=None): - self.timezone = timezone - - def get_log_files(self, extended=False): - for open_func, filename in self._get_files(extended): - if not os.path.exists(filename): - continue - try: - with open_func( - filename, mode="rt", errors="replace", encoding="utf-8" - ) as fp: - yield fp - except IOError as e: - logging.exception(e) - pass - - def _get_files(self, extended): - for f in self.LOG_FILES: - yield self._get_openfunc(f), f - if not extended: - return - for f in self.LOG_FILES_EXTENDED: - yield self._get_openfunc(f), f - - def _get_openfunc(self, filename): - if filename.endswith(".gz"): - return gzip.open - return io.open - - def find(self, sender, recipient, timestamp, extended=False): - sender = sender.strip() - recipient = recipient.strip() - for fp in self.get_log_files(extended): - result = self.search_log(fp, sender, recipient, timestamp) - if result: - return result - - def search_log(self, fp, sender, recipient, timestamp, real_file=True): - sender_re = re.compile(self.SENDER_RE.format(sender=sender)) - mail_ids = set() - for line in fp: - match = sender_re.search(line) - if match: - mail_ids.add(match.group("mail_id")) - - if real_file: - fp.seek(0) - - mail_id_res = [ - re.compile(self.ALL_RE.format(mail_id=mail_id)) for mail_id in mail_ids - ] - lines = defaultdict(list) - for line in fp: - for mail_id, mail_id_re in zip(mail_ids, mail_id_res): - if mail_id_re.search(line) is not None: - lines[mail_id].append(line) - - candidates = [] - for mail_id in mail_ids: - candidate = self.extract( - lines[mail_id], mail_id, sender_re, recipient, timestamp - ) - if candidate is not None: - candidates.append(candidate) - - if not candidates: - return None - if len(candidates) == 1: - return candidates[0] - candidates = sorted(candidates, key=lambda x: abs(x.time_diff)) - return candidates[0] - - def extract(self, lines, mail_id, sender_re, recipient, timestamp): - """ - postfix mail queue ids are not unique forever! - In case they happen to appear twice - in the same log file, split those sections apart. - """ - text = "".join(lines) - line_parts = self.MAIL_ID_DELIMITER.split(text) - texts = ["".join(x) for x in zip(line_parts[::2], line_parts[1::2])] - for text in texts: - result = self.extract_part(text, mail_id, sender_re, recipient, timestamp) - if result: - return result - - def extract_part(self, text, mail_id, sender_re, recipient, timestamp): - recipient_re = re.compile( - self.RECIPIENT_RE.format(mail_id=mail_id, recipient=recipient) - ) - match = recipient_re.search(text) - if match is None: - return - log_timestamp = self.get_timestamp(text, timestamp) - time_diff = (log_timestamp - timestamp).total_seconds() - if time_diff < -5: - # Log can't be before sending timestamp, allow for some overlap - return - message_id_re = re.compile(self.MESSAGE_ID_RE.format(mail_id=mail_id)) - - match = self.STATUS_RE.findall(text) - status = None - if match: - # find last status - status = match[-1] - - match = message_id_re.search(text) - message_id = None - if match: - message_id = match.group("message_id") - - return DeliveryReport(text, time_diff, status, message_id) - - def get_timestamp(self, text, timestamp): - match = self.TIMESTAMP_RE.search(text) - date_str = match.group(0) - - # use time.strptime, not datetime.strptime - # datetime.strptime would validate the date, which breaks on Feb 29 if date_str does not have year info - # since the default year is not a leap year - date_struct = time.strptime(date_str, self.TIME_PARSE_STR) - date_list = list(date_struct) - if ( - date_list[0] == 1900 - ): # 1900 is the default year for time.strptime, hence no year was present in date_str - date_list[0] = timestamp.year - date = datetime.fromtimestamp(time.mktime(tuple(date_list)), tz=self.timezone) - return date diff --git a/froide/foirequest/migrations/0064_foimessage_confirmation_sent.py b/froide/foirequest/migrations/0064_foimessage_confirmation_sent.py new file mode 100644 index 000000000..4e32cbbfb --- /dev/null +++ b/froide/foirequest/migrations/0064_foimessage_confirmation_sent.py @@ -0,0 +1,17 @@ +# Generated by Django 4.0.8 on 2022-11-30 13:19 + +from django.db import migrations, models + + +class Migration(migrations.Migration): + dependencies = [ + ("foirequest", "0063_alter_foirequest_costs"), + ] + + operations = [ + migrations.AddField( + model_name="foimessage", + name="confirmation_sent", + field=models.BooleanField(default=False, verbose_name="Confirmation sent?"), + ), + ] diff --git a/froide/foirequest/models/message.py b/froide/foirequest/models/message.py index 8ec0f957c..eb179d3f8 100644 --- a/froide/foirequest/models/message.py +++ b/froide/foirequest/models/message.py @@ -161,6 +161,8 @@ class FoiMessage(models.Model): ) tags = TaggableManager(through=TaggedMessage, verbose_name=_("tags"), blank=True) + confirmation_sent = models.BooleanField(_("Confirmation sent?"), default=False) + objects = FoiMessageManager() class Meta: diff --git a/froide/foirequest/signals.py b/froide/foirequest/signals.py index 8f86824d8..da9c2f3a2 100644 --- a/froide/foirequest/signals.py +++ b/froide/foirequest/signals.py @@ -197,51 +197,6 @@ def send_foiproject_created_confirmation(sender, **kwargs): ) -@receiver( - FoiRequest.message_delivered, dispatch_uid="send_foimessage_sent_confirmation" -) -def send_foimessage_sent_confirmation(sender, message: FoiMessage = None, **kwargs): - if message.is_not_email: - # All non-email sent messages are not interesting to users. - # Don't inform them about it. - return - if message.is_bulk: - # Don't notify on bulk message sending - return - - messages = sender.get_messages() - start_thread = False - if len(messages) == 1: - if sender.project_id is not None: - # Don't notify on first message in a project - return - subject = _("Your Freedom of Information Request was sent") - mail_intent = confirm_foi_request_sent_email - action_url = sender.get_absolute_domain_short_url() - start_thread = True - else: - subject = _("Your message was sent") - mail_intent = confirm_foi_message_sent_email - action_url = message.get_absolute_domain_short_url() - - upload_url = sender.user.get_autologin_url( - short_request_url("foirequest-upload_postal_message", sender) - ) - - context = { - "foirequest": sender, - "user": sender.user, - "publicbody": message.recipient_public_body, - "message": message, - "action_url": action_url, - "upload_action_url": upload_url, - } - - send_request_user_email( - mail_intent, sender, subject=subject, context=context, start_thread=start_thread - ) - - # Updating public body request counts @receiver( FoiRequest.request_to_public_body, dispatch_uid="foirequest_increment_request_count" @@ -488,3 +443,60 @@ def save_delivery_status( "last_update": timezone.now(), }, ) + + if status == "sent": + send_foimessage_sent_confirmation(message) + + +def send_foimessage_sent_confirmation(message: FoiMessage = None, **kwargs): + request = message.request + if message.is_not_email: + # All non-email sent messages are not interesting to users. + # Don't inform them about it. + return + if message.is_bulk: + # Don't notify on bulk message sending + return + + if message.confirmation_sent: + # Don't send a second confirmation for this message + return + + messages = request.get_messages() + start_thread = False + if len(messages) == 1: + if request.project_id is not None: + # Don't notify on first message in a project + return + subject = _("Your Freedom of Information Request was sent") + mail_intent = confirm_foi_request_sent_email + action_url = request.get_absolute_domain_short_url() + start_thread = True + else: + subject = _("Your message was sent") + mail_intent = confirm_foi_message_sent_email + action_url = message.get_absolute_domain_short_url() + + upload_url = request.user.get_autologin_url( + short_request_url("foirequest-upload_postal_message", request) + ) + + context = { + "foirequest": request, + "user": request.user, + "publicbody": message.recipient_public_body, + "message": message, + "action_url": action_url, + "upload_action_url": upload_url, + } + + send_request_user_email( + mail_intent, + request, + subject=subject, + context=context, + start_thread=start_thread, + ) + + message.confirmation_sent = True + message.save(update_fields=["confirmation_sent"]) diff --git a/froide/foirequest/tests/test_api.py b/froide/foirequest/tests/test_api.py index 609776557..1aefd284f 100644 --- a/froide/foirequest/tests/test_api.py +++ b/froide/foirequest/tests/test_api.py @@ -1,6 +1,5 @@ import json from datetime import timedelta -from unittest import mock from urllib.parse import urlencode from django.conf import settings @@ -12,7 +11,6 @@ from oauth2_provider.models import get_access_token_model, get_application_model -from froide.foirequest.delivery import DeliveryReport from froide.foirequest.models import FoiAttachment, FoiRequest from froide.foirequest.tests import factories from froide.publicbody.models import PublicBody @@ -311,15 +309,6 @@ def test_request_creation_without_scope(self): self.assertEqual(old_count, new_count) self.assertEqual(len(mail.outbox), 0) - @mock.patch( - "froide.foirequest.delivery.get_delivery_report", - lambda *_args, **_kwargs: DeliveryReport( - log="loglines", - time_diff=None, - status="sent", - message_id="message_id", - ), - ) def test_request_creation_with_scope(self): self.access_token.scope = "read:user make:request" self.access_token.save() diff --git a/froide/foirequest/tests/test_delivery_report.py b/froide/foirequest/tests/test_delivery_report.py deleted file mode 100644 index 072696b4f..000000000 --- a/froide/foirequest/tests/test_delivery_report.py +++ /dev/null @@ -1,42 +0,0 @@ -from io import StringIO - -from django.test import TestCase -from django.utils import timezone -from django.utils.dateparse import parse_datetime - -from ..delivery import PostfixDeliveryReporter -from . import factories - -log_string = """ -Dec 10 14:30:19 fragdenstaat postfix/smtpd[31492]: A3CD32E0C2C: client=localhost[127.0.0.1], sasl_method=PLAIN, sasl_username=foimail@fragdenstaat.de -Dec 10 14:30:19 fragdenstaat postfix/cleanup[3361]: A3CD32E0C2C: message-id=<20171211133019.12503.3873@fragdenstaat.de> -Dec 10 14:30:19 fragdenstaat opendkim[1488]: A3CD32E0C2C: DKIM-Signature field added (s=mail, d=fragdenstaat.de) -Dec 10 14:30:19 fragdenstaat postfix/qmgr[31484]: A3CD32E0C2C: from=, size=2369, nrcpt=1 (queue active) -Dec 11 14:30:25 fragdenstaat postfix/smtp[3365]: A3CD32E0C2C: to=, relay=mail10.regioit-aachen.de[91.102.136.170]:25, delay=6.1, delays=0.23/0.02/0.13/5.8, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[91.102.136.170]:10025): 250 2.0.0 Ok: queued as A1949380043) -Dec 11 14:30:19 fragdenstaat postfix/smtpd[31492]: 93CD32E0C2D: client=localhost[127.0.0.1], sasl_method=PLAIN, sasl_username=foimail@fragdenstaat.de -Dec 11 14:30:19 fragdenstaat postfix/cleanup[3361]: 93CD32E0C2D: message-id=<20171211133019.12503.3873@fragdenstaat.de> -Dec 11 14:30:19 fragdenstaat opendkim[1488]: 93CD32E0C2D: DKIM-Signature field added (s=mail, d=fragdenstaat.de) -Dec 11 14:30:19 fragdenstaat postfix/qmgr[31484]: 93CD32E0C2D: from=, size=2369, nrcpt=1 (queue active) -Dec 11 14:30:25 fragdenstaat postfix/smtp[3365]: 93CD32E0C2D: to=, relay=mail10.regioit-aachen.de[91.102.136.170]:25, delay=6.1, status=deferred -Dec 11 14:30:25 fragdenstaat postfix/smtp[3365]: 93CD32E0C2D: to=, relay=mail10.regioit-aachen.de[91.102.136.170]:25, delay=6.1, delays=0.23/0.02/0.13/5.8, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[91.102.136.170]:10025): 250 2.0.0 Ok: queued as A1949380043) -Dec 11 14:30:25 fragdenstaat postfix/qmgr[31484]: 93CD32E0C2D: removed -""" - - -class PostfixDeliveryReportTest(TestCase): - def setUp(self): - factories.make_world() - - def test_parsing(self): - sender = "s.peter.xyz123@fragdenstaat.de" - recipient = "test.testing@staedteregion-aachen.de" - - pdl = PostfixDeliveryReporter(timezone=timezone.get_current_timezone()) - log_file = StringIO(log_string) - naive = parse_datetime("2017-12-11 14:28:45") - - timestamp = naive.replace(tzinfo=timezone.get_current_timezone()) - - result = pdl.search_log(log_file, sender, recipient, timestamp) - self.assertEqual(result.status, "sent") - self.assertEqual(result.message_id, "20171211133019.12503.3873@fragdenstaat.de") diff --git a/froide/foirequest/tests/test_request.py b/froide/foirequest/tests/test_request.py index 1b28f7764..b98685dbe 100644 --- a/froide/foirequest/tests/test_request.py +++ b/froide/foirequest/tests/test_request.py @@ -23,9 +23,6 @@ import time_machine from pytest_django.asserts import assertContains, assertFormError, assertNotContains -import pytest - -from froide.foirequest.delivery import DeliveryReport from froide.foirequest.foi_mail import ( add_message_from_email, generate_foirequest_files, @@ -39,6 +36,7 @@ FoiRequest, ) from froide.foirequest.models.message import MessageKind +from froide.foirequest.signals import email_left_queue from froide.foirequest.tests import factories from froide.foirequest.utils import possible_reply_addresses from froide.helper.content_urls import get_content_url @@ -1763,7 +1761,6 @@ def test_extend_deadline(world, client): assert foirequest.due_date == foirequest.law.calculate_due_date(old_due_date, 2) -@pytest.mark.no_delivery_mock @pytest.mark.django_db def test_resend_message(world, client): foirequest = FoiRequest.objects.all()[0] @@ -2188,19 +2185,15 @@ def test_mail_confirmation_after_success(world, user, client, faker): # Now mark the email as sent foimessage = req.foimessage_set.get() - with mock.patch( - "froide.foirequest.delivery.get_delivery_report", - lambda *_args, **_kwargs: DeliveryReport( - log="loglines", - time_diff=None, - status="sent", - message_id=foimessage.email_message_id, - ), - ): - foimessage.check_delivery_status() - assert foimessage.deliverystatus is not None - ds = foimessage.get_delivery_status() - assert ds.status == "sent" + + email_left_queue.send( + sender=__name__, + to=foimessage.recipient_email, + from_address=foimessage.sender_email, + message_id=foimessage.email_message_id, + status="sent", + log=[], + ) # Expectation: The user should receive a confirmation that the request was sent assert len(mail.outbox) == 2 @@ -2232,22 +2225,29 @@ def test_mail_confirmation_after_success(world, user, client, faker): assert foimessage.plaintext in message.body # Action: Mark the email as sent - with mock.patch( - "froide.foirequest.delivery.get_delivery_report", - lambda *_args, **_kwargs: DeliveryReport( - log="loglines", - time_diff=None, - status="sent", - message_id=foimessage.email_message_id, - ), - ): - foimessage.check_delivery_status() - assert foimessage.deliverystatus is not None - ds = foimessage.get_delivery_status() - assert ds is not None - assert ds.status == "sent" + email_left_queue.send( + sender=__name__, + to=foimessage.recipient_email, + from_address=foimessage.sender_email, + message_id=foimessage.email_message_id, + status="sent", + log=[], + ) # Expectation: The user should receive a confirmation that the message was sent assert len(mail.outbox) == 4 confirmation_message = mail.outbox[3] assert "Your message was sent" in confirmation_message.subject + + # Action: Mark the email as sent *again* + email_left_queue.send( + sender=__name__, + to=foimessage.recipient_email, + from_address=foimessage.sender_email, + message_id=foimessage.email_message_id, + status="sent", + log=[], + ) + + # Expectation: The user should not receive another confirmation that the message was sent + assert len(mail.outbox) == 4 diff --git a/froide/settings.py b/froide/settings.py index 946720de8..9ac0e3bed 100644 --- a/froide/settings.py +++ b/froide/settings.py @@ -534,7 +534,6 @@ def STATICFILES_DIRS(self): dsn=False, target_countries=None, suspicious_asn_provider_list=None, - delivery_reporter=None, request_throttle=None, # Set to [(15, 7 * 24 * 60 * 60),] for 15 requests in 7 days message_throttle=[ (2, 5 * 60), # X messages in X seconds diff --git a/pytest.ini b/pytest.ini index 938f9fff5..73035adaf 100644 --- a/pytest.ini +++ b/pytest.ini @@ -4,3 +4,5 @@ DJANGO_SETTINGS_MODULE=froide.settings DJANGO_CONFIGURATION=Test python_files = tests.py test_*.py +markers = + no_delivery_mock