From cc648a2c19d2e60156b980b46984ab7818896b4e Mon Sep 17 00:00:00 2001 From: Lauryn Menard Date: Thu, 11 May 2023 18:12:03 +0200 Subject: [PATCH] scheduled-messages: Send notification if send scheduled message fails. In the case that there is an error when sending a scheduled message, we now send a message from the notification bot to the user who scheduled the message about the failure/error. The notification message is not sent if the error when sending the scheduled message was due to the realm or sender being deactivated. --- zerver/actions/scheduled_messages.py | 99 +++++++++++++++++++------ zerver/tests/test_scheduled_messages.py | 41 +++++++++- 2 files changed, 117 insertions(+), 23 deletions(-) diff --git a/zerver/actions/scheduled_messages.py b/zerver/actions/scheduled_messages.py index bca56a7801..76c9a33900 100644 --- a/zerver/actions/scheduled_messages.py +++ b/zerver/actions/scheduled_messages.py @@ -3,11 +3,17 @@ import logging from typing import List, Optional, Sequence, Tuple, Union import orjson +from django.conf import settings from django.db import transaction from django.utils.timezone import now as timezone_now from django.utils.translation import gettext as _ +from django.utils.translation import override as override_language -from zerver.actions.message_send import check_message, do_send_messages +from zerver.actions.message_send import ( + check_message, + do_send_messages, + internal_send_private_message, +) from zerver.actions.uploads import check_attachment_reference_change, do_claim_attachments from zerver.lib.addressee import Addressee from zerver.lib.exceptions import JsonableError, RealmDeactivatedError, UserDeactivatedError @@ -19,6 +25,7 @@ from zerver.models import ( ScheduledMessage, Subscription, UserProfile, + get_system_bot, ) from zerver.tornado.django_api import send_event @@ -202,7 +209,7 @@ def send_scheduled_message(scheduled_message: ScheduledMessage) -> None: minutes=SCHEDULED_MESSAGE_LATE_CUTOFF_MINUTES ) if timezone_now() > latest_send_time: - raise JsonableError(_("Scheduled send time has already passed.")) + raise JsonableError(_("Message could not be sent at the scheduled time.")) # Recheck that we have permission to send this message, in case # permissions have changed since the message was scheduled. @@ -237,6 +244,41 @@ def send_scheduled_message(scheduled_message: ScheduledMessage) -> None: notify_remove_scheduled_message(scheduled_message.sender, scheduled_message.id) +def send_failed_scheduled_message_notification( + user_profile: UserProfile, scheduled_message_id: int +) -> None: + scheduled_message = access_scheduled_message(user_profile, scheduled_message_id) + delivery_datetime_string = str(scheduled_message.scheduled_timestamp) + + with override_language(user_profile.default_language): + error_string = scheduled_message.failure_message + delivery_time_markdown = f" " + + content = "".join( + [ + _( + "The message you scheduled for {delivery_datetime} was not sent because of the following error:" + ), + "\n\n", + "> {error_message}", + "\n\n", + _("[View scheduled messages](#scheduled)"), + "\n\n", + ] + ) + + content = content.format( + delivery_datetime=delivery_time_markdown, + error_message=error_string, + ) + + internal_send_private_message( + get_system_bot(settings.NOTIFICATION_BOT, user_profile.realm_id), + user_profile, + content, + ) + + @transaction.atomic def try_deliver_one_scheduled_message(logger: logging.Logger) -> bool: # Returns whether there was a scheduled message to attempt @@ -261,26 +303,39 @@ def try_deliver_one_scheduled_message(logger: logging.Logger) -> bool: scheduled_message.sender_id, ) - try: - send_scheduled_message(scheduled_message) - except JsonableError as e: - scheduled_message.failed = True - scheduled_message.failure_message = e.msg - scheduled_message.save(update_fields=["failed", "failure_message"]) - logger.info("Failed with message: %s", scheduled_message.failure_message) - except Exception: - # An unexpected failure; store as a generic 500 error. - scheduled_message.refresh_from_db() - was_delivered = scheduled_message.delivered - scheduled_message.failed = True - scheduled_message.failure_message = _("Internal server error") - scheduled_message.save(update_fields=["failed", "failure_message"]) + with override_language(scheduled_message.sender.default_language): + try: + send_scheduled_message(scheduled_message) + except Exception as e: + scheduled_message.refresh_from_db() + was_delivered = scheduled_message.delivered + scheduled_message.failed = True - logger.exception( - "Unexpected error sending scheduled message %s (sent: %s)", - scheduled_message.id, - was_delivered, - stack_info=True, - ) + if isinstance(e, JsonableError): + scheduled_message.failure_message = e.msg + logger.info("Failed with message: %s", e.msg) + else: + # An unexpected failure; store and send user a generic + # internal server error in notification message. + scheduled_message.failure_message = _("Internal server error") + logger.exception( + "Unexpected error sending scheduled message %s (sent: %s)", + scheduled_message.id, + was_delivered, + stack_info=True, + ) + + scheduled_message.save(update_fields=["failed", "failure_message"]) + + if ( + not was_delivered + # Do not send notification if either the realm or + # the sending user account has been deactivated. + and not isinstance(e, RealmDeactivatedError) + and not isinstance(e, UserDeactivatedError) + ): + send_failed_scheduled_message_notification( + scheduled_message.sender, scheduled_message.id + ) return True diff --git a/zerver/tests/test_scheduled_messages.py b/zerver/tests/test_scheduled_messages.py index 0dc1b48dbe..da7b284a60 100644 --- a/zerver/tests/test_scheduled_messages.py +++ b/zerver/tests/test_scheduled_messages.py @@ -17,6 +17,7 @@ from zerver.actions.scheduled_messages import ( from zerver.actions.users import change_user_is_active from zerver.lib.exceptions import JsonableError from zerver.lib.test_classes import ZulipTestCase +from zerver.lib.test_helpers import most_recent_message from zerver.lib.timestamp import timestamp_to_datetime from zerver.models import Attachment, Message, ScheduledMessage @@ -224,7 +225,7 @@ class ScheduledMessageTest(ZulipTestCase): self.assertTrue(scheduled_message.failed) def test_too_late_to_deliver_scheduled_message(self) -> None: - expected_failure_message = "Scheduled send time has already passed." + expected_failure_message = "Message could not be sent at the scheduled time." logger = mock.Mock() self.create_scheduled_message() scheduled_message = self.last_scheduled_message() @@ -241,12 +242,25 @@ class ScheduledMessageTest(ZulipTestCase): scheduled_message, logger, expected_failure_message ) + # Verify that the user was sent a message informing them about + # the failed scheduled message. + realm = scheduled_message.sender.realm + msg = most_recent_message(scheduled_message.sender) + self.assertEqual(msg.recipient.type, msg.recipient.PERSONAL) + self.assertEqual(msg.sender_id, self.notification_bot(realm).id) + self.assertIn(expected_failure_message, msg.content) + def test_realm_deactivated_failed_to_deliver_scheduled_message(self) -> None: expected_failure_message = "This organization has been deactivated" logger = mock.Mock() self.create_scheduled_message() scheduled_message = self.last_scheduled_message() + # Verify realm isn't deactivated and get user's most recent + # message. + self.assertFalse(scheduled_message.sender.realm.deactivated) + message_before_deactivation = most_recent_message(scheduled_message.sender) + more_than_scheduled_delivery_datetime = ( scheduled_message.scheduled_timestamp + datetime.timedelta(minutes=1) ) @@ -261,12 +275,23 @@ class ScheduledMessageTest(ZulipTestCase): scheduled_message, logger, expected_failure_message ) + # Verify that no failed scheduled message notification was sent. + self.assertTrue(scheduled_message.sender.realm.deactivated) + message_after_deactivation = most_recent_message(scheduled_message.sender) + self.assertEqual(message_after_deactivation.content, message_before_deactivation.content) + self.assertNotIn(expected_failure_message, message_after_deactivation.content) + def test_sender_deactivated_failed_to_deliver_scheduled_message(self) -> None: expected_failure_message = "Account is deactivated" logger = mock.Mock() self.create_scheduled_message() scheduled_message = self.last_scheduled_message() + # Verify user isn't deactivated and get user's most recent + # message. + self.assertTrue(scheduled_message.sender.is_active) + message_before_deactivation = most_recent_message(scheduled_message.sender) + more_than_scheduled_delivery_datetime = ( scheduled_message.scheduled_timestamp + datetime.timedelta(minutes=1) ) @@ -280,6 +305,12 @@ class ScheduledMessageTest(ZulipTestCase): scheduled_message, logger, expected_failure_message ) + # Verify that no failed scheduled message notification was sent. + self.assertFalse(scheduled_message.sender.is_active) + message_after_deactivation = most_recent_message(scheduled_message.sender) + self.assertEqual(message_after_deactivation.content, message_before_deactivation.content) + self.assertNotIn(expected_failure_message, message_after_deactivation.content) + def test_delivery_type_reminder_failed_to_deliver_scheduled_message_unknown_exception( self, ) -> None: @@ -314,6 +345,14 @@ class ScheduledMessageTest(ZulipTestCase): ) self.assertTrue(scheduled_message.failed) + # Verify that the user was sent a message informing them about + # the failed scheduled message. + realm = scheduled_message.sender.realm + msg = most_recent_message(scheduled_message.sender) + self.assertEqual(msg.recipient.type, msg.recipient.PERSONAL) + self.assertEqual(msg.sender_id, self.notification_bot(realm).id) + self.assertIn("Internal server error", msg.content) + def test_scheduling_in_past(self) -> None: # Scheduling a message in past should fail. content = "Test message"