Push Notifications Improvements (#12019)

* start fixing push notitifications

* push notifications: refactor error handling

* remove comment and improve logging

* improve emails errors

* wip: start improving webhooks tests

* add max length to push notifications and tests

* fix typos

test/api/unit/libs/pushNotifications.js

@@ -1,13 +1,15 @@
-import requireAgain from 'require-again';
 import apn from 'apn/mock';
+import _ from 'lodash';
 import nconf from 'nconf';
 import gcmLib from 'node-gcm'; // works with FCM notifications too
 import { model as User } from '../../../../website/server/models/user';
+import {
+  sendNotification as sendPushNotification,
+  MAX_MESSAGE_LENGTH,
+} from '../../../../website/server/libs/pushNotifications';
 
 describe('pushNotifications', () => {
   let user;
-  let sendPushNotification;
-  const pathToPushNotifications = '../../../../website/server/libs/pushNotifications';
   let fcmSendSpy;
   let apnSendSpy;
 
@@ -28,8 +30,6 @@ describe('pushNotifications', () => {
       on: () => null,
       send: apnSendSpy,
     });
-
-    sendPushNotification = requireAgain(pathToPushNotifications).sendNotification;
   });
 
   afterEach(() => {
@@ -86,6 +86,67 @@ describe('pushNotifications', () => {
     expect(apnSendSpy).to.not.have.been.called;
   });
 
+  it('cuts the message to 300 chars', () => {
+    const longMessage = `12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345`;
+
+    expect(longMessage.length > MAX_MESSAGE_LENGTH).to.equal(true);
+
+    const details = {
+      identifier,
+      title,
+      message: longMessage,
+      payload: {
+        message: longMessage,
+      },
+    };
+
+    sendPushNotification(user, details);
+
+    expect(details.message).to.equal(_.truncate(longMessage, { length: MAX_MESSAGE_LENGTH }));
+    expect(details.payload.message)
+      .to.equal(_.truncate(longMessage, { length: MAX_MESSAGE_LENGTH }));
+
+    expect(details.message.length).to.equal(MAX_MESSAGE_LENGTH);
+    expect(details.payload.message.length).to.equal(MAX_MESSAGE_LENGTH);
+  });
+
+  it('cuts the message to 300 chars (no payload)', () => {
+    const longMessage = `12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345
+      12345 12345 12345 12345 12345 12345 12345 12345 12345 12345`;
+
+    expect(longMessage.length > MAX_MESSAGE_LENGTH).to.equal(true);
+
+    const details = {
+      identifier,
+      title,
+      message: longMessage,
+    };
+
+    sendPushNotification(user, details);
+
+    expect(details.message).to.equal(_.truncate(longMessage, { length: MAX_MESSAGE_LENGTH }));
+    expect(details.message.length).to.equal(MAX_MESSAGE_LENGTH);
+  });
+
   // TODO disabled because APN relies on a Promise
   xit('uses APN for iOS devices', () => {
     user.pushDevices.push({

test/api/unit/libs/webhooks.test.js

@@ -16,7 +16,7 @@ import {
   defer,
   sleep,
 } from '../../../helpers/api-unit.helper';
-
+import logger from '../../../../website/server/libs/logger';
 
 describe('webhooks', () => {
   let webhooks; let
@@ -356,6 +356,7 @@ describe('webhooks', () => {
       });
 
       it('records failures', async () => {
+        sinon.stub(logger, 'error');
         const body = {};
         sendWebhook.send(user, body);
 
@@ -369,6 +370,9 @@ describe('webhooks', () => {
 
         expect(user.webhooks[0].failures).to.equal(1);
         expect((Date.now() - user.webhooks[0].lastFailureAt.getTime()) < 10000).to.be.true;
+
+        expect(logger.error).to.be.calledOnce;
+        logger.error.restore();
       });
 
       it('disables a webhook after 10 failures', async () => {

website/server/libs/pushNotifications.js

@@ -5,15 +5,10 @@ import gcmLib from 'node-gcm'; // works with FCM notifications too
 import logger from './logger';
 
 const FCM_API_KEY = nconf.get('PUSH_CONFIGS_FCM_SERVER_API_KEY');
-
 const fcmSender = FCM_API_KEY ? new gcmLib.Sender(FCM_API_KEY) : undefined;
 
-let apnProvider;
-// Load APN certificate and key from S3
 const APN_ENABLED = nconf.get('PUSH_CONFIGS_APN_ENABLED') === 'true';
-
+const apnProvider = APN_ENABLED ? new apn.Provider({
-if (APN_ENABLED) {
-  apnProvider = APN_ENABLED ? new apn.Provider({
   token: {
     key: nconf.get('PUSH_CONFIGS_APN_KEY'),
     keyId: nconf.get('PUSH_CONFIGS_APN_KEY_ID'),
@@ -21,9 +16,18 @@ if (APN_ENABLED) {
   },
   production: true,
 }) : undefined;
+
+function removePushDevice (user, pushDevice) {
+  return user.update({
+    $pull: { pushDevices: { regId: pushDevice.regId } },
+  }).exec().catch(err => {
+    logger.error(err, `Error removing pushDevice ${pushDevice.regId} for user ${user._id}`);
+  });
 }
 
-function sendNotification (user, details = {}) {
+export const MAX_MESSAGE_LENGTH = 300;
+
+export function sendNotification (user, details = {}) {
   if (!user) throw new Error('User is required.');
   if (user.preferences.pushNotifications.unsubscribeFromAll === true) return;
   const pushDevices = user.pushDevices.toObject ? user.pushDevices.toObject() : user.pushDevices;
@@ -35,6 +39,15 @@ function sendNotification (user, details = {}) {
   const payload = details.payload ? details.payload : {};
   payload.identifier = details.identifier;
 
+  // Cut the message to 300 characters to avoid going over the limit of 4kb per notifications
+  if (details.message.length > MAX_MESSAGE_LENGTH) {
+    details.message = _.truncate(details.message, { length: MAX_MESSAGE_LENGTH });
+  }
+
+  if (payload.message && payload.message.length > MAX_MESSAGE_LENGTH) {
+    payload.message = _.truncate(payload.message, { length: MAX_MESSAGE_LENGTH });
+  }
+
   _.each(pushDevices, pushDevice => {
     switch (pushDevice.type) { // eslint-disable-line default-case
       case 'android':
@@ -49,8 +62,33 @@ function sendNotification (user, details = {}) {
 
           fcmSender.send(message, {
             registrationTokens: [pushDevice.regId],
-          }, 10, err => {
+          }, 5, (err, response) => {
-            if (err) logger.error(err, 'FCM Error');
+            if (err) {
+              logger.error(err, 'Unhandled FCM error.');
+              return;
+            }
+
+            // Handle failed push notifications deliveries
+            // Note that we're always sending to one device, not multiple
+            const failed = response
+              && response.results && response.results[0] && response.results[0].error;
+
+            if (failed) {
+              // See https://firebase.google.com/docs/cloud-messaging/http-server-ref#table9
+              // for the list of errors
+
+              // The regId is not valid anymore, remove it
+              if (failed === 'NotRegistered') {
+                removePushDevice(user, pushDevice);
+                logger.error(new Error('FCM error, invalid pushDevice'), {
+                  response, regId: pushDevice.regId, userId: user._id,
+                });
+              } else {
+                logger.error(new Error('FCM error'), {
+                  response, regId: pushDevice.regId, userId: user._id,
+                });
+              }
+            }
           });
         }
         break;
@@ -69,21 +107,32 @@ function sendNotification (user, details = {}) {
           });
           apnProvider.send(notification, pushDevice.regId)
             .then(response => {
+              // Handle failed push notifications deliveries
               response.failed.forEach(failure => {
-                if (failure.error) {
+                if (failure.error) { // generic error
-                  logger.error(new Error('APN error'), { failure });
+                  logger.error(new Error('APN error'), {
+                    response, regId: pushDevice.regId, userId: user._id,
+                  });
+                } else { // rejected
+                  // see https://developer.apple.com/library/archive/documentation/NetworkingInternet/Conceptual/RemoteNotificationsPG/CommunicatingwithAPNs.html#//apple_ref/doc/uid/TP40008194-CH11-SW17
+                  // for a list of rejection reasons
+                  const { reason } = failure.response;
+                  if (reason === 'Unregistered') {
+                    removePushDevice(user, pushDevice);
+                    logger.error(new Error('APN error, invalid pushDevice'), {
+                      response, regId: pushDevice.regId, userId: user._id,
+                    });
                   } else {
-                  logger.error(new Error('APN transmissionError'), { failure, notification });
+                    logger.error(new Error('APN error'), {
+                      response, regId: pushDevice.regId, userId: user._id,
+                    });
+                  }
                 }
               });
             })
-            .catch(err => logger.error(err, 'APN error'));
+            .catch(err => logger.error(err, 'Unhandled APN error.'));
         }
         break;
     }
   });
 }
-
-export {
-  sendNotification, // eslint-disable-line import/prefer-default-export
-};