feat(devices): Add metrics on device updates, and a flag to disable them

config/index.js

@@ -314,6 +314,14 @@ var conf = convict({
     env: 'NEW_LOGIN_NOTIFICATION_ENABLED',
     default: true
   },
+  // A safety switch to disable device metadata updates,
+  // in case problems with the client logic cause server overload.
+  deviceUpdatesEnabled: {
+    doc: 'Are updates to device metadata enabled?',
+    format: Boolean,
+    env: 'DEVICE_UPDATES_ENABLED',
+    default: true
+  },
   oauth: {
     url: {
       format: 'url',

docs/api.md

@@ -86,6 +86,7 @@ The currently-defined error responses are:
 * status code 400, errno 124:  session already registered by another device
 * status code 400, errno 126:  account must be reset
 * status code 503, errno 201:  service temporarily unavailable to due high load (see [backoff protocol](#backoff-protocol))
+* status code 503, errno 202:  feature has been disabled for operational reasons
 * any status code, errno 999:  unknown error
 
 The follow error responses include additional parameters:

lib/error.js

@@ -15,6 +15,7 @@ var ERRNO = {
   DEVICE_UNKNOWN: 123,
   DEVICE_CONFLICT: 124,
   ENDPOINT_NOT_SUPPORTED: 116,
+  FEATURE_NOT_ENABLED: 202,
   INCORRECT_EMAIL_CASE: 120,
   INCORRECT_PASSWORD: 103,
   INVALID_JSON: 106,
@@ -365,6 +366,26 @@ AppError.serviceUnavailable = function (retryAfter) {
   )
 }
 
+AppError.featureNotEnabled = function (retryAfter) {
+  if (!retryAfter) {
+    retryAfter = 30
+  }
+  return new AppError(
+    {
+      code: 503,
+      error: 'Feature not enabled',
+      errno: ERRNO.FEATURE_NOT_ENABLED,
+      message: 'Service unavailable'
+    },
+    {
+      retryAfter: retryAfter
+    },
+    {
+      'retry-after': retryAfter
+    }
+  )
+}
+
 AppError.gone = function () {
   return new AppError({
     code: 410,

lib/routes/account.js

@@ -843,17 +843,17 @@ module.exports = function (
         log.begin('Account.device', request)
         var payload = request.payload
         var sessionToken = request.auth.credentials
-        // Clients have been known to send spurious device updates,
-        // which generates lots of unnecessary database load.
-        // Don't write out the update if nothing has actually changed.
-        if (payload.id && sessionToken.deviceId &&
-          payload.id === sessionToken.deviceId.toString('hex') &&
-          (! payload.name || payload.name === sessionToken.deviceName) &&
-          (! payload.type || payload.type === sessionToken.deviceType) &&
-          (! payload.pushCallback || payload.pushCallback === sessionToken.deviceCallbackURL) &&
-          (! payload.pushPublicKey || payload.pushPublicKey === sessionToken.deviceCallbackPublicKey)) {
-          log.info({ op: 'Account.device.spuriousUpdate' })
-          return reply(payload)
+        if (payload.id) {
+          // Don't write out the update if nothing has actually changed.
+          if (isSpuriousUpdate(payload, sessionToken)) {
+            log.increment('device.update.spurious')
+            return reply(payload)
+          }
+          // We also reserve the right to disable updates until
+          // we're confident clients are behaving correctly.
+          if (config.deviceUpdatesEnabled === false) {
+            throw error.featureNotEnabled()
+          }
         }
         var operation = payload.id ? 'updateDevice' : 'createDevice'
         db[operation](sessionToken.uid, sessionToken.tokenId, payload).then(
@@ -862,6 +862,35 @@ module.exports = function (
           },
           reply
         )
+
+        // Clients have been known to send spurious device updates,
+        // which generates lots of unnecessary database load.
+        // Check if anything has actually changed, and log lots metrics on what.
+        function isSpuriousUpdate(paylad, token) {
+          var spurious = true
+          if(! token.deviceId || payload.id !== token.deviceId.toString('hex')) {
+            spurious = false
+            log.increment('device.update.sessionToken')
+          }
+          if (payload.name && payload.name !== token.deviceName) {
+            spurious = false
+            log.increment('device.update.name')
+          }
+          if (payload.type && payload.type !== token.deviceType) {
+            spurious = false
+            log.increment('device.update.type')
+          }
+          if (payload.pushCallback && payload.pushCallback !== token.deviceCallbackURL) {
+            spurious = false
+            log.increment('device.update.pushCallback')
+          }
+          if (payload.pushPublicKey && payload.pushPublicKey !== token.deviceCallbackPublicKey) {
+            spurious = false
+            log.increment('device.update.pushPublicKey')
+          }
+          return spurious
+        }
+
       }
     },
     {

test/local/account_routes.js

@@ -22,10 +22,10 @@ var TEST_EMAIL_INVALID = 'example@dotless-domain'
 var makeRoutes = function (options) {
   options = options || {}
 
-  var config = options.config || {
-    verifierVersion: 0,
-    smtp: {}
-  }
+  var config = options.config || {}
+  config.verifierVersion = config.verifierVersion || 0
+  config.smtp = config.smtp ||  {}
+
   var log = options.log || mocks.mockLog()
   var Password = require('../../lib/crypto/password')(log, config)
   var db = options.db || {}
@@ -213,3 +213,146 @@ test(
     })
   }
 )
+
+test(
+  'device updates dont write to the db if nothing has changed',
+  function (t) {
+    var uid = uuid.v4('binary')
+    var deviceId = crypto.randomBytes(16)
+    var mockRequest = {
+      auth: {
+        credentials: {
+          uid: uid.toString('hex'),
+          deviceId: deviceId,
+          deviceName: 'my awesome device',
+          deviceType: 'desktop',
+          deviceCallbackURL: '',
+          deviceCallbackPublicKey: '',
+        }
+      },
+      payload: {
+        id: deviceId.toString('hex'),
+        name: 'my awesome device'
+      }
+    }
+    var mockDB = {
+      updateDevice: sinon.spy(function () {
+        return P.resolve()
+      })
+    }
+    var mockLog = mocks.spyLog()
+    var accountRoutes = makeRoutes({
+      db: mockDB,
+      log: mockLog
+    })
+    return new P(function(resolve) {
+      getRoute(accountRoutes, '/account/device')
+        .handler(mockRequest, function(response) {
+          resolve(response)
+        })
+    })
+    .then(function(response) {
+      t.equal(mockDB.updateDevice.callCount, 0, 'updateDevice was not called')
+
+      t.equal(mockLog.increment.callCount, 1, 'a counter was incremented')
+      t.equal(mockLog.increment.firstCall.args[0], 'device.update.spurious')
+
+      t.deepEqual(response, mockRequest.payload)
+    })
+  }
+)
+
+test(
+  'device updates log metrics about what has changed',
+  function (t) {
+    var uid = uuid.v4('binary')
+    var deviceId = crypto.randomBytes(16)
+    var mockRequest = {
+      auth: {
+        credentials: {
+          uid: uid.toString('hex'),
+          tokenId: 'lookmumasessiontoken',
+          deviceId: 'aDifferentDeviceId',
+          deviceName: 'my awesome device',
+          deviceType: 'desktop',
+          deviceCallbackURL: '',
+          deviceCallbackPublicKey: '',
+        }
+      },
+      payload: {
+        id: deviceId.toString('hex'),
+        name: 'my even awesomer device',
+        type: 'phone',
+        pushCallback: 'https://push.services.mozilla.com/123456',
+        pushPublicKey: 'SomeEncodedBinaryStuffThatDoesntGetValidedByThisTest'
+      }
+    }
+    var mockDB = {
+      updateDevice: sinon.spy(function (uid, sessionTokenId, deviceInfo) {
+        return P.resolve(deviceInfo)
+      })
+    }
+    var mockLog = mocks.spyLog()
+    var accountRoutes = makeRoutes({
+      db: mockDB,
+      log: mockLog
+    })
+    return new P(function(resolve) {
+      getRoute(accountRoutes, '/account/device')
+        .handler(mockRequest, function(response) {
+          resolve(response)
+        })
+    })
+    .then(function() {
+      t.equal(mockDB.updateDevice.callCount, 1, 'updateDevice was called')
+
+      t.equal(mockLog.increment.callCount, 5, 'the counters were incremented')
+      t.equal(mockLog.increment.getCall(0).args[0], 'device.update.sessionToken')
+      t.equal(mockLog.increment.getCall(1).args[0], 'device.update.name')
+      t.equal(mockLog.increment.getCall(2).args[0], 'device.update.type')
+      t.equal(mockLog.increment.getCall(3).args[0], 'device.update.pushCallback')
+      t.equal(mockLog.increment.getCall(4).args[0], 'device.update.pushPublicKey')
+    })
+  }
+)
+
+test(
+  'device updates can be disabled via config',
+  function (t) {
+    var uid = uuid.v4('binary')
+    var deviceId = crypto.randomBytes(16)
+    var mockRequest = {
+      auth: {
+        credentials: {
+          uid: uid.toString('hex'),
+          deviceId: deviceId
+        }
+      },
+      payload: {
+        id: deviceId.toString('hex'),
+        name: 'new device name'
+      }
+    }
+    var accountRoutes = makeRoutes({
+      config: {
+        deviceUpdatesEnabled: false
+      }
+    })
+
+    return new P(function(resolve) {
+      getRoute(accountRoutes, '/account/device')
+        .handler(mockRequest, function(response) {
+          resolve(response)
+        })
+    })
+    .then(
+      function(response) {
+        t.fail('should have thrown')
+      },
+      function(err) {
+        t.equal(err.output.statusCode, 503, 'correct status code is returned')
+        t.equal(err.errno, error.ERRNO.FEATURE_NOT_ENABLED, 'correct errno is returned')
+      }
+    )
+  }
+)