Merge pull request #2967 from mozilla/pb/2966-redis-conflict-409

https://github.com/mozilla/fxa-auth-server/pull/2967
r=shane-tomlinson

docs/api.md

@@ -304,6 +304,8 @@ for `code` and `errno` are:
   Unknown client_id
 * `code: 400, errno: 164`:
   Stale auth timestamp
+* `code: 409, errno: 165`:
+  Redis WATCH detected a conflicting update
 * `code: 503, errno: 201`:
   Service unavailable
 * `code: 503, errno: 202`:

lib/error.js

@@ -63,20 +63,17 @@ var ERRNO = {
   FAILED_TO_SEND_EMAIL: 151,
   INVALID_TOKEN_VERIFICATION_CODE: 152,
   EXPIRED_TOKEN_VERIFICATION_CODE: 153,
-
   TOTP_TOKEN_EXISTS: 154,
   TOTP_TOKEN_NOT_FOUND: 155,
-
   RECOVERY_CODE_NOT_FOUND: 156,
   DEVICE_COMMAND_UNAVAILABLE: 157,
-
   RECOVERY_KEY_NOT_FOUND: 158,
   RECOVERY_KEY_INVALID: 159,
   TOTP_REQUIRED: 160,
   RECOVERY_KEY_EXISTS: 161,
-
   UNKNOWN_CLIENT_ID: 162,
   STALE_AUTH_AT: 164,
+  REDIS_CONFLICT: 165,
 
   SERVER_BUSY: 201,
   FEATURE_NOT_ENABLED: 202,
@@ -910,6 +907,15 @@ AppError.staleAuthAt = (authAt) => {
   })
 }
 
