push_notifications: Add log line with user-id, UUID, and devices.

Being able to determine how many distinct users are getting push
notifications per remote host is useful, as is the distribution of
device counts.  This parallels the log line in
handle_push_notification for push notifications from local realms,
handled via the event queue.
This commit is contained in:
Alex Vandiver 2021-10-19 23:16:18 +00:00 committed by Alex Vandiver
parent 2285338b11
commit 5bcd3c01cb
3 changed files with 45 additions and 7 deletions

View File

@ -983,7 +983,7 @@ def handle_push_notification(user_profile_id: int, missed_message: Dict[str, Any
) )
logger.info( logger.info(
"Sending mobile push notifications for user %s: %s via FCM devices, %s via APNs devices", "Sending mobile push notifications for local user %s: %s via FCM devices, %s via APNs devices",
user_profile_id, user_profile_id,
len(android_devices), len(android_devices),
len(apple_devices), len(apple_devices),

View File

@ -300,7 +300,7 @@ class PushBouncerNotificationTest(BouncerTestCase):
} }
with mock.patch("zilencer.views.send_android_push_notification"), mock.patch( with mock.patch("zilencer.views.send_android_push_notification"), mock.patch(
"zilencer.views.send_apple_push_notification" "zilencer.views.send_apple_push_notification"
): ), self.assertLogs("zilencer.views", level="INFO") as logger:
result = self.uuid_post( result = self.uuid_post(
self.server_uuid, self.server_uuid,
"/api/v1/remotes/push/notify", "/api/v1/remotes/push/notify",
@ -313,6 +313,14 @@ class PushBouncerNotificationTest(BouncerTestCase):
{"result": "success", "msg": "", "total_android_devices": 2, "total_apple_devices": 1}, {"result": "success", "msg": "", "total_android_devices": 2, "total_apple_devices": 1},
data, data,
) )
self.assertEqual(
logger.output,
[
"INFO:zilencer.views:"
f"Sending mobile push notifications for remote user 1234-abcd:{hamlet.id}: "
"2 via FCM devices, 1 via APNs devices"
],
)
def test_remote_push_unregister_all(self) -> None: def test_remote_push_unregister_all(self) -> None:
payload = self.get_generic_payload("register") payload = self.get_generic_payload("register")
@ -868,7 +876,9 @@ class HandlePushNotificationTest(PushNotificationTest):
"zerver.lib.push_notifications.gcm_client" "zerver.lib.push_notifications.gcm_client"
) as mock_gcm, self.mock_apns() as apns_context, self.assertLogs( ) as mock_gcm, self.mock_apns() as apns_context, self.assertLogs(
"zerver.lib.push_notifications", level="INFO" "zerver.lib.push_notifications", level="INFO"
) as logger: ) as pn_logger, self.assertLogs(
"zilencer.views", level="INFO"
) as views_logger:
apns_devices = [ apns_devices = [
(b64_to_hex(device.token), device.ios_app_id, device.token) (b64_to_hex(device.token), device.ios_app_id, device.token)
for device in RemotePushDeviceToken.objects.filter(kind=PushDeviceToken.APNS) for device in RemotePushDeviceToken.objects.filter(kind=PushDeviceToken.APNS)
@ -885,16 +895,24 @@ class HandlePushNotificationTest(PushNotificationTest):
) )
apns_context.apns.send_notification.return_value.set_result(result) apns_context.apns.send_notification.return_value.set_result(result)
handle_push_notification(self.user_profile.id, missed_message) handle_push_notification(self.user_profile.id, missed_message)
self.assertEqual(
views_logger.output,
[
"INFO:zilencer.views:"
f"Sending mobile push notifications for remote user 1234-abcd:{self.user_profile.id}: "
f"{len(gcm_devices)} via FCM devices, {len(apns_devices)} via APNs devices"
],
)
for _, _, token in apns_devices: for _, _, token in apns_devices:
self.assertIn( self.assertIn(
"INFO:zerver.lib.push_notifications:" "INFO:zerver.lib.push_notifications:"
f"APNs: Success sending for user {self.user_profile.id} to device {token}", f"APNs: Success sending for user {self.user_profile.id} to device {token}",
logger.output, pn_logger.output,
) )
for _, _, token in gcm_devices: for _, _, token in gcm_devices:
self.assertIn( self.assertIn(
"INFO:zerver.lib.push_notifications:" f"GCM: Sent {token} as {message.id}", "INFO:zerver.lib.push_notifications:" f"GCM: Sent {token} as {message.id}",
logger.output, pn_logger.output,
) )
@override_settings(PUSH_NOTIFICATION_BOUNCER_URL="https://push.zulip.org.example.com") @override_settings(PUSH_NOTIFICATION_BOUNCER_URL="https://push.zulip.org.example.com")
@ -918,7 +936,9 @@ class HandlePushNotificationTest(PushNotificationTest):
"zerver.lib.push_notifications.gcm_client" "zerver.lib.push_notifications.gcm_client"
) as mock_gcm, self.mock_apns() as apns_context, self.assertLogs( ) as mock_gcm, self.mock_apns() as apns_context, self.assertLogs(
"zerver.lib.push_notifications", level="INFO" "zerver.lib.push_notifications", level="INFO"
) as logger: ) as pn_logger, self.assertLogs(
"zilencer.views", level="INFO"
) as views_logger:
apns_devices = [ apns_devices = [
(b64_to_hex(device.token), device.ios_app_id, device.token) (b64_to_hex(device.token), device.ios_app_id, device.token)
for device in RemotePushDeviceToken.objects.filter(kind=PushDeviceToken.APNS) for device in RemotePushDeviceToken.objects.filter(kind=PushDeviceToken.APNS)
@ -936,11 +956,19 @@ class HandlePushNotificationTest(PushNotificationTest):
) )
apns_context.apns.send_notification.return_value.set_result(result) apns_context.apns.send_notification.return_value.set_result(result)
handle_push_notification(self.user_profile.id, missed_message) handle_push_notification(self.user_profile.id, missed_message)
self.assertEqual(
views_logger.output,
[
"INFO:zilencer.views:"
f"Sending mobile push notifications for remote user 1234-abcd:{self.user_profile.id}: "
f"{len(gcm_devices)} via FCM devices, {len(apns_devices)} via APNs devices"
],
)
for _, _, token in apns_devices: for _, _, token in apns_devices:
self.assertIn( self.assertIn(
"INFO:zerver.lib.push_notifications:" "INFO:zerver.lib.push_notifications:"
f"APNs: Removing invalid/expired token {token} (Unregistered)", f"APNs: Removing invalid/expired token {token} (Unregistered)",
logger.output, pn_logger.output,
) )
self.assertEqual( self.assertEqual(
RemotePushDeviceToken.objects.filter(kind=PushDeviceToken.APNS).count(), 0 RemotePushDeviceToken.objects.filter(kind=PushDeviceToken.APNS).count(), 0

View File

@ -41,6 +41,8 @@ from zilencer.models import (
RemoteZulipServer, RemoteZulipServer,
) )
logger = logging.getLogger(__name__)
def validate_entity(entity: Union[UserProfile, RemoteZulipServer]) -> RemoteZulipServer: def validate_entity(entity: Union[UserProfile, RemoteZulipServer]) -> RemoteZulipServer:
if not isinstance(entity, RemoteZulipServer): if not isinstance(entity, RemoteZulipServer):
@ -192,6 +194,14 @@ def remote_server_notify_push(
) )
) )
logger.info(
"Sending mobile push notifications for remote user %s:%s: %s via FCM devices, %s via APNs devices",
server.uuid,
user_id,
len(android_devices),
len(apple_devices),
)
send_android_push_notification(android_devices, gcm_payload, gcm_options, remote=True) send_android_push_notification(android_devices, gcm_payload, gcm_options, remote=True)
send_apple_push_notification(user_id, apple_devices, apns_payload, remote=True) send_apple_push_notification(user_id, apple_devices, apns_payload, remote=True)