From 6819ecee92a0a3c1e2253c77f2bd89cc3fe808fa Mon Sep 17 00:00:00 2001 From: Mateusz Mandera Date: Sat, 28 Oct 2023 02:01:22 +0200 Subject: [PATCH] zilencer: Add new LoggingCountStat mobile_pushes_forwarded. This one counts actual successful deliveries. --- analytics/lib/counts.py | 15 +++++++++++++++ analytics/tests/test_counts.py | 14 ++++++++++---- zerver/lib/push_notifications.py | 22 +++++++++++++++------- zerver/tests/test_push_notifications.py | 10 ++++++---- zilencer/views.py | 14 ++++++++++++-- 5 files changed, 58 insertions(+), 17 deletions(-) diff --git a/analytics/lib/counts.py b/analytics/lib/counts.py index 25e17f4163..fcf39137f1 100644 --- a/analytics/lib/counts.py +++ b/analytics/lib/counts.py @@ -845,12 +845,27 @@ def get_count_stats(realm: Optional[Realm] = None) -> Dict[str, CountStat]: if settings.ZILENCER_ENABLED: count_stats_.append( + # Tracks the number of push notifications requested to be sent + # by a remote server. LoggingCountStat( "mobile_pushes_received::day", RemoteInstallationCount, CountStat.DAY, ) ) + count_stats_.append( + # Tracks the number of push notifications successfully sent to mobile + # devices, as requested by the remote server. Therefore this should be + # less than or equal to mobile_pushes_received - with potential tiny offsets + # resulting from a request being *received* by the bouncer right before midnight, + # but *sent* to the mobile device right after midnight. This would cause the increments + # to happen to CountStat records for different days. + LoggingCountStat( + "mobile_pushes_forwarded::day", + RemoteInstallationCount, + CountStat.DAY, + ) + ) return OrderedDict((stat.property, stat) for stat in count_stats_) diff --git a/analytics/tests/test_counts.py b/analytics/tests/test_counts.py index 1995d5a7c0..e1938cdd71 100644 --- a/analytics/tests/test_counts.py +++ b/analytics/tests/test_counts.py @@ -1442,8 +1442,10 @@ class TestLoggingCountStats(AnalyticsTestCase): } now = timezone_now() with time_machine.travel(now, tick=False), mock.patch( - "zilencer.views.send_android_push_notification" - ), mock.patch("zilencer.views.send_apple_push_notification"), self.assertLogs( + "zilencer.views.send_android_push_notification", return_value=1 + ), mock.patch( + "zilencer.views.send_apple_push_notification", return_value=1 + ), self.assertLogs( "zilencer.views", level="INFO" ): result = self.uuid_post( @@ -1455,13 +1457,17 @@ class TestLoggingCountStats(AnalyticsTestCase): ) self.assert_json_success(result) - # There are 3 devices we created for the user, and the Count increment should - # match that number. + # There are 3 devices we created for the user: + # 1. The mobile_pushes_received increment should match that number. + # 2. mobile_pushes_forwarded only counts successful deliveries, and we've set up + # the mocks above to simulate 1 successful android and 1 successful apple delivery. + # Thus the increment should be just 2. self.assertTableState( RemoteInstallationCount, ["property", "value", "subgroup", "server", "remote_id", "end_time"], [ ["mobile_pushes_received::day", 3, None, self.server, None, ceiling_to_day(now)], + ["mobile_pushes_forwarded::day", 2, None, self.server, None, ceiling_to_day(now)], ], ) diff --git a/zerver/lib/push_notifications.py b/zerver/lib/push_notifications.py index f3578e7605..d9e2cf0fee 100644 --- a/zerver/lib/push_notifications.py +++ b/zerver/lib/push_notifications.py @@ -218,9 +218,9 @@ def send_apple_push_notification( devices: Sequence[DeviceToken], payload_data: Mapping[str, Any], remote: Optional["RemoteZulipServer"] = None, -) -> None: +) -> int: if not devices: - return + return 0 # We lazily do the APNS imports as part of optimizing Zulip's base # import time; since these are only needed in the push # notification queue worker, it's best to only import them in the @@ -234,7 +234,7 @@ def send_apple_push_notification( "APNs: Dropping a notification because nothing configured. " "Set PUSH_NOTIFICATION_BOUNCER_URL (or APNS_CERT_FILE)." ) - return + return 0 if remote: assert settings.ZILENCER_ENABLED @@ -275,6 +275,7 @@ def send_apple_push_notification( results = apns_context.loop.run_until_complete(send_all_notifications()) + successfully_sent_count = 0 for device, result in results: if isinstance(result, aioapns.exceptions.ConnectionError): logger.error( @@ -290,6 +291,7 @@ def send_apple_push_notification( exc_info=result, ) elif result.is_successful: + successfully_sent_count += 1 logger.info( "APNs: Success sending for user %s to device %s", user_identity, device.token ) @@ -310,6 +312,8 @@ def send_apple_push_notification( result.description, ) + return successfully_sent_count + # # Sending to GCM, for Android @@ -411,7 +415,7 @@ def send_android_push_notification( data: Dict[str, Any], options: Dict[str, Any], remote: Optional["RemoteZulipServer"] = None, -) -> None: +) -> int: """ Send a GCM message to the given devices. @@ -424,13 +428,13 @@ def send_android_push_notification( For details, see `parse_gcm_options`. """ if not devices: - return + return 0 if not gcm_client: logger.debug( "Skipping sending a GCM push notification since " "PUSH_NOTIFICATION_BOUNCER_URL and ANDROID_GCM_API_KEY are both unset" ) - return + return 0 if remote: logger.info( @@ -463,11 +467,13 @@ def send_android_push_notification( ) except OSError: logger.warning("Error while pushing to GCM", exc_info=True) - return + return 0 + successfully_sent_count = 0 if res and "success" in res: for reg_id, msg_id in res["success"].items(): logger.info("GCM: Sent %s as %s", reg_id, msg_id) + successfully_sent_count = len(res["success"].keys()) if remote: assert settings.ZILENCER_ENABLED @@ -520,6 +526,8 @@ def send_android_push_notification( for reg_id in reg_ids: logger.warning("GCM: Delivery to %s failed: %s", reg_id, error) + return successfully_sent_count + # python-gcm handles retrying of the unsent messages. # Ref: https://github.com/geeknam/python-gcm/blob/master/gcm/gcm.py#L497 diff --git a/zerver/tests/test_push_notifications.py b/zerver/tests/test_push_notifications.py index 210d0822df..c9b75d3e46 100644 --- a/zerver/tests/test_push_notifications.py +++ b/zerver/tests/test_push_notifications.py @@ -603,9 +603,9 @@ class PushBouncerNotificationTest(BouncerTestCase): "gcm_options": {}, } with mock.patch( - "zilencer.views.send_android_push_notification" + "zilencer.views.send_android_push_notification", return_value=2 ) as android_push, mock.patch( - "zilencer.views.send_apple_push_notification" + "zilencer.views.send_apple_push_notification", return_value=1 ) as apple_push, self.assertLogs( "zilencer.views", level="INFO" ) as logger: @@ -698,8 +698,10 @@ class PushBouncerNotificationTest(BouncerTestCase): } time_received = time_sent + datetime.timedelta(seconds=1, milliseconds=234) with time_machine.travel(time_received, tick=False), mock.patch( - "zilencer.views.send_android_push_notification" - ), mock.patch("zilencer.views.send_apple_push_notification"), self.assertLogs( + "zilencer.views.send_android_push_notification", return_value=1 + ), mock.patch( + "zilencer.views.send_apple_push_notification", return_value=1 + ), self.assertLogs( "zilencer.views", level="INFO" ) as logger: result = self.uuid_post( diff --git a/zilencer/views.py b/zilencer/views.py index 796163e861..0fac09d712 100644 --- a/zilencer/views.py +++ b/zilencer/views.py @@ -429,7 +429,7 @@ def remote_server_notify_push( # send_apple_push_notification. gcm_payload = truncate_payload(gcm_payload) - send_android_push_notification( + android_successfully_delivered = send_android_push_notification( user_identity, android_devices, gcm_payload, gcm_options, remote=server ) @@ -437,7 +437,17 @@ def remote_server_notify_push( apns_payload["custom"].get("zulip"), dict ): apns_payload["custom"]["zulip"] = truncate_payload(apns_payload["custom"]["zulip"]) - send_apple_push_notification(user_identity, apple_devices, apns_payload, remote=server) + apple_successfully_delivered = send_apple_push_notification( + user_identity, apple_devices, apns_payload, remote=server + ) + + do_increment_logging_stat( + server, + COUNT_STATS["mobile_pushes_forwarded::day"], + None, + timezone_now(), + increment=android_successfully_delivered + apple_successfully_delivered, + ) return json_success( request,