From b47535d8bb6717280ebbd1a8e23d461e870a7c1a Mon Sep 17 00:00:00 2001 From: Tim Abbott Date: Wed, 5 Dec 2018 10:36:58 -0800 Subject: [PATCH] push notifications: Fix exception when handling deleted messages. If a user deletes message between when it triggered a potential push notification for another user, and when that notification was actually sent, we'd end up with a situation where the `Message` table didn't have an entry for the requested message ID. The clean fix for this is to still throw an exception in the event that the message doesn't exist at all, but if it exists in ArchivedMessage, don't throw a user-facing exception. --- zerver/lib/notifications.py | 3 ++ zerver/lib/push_notifications.py | 15 ++++++-- zerver/tests/test_push_notifications.py | 46 +++++++++++++++++++++++++ 3 files changed, 62 insertions(+), 2 deletions(-) diff --git a/zerver/lib/notifications.py b/zerver/lib/notifications.py index c14d0a20f8..a6461379a2 100644 --- a/zerver/lib/notifications.py +++ b/zerver/lib/notifications.py @@ -400,6 +400,9 @@ def handle_missedmessage_emails(user_profile_id: int, if not receives_offline_email_notifications(user_profile): return + # Note: This query structure automatically filters out any + # messages that were permanently deleted, since those would now be + # in the ArchivedMessage table, not the Message table. messages = Message.objects.filter(usermessage__user_profile_id=user_profile, id__in=message_ids, usermessage__flags=~UserMessage.flags.read) diff --git a/zerver/lib/push_notifications.py b/zerver/lib/push_notifications.py index 2d73bc7b74..cc135e3075 100644 --- a/zerver/lib/push_notifications.py +++ b/zerver/lib/push_notifications.py @@ -30,7 +30,8 @@ from zerver.lib.timestamp import datetime_to_timestamp, timestamp_to_datetime from zerver.lib.utils import generate_random_token from zerver.models import PushDeviceToken, Message, Recipient, UserProfile, \ UserMessage, get_display_recipient, receives_offline_push_notifications, \ - receives_online_notifications, receives_stream_notifications, get_user_profile_by_id + receives_online_notifications, receives_stream_notifications, get_user_profile_by_id, \ + ArchivedMessage from version import ZULIP_VERSION logger = logging.getLogger(__name__) @@ -650,7 +651,17 @@ def handle_push_notification(user_profile_id: int, missed_message: Dict[str, Any return user_profile = get_user_profile_by_id(user_profile_id) - (message, user_message) = access_message(user_profile, missed_message['message_id']) + try: + (message, user_message) = access_message(user_profile, missed_message['message_id']) + except JsonableError: + if ArchivedMessage.objects.filter(id=missed_message['message_id']).exists(): + # If the cause is a race with the message being deleted, + # that's normal and we have no need to log an error. + return + logging.error("Unexpected message access failure handling push notifications: %s %s" % ( + user_profile.id, missed_message['message_id'])) + return + if user_message is not None: # If the user has read the message already, don't push-notify. # diff --git a/zerver/tests/test_push_notifications.py b/zerver/tests/test_push_notifications.py index f6e4740d36..cd9d415c14 100644 --- a/zerver/tests/test_push_notifications.py +++ b/zerver/tests/test_push_notifications.py @@ -34,6 +34,7 @@ from zerver.models import ( Stream, Subscription, ) +from zerver.lib.actions import do_delete_message from zerver.lib.soft_deactivation import do_soft_deactivate_users from zerver.lib import push_notifications as apn from zerver.lib.push_notifications import get_mobile_push_content, \ @@ -474,6 +475,51 @@ class HandlePushNotificationTest(PushNotificationTest): } apn.handle_push_notification(user_profile.id, missed_message) + def test_deleted_message(self) -> None: + """Simulates the race where message is deleted before handlingx push notifications""" + user_profile = self.example_user('hamlet') + message = self.get_message(Recipient.PERSONAL, type_id=1) + UserMessage.objects.create( + user_profile=user_profile, + flags=UserMessage.flags.read, + message=message + ) + missed_message = { + 'message_id': message.id, + 'trigger': 'private_message', + } + # Now, delete the message the normal way + do_delete_message(user_profile, message) + + with mock.patch('zerver.lib.push_notifications.uses_notification_bouncer') as mock_check: + apn.handle_push_notification(user_profile.id, missed_message) + # Check we didn't proceed through. + mock_check.assert_not_called() + + def test_missing_message(self) -> None: + """Simulates the race where message is missing when handling push notifications""" + user_profile = self.example_user('hamlet') + message = self.get_message(Recipient.PERSONAL, type_id=1) + UserMessage.objects.create( + user_profile=user_profile, + flags=UserMessage.flags.read, + message=message + ) + missed_message = { + 'message_id': message.id, + 'trigger': 'private_message', + } + # Now delete the message forcefully, so it just doesn't exist. + message.delete() + + # This should log an error + with mock.patch('zerver.lib.push_notifications.uses_notification_bouncer') as mock_check, \ + mock.patch('logging.error') as mock_logging_error: + apn.handle_push_notification(user_profile.id, missed_message) + # Check we didn't proceed through. + mock_check.assert_not_called() + mock_logging_error.assert_called_once() + def test_send_notifications_to_bouncer(self) -> None: user_profile = self.example_user('hamlet') message = self.get_message(Recipient.PERSONAL, type_id=1)