mirror of
				https://github.com/zulip/zulip.git
				synced 2025-11-03 21:43:21 +00:00 
			
		
		
		
	push_notification: Remove "Remote queue latency" log on bouncer.
We haven't ever inspected those logs, since adding the metric.
This commit is contained in:
		
				
					committed by
					
						
						Tim Abbott
					
				
			
			
				
	
			
			
			
						parent
						
							298a39e457
						
					
				
				
					commit
					2225142554
				
			@@ -1,12 +1,9 @@
 | 
			
		||||
from datetime import timedelta
 | 
			
		||||
from unittest import mock
 | 
			
		||||
 | 
			
		||||
import responses
 | 
			
		||||
import time_machine
 | 
			
		||||
from django.conf import settings
 | 
			
		||||
from django.http.response import ResponseHeaders
 | 
			
		||||
from django.test import override_settings
 | 
			
		||||
from django.utils.timezone import now
 | 
			
		||||
from requests.exceptions import ConnectionError
 | 
			
		||||
from requests.models import PreparedRequest
 | 
			
		||||
from typing_extensions import override
 | 
			
		||||
@@ -59,8 +56,6 @@ class HandlePushNotificationTest(PushNotificationTestCase):
 | 
			
		||||
        self.setup_apns_tokens()
 | 
			
		||||
        self.setup_fcm_tokens()
 | 
			
		||||
 | 
			
		||||
        time_sent = now().replace(microsecond=0)
 | 
			
		||||
        with time_machine.travel(time_sent, tick=False):
 | 
			
		||||
        message = self.get_message(
 | 
			
		||||
            Recipient.PERSONAL,
 | 
			
		||||
            type_id=self.personal_recipient_user.id,
 | 
			
		||||
@@ -71,13 +66,11 @@ class HandlePushNotificationTest(PushNotificationTestCase):
 | 
			
		||||
            message=message,
 | 
			
		||||
        )
 | 
			
		||||
 | 
			
		||||
        time_received = time_sent + timedelta(seconds=1, milliseconds=234)
 | 
			
		||||
        missed_message = {
 | 
			
		||||
            "message_id": message.id,
 | 
			
		||||
            "trigger": NotificationTriggers.DIRECT_MESSAGE,
 | 
			
		||||
        }
 | 
			
		||||
        with (
 | 
			
		||||
            time_machine.travel(time_received, tick=False),
 | 
			
		||||
            self.mock_fcm() as (
 | 
			
		||||
                mock_fcm_app,
 | 
			
		||||
                mock_fcm_messaging,
 | 
			
		||||
@@ -116,9 +109,6 @@ class HandlePushNotificationTest(PushNotificationTestCase):
 | 
			
		||||
            self.assertEqual(
 | 
			
		||||
                views_logger.output,
 | 
			
		||||
                [
 | 
			
		||||
                    "INFO:zilencer.views:"
 | 
			
		||||
                    f"Remote queuing latency for 6cde5f7a-1f7e-4978-9716-49f69ebfc9fe:<id:{self.user_profile.id}><uuid:{self.user_profile.uuid}> "
 | 
			
		||||
                    "is 1 seconds",
 | 
			
		||||
                    "INFO:zilencer.views:"
 | 
			
		||||
                    f"Sending mobile push notifications for remote user 6cde5f7a-1f7e-4978-9716-49f69ebfc9fe:<id:{self.user_profile.id}><uuid:{self.user_profile.uuid}>: "
 | 
			
		||||
                    f"{len(fcm_devices)} via FCM devices, {len(apns_devices)} via APNs devices",
 | 
			
		||||
@@ -234,8 +224,6 @@ class HandlePushNotificationTest(PushNotificationTestCase):
 | 
			
		||||
        self.setup_apns_tokens()
 | 
			
		||||
        self.setup_fcm_tokens()
 | 
			
		||||
 | 
			
		||||
        time_sent = now().replace(microsecond=0)
 | 
			
		||||
        with time_machine.travel(time_sent, tick=False):
 | 
			
		||||
        message = self.get_message(
 | 
			
		||||
            Recipient.PERSONAL,
 | 
			
		||||
            type_id=self.personal_recipient_user.id,
 | 
			
		||||
@@ -246,13 +234,11 @@ class HandlePushNotificationTest(PushNotificationTestCase):
 | 
			
		||||
            message=message,
 | 
			
		||||
        )
 | 
			
		||||
 | 
			
		||||
        time_received = time_sent + timedelta(seconds=1, milliseconds=234)
 | 
			
		||||
        missed_message = {
 | 
			
		||||
            "message_id": message.id,
 | 
			
		||||
            "trigger": NotificationTriggers.DIRECT_MESSAGE,
 | 
			
		||||
        }
 | 
			
		||||
        with (
 | 
			
		||||
            time_machine.travel(time_received, tick=False),
 | 
			
		||||
            self.mock_fcm() as (
 | 
			
		||||
                mock_fcm_app,
 | 
			
		||||
                mock_fcm_messaging,
 | 
			
		||||
@@ -313,9 +299,6 @@ class HandlePushNotificationTest(PushNotificationTestCase):
 | 
			
		||||
            self.assertEqual(
 | 
			
		||||
                views_logger.output,
 | 
			
		||||
                [
 | 
			
		||||
                    "INFO:zilencer.views:"
 | 
			
		||||
                    f"Remote queuing latency for 6cde5f7a-1f7e-4978-9716-49f69ebfc9fe:<id:{self.user_profile.id}><uuid:{self.user_profile.uuid}> "
 | 
			
		||||
                    "is 1 seconds",
 | 
			
		||||
                    "INFO:zilencer.views:"
 | 
			
		||||
                    f"Sending mobile push notifications for remote user 6cde5f7a-1f7e-4978-9716-49f69ebfc9fe:<id:{self.user_profile.id}><uuid:{self.user_profile.uuid}>: "
 | 
			
		||||
                    f"{len(fcm_devices)} via FCM devices, {len(apns_devices)} via APNs devices",
 | 
			
		||||
 
 | 
			
		||||
@@ -943,73 +943,6 @@ class PushBouncerNotificationTest(BouncerTestCase):
 | 
			
		||||
            logger.output,
 | 
			
		||||
        )
 | 
			
		||||
 | 
			
		||||
    def test_subsecond_timestamp_format(self) -> None:
 | 
			
		||||
        hamlet = self.example_user("hamlet")
 | 
			
		||||
        RemotePushDeviceToken.objects.create(
 | 
			
		||||
            kind=RemotePushDeviceToken.FCM,
 | 
			
		||||
            token="aaaaaa",
 | 
			
		||||
            user_id=hamlet.id,
 | 
			
		||||
            server=self.server,
 | 
			
		||||
        )
 | 
			
		||||
 | 
			
		||||
        time_sent = now().replace(microsecond=234000)
 | 
			
		||||
        with time_machine.travel(time_sent, tick=False):
 | 
			
		||||
            message = Message(
 | 
			
		||||
                sender=hamlet,
 | 
			
		||||
                recipient=self.example_user("othello").recipient,
 | 
			
		||||
                realm_id=hamlet.realm_id,
 | 
			
		||||
                content="This is test content",
 | 
			
		||||
                rendered_content="This is test content",
 | 
			
		||||
                date_sent=now(),
 | 
			
		||||
                sending_client=get_client("test"),
 | 
			
		||||
            )
 | 
			
		||||
            message.set_topic_name("Test topic")
 | 
			
		||||
            message.save()
 | 
			
		||||
            gcm_payload, gcm_options = get_message_payload_gcm(hamlet, message)
 | 
			
		||||
            apns_payload = get_message_payload_apns(
 | 
			
		||||
                hamlet, message, NotificationTriggers.DIRECT_MESSAGE
 | 
			
		||||
            )
 | 
			
		||||
 | 
			
		||||
        # Reconfigure like recent versions, which had subsecond-granularity
 | 
			
		||||
        # timestamps.
 | 
			
		||||
        self.assertIsNotNone(gcm_payload.get("time"))
 | 
			
		||||
        gcm_payload["time"] = float(gcm_payload["time"] + 0.234)
 | 
			
		||||
        self.assertEqual(gcm_payload["time"], time_sent.timestamp())
 | 
			
		||||
        self.assertIsNotNone(apns_payload["custom"]["zulip"].get("time"))
 | 
			
		||||
        apns_payload["custom"]["zulip"]["time"] = gcm_payload["time"]
 | 
			
		||||
 | 
			
		||||
        payload = {
 | 
			
		||||
            "user_id": hamlet.id,
 | 
			
		||||
            "user_uuid": str(hamlet.uuid),
 | 
			
		||||
            "gcm_payload": gcm_payload,
 | 
			
		||||
            "apns_payload": apns_payload,
 | 
			
		||||
            "gcm_options": gcm_options,
 | 
			
		||||
        }
 | 
			
		||||
        time_received = time_sent + timedelta(seconds=1, milliseconds=234)
 | 
			
		||||
        with (
 | 
			
		||||
            time_machine.travel(time_received, tick=False),
 | 
			
		||||
            mock.patch("zilencer.views.send_android_push_notification", return_value=1),
 | 
			
		||||
            mock.patch("zilencer.views.send_apple_push_notification", return_value=1),
 | 
			
		||||
            mock.patch(
 | 
			
		||||
                "corporate.lib.stripe.RemoteServerBillingSession.current_count_for_billed_licenses",
 | 
			
		||||
                return_value=10,
 | 
			
		||||
            ),
 | 
			
		||||
            self.assertLogs("zilencer.views", level="INFO") as logger,
 | 
			
		||||
        ):
 | 
			
		||||
            result = self.uuid_post(
 | 
			
		||||
                self.server_uuid,
 | 
			
		||||
                "/api/v1/remotes/push/notify",
 | 
			
		||||
                payload,
 | 
			
		||||
                content_type="application/json",
 | 
			
		||||
            )
 | 
			
		||||
        self.assert_json_success(result)
 | 
			
		||||
        self.assertEqual(
 | 
			
		||||
            logger.output[0],
 | 
			
		||||
            "INFO:zilencer.views:"
 | 
			
		||||
            f"Remote queuing latency for 6cde5f7a-1f7e-4978-9716-49f69ebfc9fe:<id:{hamlet.id}><uuid:{hamlet.uuid}> "
 | 
			
		||||
            "is 1.234 seconds",
 | 
			
		||||
        )
 | 
			
		||||
 | 
			
		||||
    def test_remote_push_unregister_all(self) -> None:
 | 
			
		||||
        payload = self.get_generic_payload("register")
 | 
			
		||||
 | 
			
		||||
 
 | 
			
		||||
@@ -924,29 +924,6 @@ def remote_server_notify_push(
 | 
			
		||||
    if apple_devices and user_id is not None and user_uuid is not None:
 | 
			
		||||
        apple_devices = delete_duplicate_registrations(apple_devices, server.id, user_id, user_uuid)
 | 
			
		||||
 | 
			
		||||
    remote_queue_latency: str | None = None
 | 
			
		||||
    sent_time: float | int | None = gcm_payload.get(
 | 
			
		||||
        # TODO/compatibility: This could be a lot simpler if not for pre-5.0 Zulip servers
 | 
			
		||||
        # that had an older format. Future implementation:
 | 
			
		||||
        #     "time", apns_payload["custom"]["zulip"].get("time")
 | 
			
		||||
        "time",
 | 
			
		||||
        apns_payload.get("custom", {}).get("zulip", {}).get("time"),
 | 
			
		||||
    )
 | 
			
		||||
    if sent_time is not None:
 | 
			
		||||
        if isinstance(sent_time, int):
 | 
			
		||||
            # The 'time' field only used to have whole-integer
 | 
			
		||||
            # granularity, so if so we only report with
 | 
			
		||||
            # whole-second granularity
 | 
			
		||||
            remote_queue_latency = str(int(timezone_now().timestamp()) - sent_time)
 | 
			
		||||
        else:
 | 
			
		||||
            remote_queue_latency = f"{timezone_now().timestamp() - sent_time:.3f}"
 | 
			
		||||
        logger.info(
 | 
			
		||||
            "Remote queuing latency for %s:%s is %s seconds",
 | 
			
		||||
            server.uuid,
 | 
			
		||||
            user_identity,
 | 
			
		||||
            remote_queue_latency,
 | 
			
		||||
        )
 | 
			
		||||
 | 
			
		||||
    logger.info(
 | 
			
		||||
        "Sending mobile push notifications for remote user %s:%s: %s via FCM devices, %s via APNs devices",
 | 
			
		||||
        server.uuid,
 | 
			
		||||
 
 | 
			
		||||
		Reference in New Issue
	
	Block a user