+AppError.redisConflict = () => {
+  return new AppError({
+    code: 409,
+    error: 'Conflict',
+    errno: ERRNO.REDIS_CONFLICT,
+    message: 'Redis WATCH detected a conflicting update'
+  })
+}
+
 AppError.backendServiceFailure = (service, operation) => {
   return new AppError({
     code: 500,

lib/redis.js

@@ -19,11 +19,10 @@ module.exports = (config, log) => {
           return await value(...args)
         } catch (err) {
           if (err.message === 'redis.watch.conflict') {
-            // If you see this line in a stack trace in Sentry
-            // it's nothing to worry about, just a sign that our
-            // protection against concurrent updates is working
-            // correctly. fxa-shared is responsible for logging.
-            throw error.unexpectedError()
+            // This error is nothing to worry about, just a sign that our
+            // protection against concurrent updates is working correctly.
+            // fxa-shared is responsible for logging.
+            throw error.redisConflict()
           }
 
           // If you see this line in a stack trace in Sentry

test/local/redis.js

@@ -0,0 +1,141 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at https://mozilla.org/MPL/2.0/. */
+
+'use strict'
+
+const LIB_DIR = '../../lib'
+
+const { assert } = require('chai')
+const error = require(`${LIB_DIR}/error`)
+const mocks = require('../mocks')
+const P = require(`${LIB_DIR}/promise`)
+const proxyquire = require('proxyquire')
+const sinon = require('sinon')
+
+describe('lib/redis:', () => {
+  let config, log, mockError, redis, fxaShared, wrapper
+
+  beforeEach(() => {
+    config = {}
+    log = mocks.mockLog()
+    redis = {
+      foo: sinon.spy(() => {
+        if (mockError) {
+          return P.reject(mockError)
+        }
+
+        return P.resolve('bar')
+      }),
+      baz: sinon.spy(),
+      wibble: 'blee',
+    }
+    fxaShared = sinon.spy(() => redis)
+    wrapper = proxyquire(`${LIB_DIR}/redis`, { 'fxa-shared/redis': fxaShared })(config, log)
+  })
+
+  it('returned the wrapped interface', () => {
+    assert.isObject(wrapper)
+    assert.notEqual(wrapper, redis)
+    assert.lengthOf(Object.keys(wrapper), 3)
+
+    assert.isFunction(wrapper.foo)
+    assert.notEqual(wrapper.foo, redis.foo)
+    assert.lengthOf(wrapper.foo, 0)
+
+    assert.isFunction(wrapper.baz)
+    assert.notEqual(wrapper.baz, redis.baz)
+    assert.lengthOf(wrapper.baz, 0)
+
+    assert.equal(wrapper.wibble, 'blee')
+  })
+
+  it('called fxa-shared', () => {
+    assert.equal(fxaShared.callCount, 1)
+    const args = fxaShared.args[0]
+    assert.lengthOf(args, 2)
+    assert.equal(args[0], config)
+    assert.equal(args[1], log)
+  })
+
+  it('did not call any redis methods', () => {
+    assert.equal(redis.foo.callCount, 0)
+    assert.equal(redis.baz.callCount, 0)
+  })
+
+  describe('successful method call:', () => {
+    let result
+
+    beforeEach(async () => {
+      result = await wrapper.foo('mock arg 1', 'mock arg 2')
+    })
+
+    it('returned the expected result', () => {
+      assert.equal(result, 'bar')
+    })
+
+    it('called the underlying redis method', () => {
+      assert.equal(redis.foo.callCount, 1)
+      const args = redis.foo.args[0]
+      assert.lengthOf(args, 2)
+      assert.equal(args[0], 'mock arg 1')
+      assert.equal(args[1], 'mock arg 2')
+    })
+
+    it('did not call the other redis method', () => {
+      assert.equal(redis.baz.callCount, 0)
+    })
+  })
+
+  describe('conflicting method call:', () => {
+    let result, err
+
+    beforeEach(async () => {
+      try {
+        mockError = new Error('redis.watch.conflict')
+        result = await wrapper.foo()
+      } catch (e) {
+        err = e
+      }
+    })
+
+    it('rejected with 409 conflict', () => {
+      assert.isUndefined(result)
+      assert.isObject(err)
+      assert.equal(err.errno, error.ERRNO.REDIS_CONFLICT)
+      assert.equal(err.message, 'Redis WATCH detected a conflicting update')
+      assert.equal(err.output.statusCode, 409)
+      assert.equal(err.output.payload.error, 'Conflict')
+    })
+
+    it('called the underlying redis method', () => {
+      assert.equal(redis.foo.callCount, 1)
+    })
+  })
+
+  describe('failing method call:', () => {
+    let result, err
+
+    beforeEach(async () => {
+      try {
+        mockError = new Error('wibble')
+        result = await wrapper.foo()
+      } catch (e) {
+        err = e
+      }
+    })
+
+    it('rejected with 500 error', () => {
+      assert.isUndefined(result)
+      assert.isObject(err)
+      assert.equal(err.errno, error.ERRNO.UNEXPECTED_ERROR)
+      assert.equal(err.message, 'Unspecified error')
+      assert.equal(err.output.statusCode, 500)
+      assert.equal(err.output.payload.error, 'Internal Server Error')
+    })
+
+    it('called the underlying redis method', () => {
+      assert.equal(redis.foo.callCount, 1)
+    })
+  })
+})

test/remote/redis_tests.js

@@ -114,8 +114,8 @@ describe('concurrent updates of the same key:', () => {
 
   it('one update failed', () => {
     assert.equal(errors.length, 1)
-    assert.equal(errors[0].message, 'Unspecified error')
-    assert.equal(errors[0].errno, 999)
+    assert.equal(errors[0].message, 'Redis WATCH detected a conflicting update')
+    assert.equal(errors[0].errno, 165)
   })
 
   it('the other update completed successfully', () => {
@@ -199,8 +199,8 @@ describe('set concurrently with update:', () => {
 
   it('update failed', () => {
     assert.ok(error)
-    assert.equal(error.message, 'Unspecified error')
-    assert.equal(error.errno, 999)
+    assert.equal(error.message, 'Redis WATCH detected a conflicting update')
+    assert.equal(error.errno, 165)
   })
 
   it('data was set', () => {
@@ -220,8 +220,8 @@ describe('del concurrently with update:', () => {
 
   it('update failed', () => {
     assert.ok(error)
-    assert.equal(error.message, 'Unspecified error')
-    assert.equal(error.errno, 999)
+    assert.equal(error.message, 'Redis WATCH detected a conflicting update')
+    assert.equal(error.errno, 165)
   })
 
   it('data was deleted', () => {