fix(db): sanely handle redis errors

https://github.com/mozilla/fxa-auth-server/pull/2215
r=vbudhram
This commit is contained in:
Phil Booth 2017-11-10 16:14:26 +00:00 коммит произвёл GitHub
Родитель afccd3a960
Коммит 8826364483
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: 4AEE18F83AFDEB23
4 изменённых файлов: 147 добавлений и 49 удалений

Просмотреть файл

@ -59,10 +59,18 @@ module.exports = (
const redisConfig = {
host: config.redis.host,
port: config.redis.port,
prefix: config.redis.sessionsKeyPrefix
prefix: config.redis.sessionsKeyPrefix,
// Prefer redis to fail fast than wait indefinitely for reconnection
enable_offline_queue: false
}
log.info({op: 'db.redis.enabled', config: redisConfig})
this.redis = redis.createClient(redisConfig)
// If the `error` event is not handled, redis errors are fatal
this.redis.on('error', err => log.error({
op: 'db.redis.error',
err: err.message,
stack: err.stack
}))
} else {
this.redis = false
log.info({op: 'db.redis.disabled'})
@ -255,9 +263,17 @@ module.exports = (
const promises = [
this.pool.get('/account/' + uid + '/sessions')
]
let isRedisOk = true
if (this.redis) {
promises.push(this.redis.getAsync(uid))
promises.push(
this.redis.getAsync(uid)
.catch(err => {
// Ensure that we don't return lastAccessTime if redis is down
isRedisOk = false
log.error({ op: 'db.redis.get.error', method: 'sessions', err: err.message })
})
)
}
return P.all(promises)
@ -274,7 +290,7 @@ module.exports = (
}
// for each db session token, if there is a matching redis token
// overwrite the properties of the db token with the redis token values
const lastAccessTimeEnabled = features.isLastAccessTimeEnabledForUser(uid)
const lastAccessTimeEnabled = isRedisOk && features.isLastAccessTimeEnabledForUser(uid)
const redisSessionTokens = redisTokens ? JSON.parse(redisTokens) : {}
const sessions = mysqlSessionTokens.map((sessionToken) => {
const id = sessionToken.tokenId
@ -444,9 +460,17 @@ module.exports = (
const promises = [
this.pool.get('/account/' + uid + '/devices')
]
let isRedisOk = true
if (this.redis) {
promises.push(this.redis.getAsync(uid))
promises.push(
this.redis.getAsync(uid)
.catch(err => {
// Ensure that we don't return lastAccessTime if redis is down
isRedisOk = false
log.error({ op: 'db.redis.get.error', method: 'devices', err: err.message })
})
)
}
return P.all(promises)
.spread((devices, redisTokens) => {
@ -458,7 +482,7 @@ module.exports = (
})
// for each device, if there is a redis token with a matching tokenId,
// overwrite device's ua properties and lastAccessTime with redis token values
const lastAccessTimeEnabled = features.isLastAccessTimeEnabledForUser(uid)
const lastAccessTimeEnabled = isRedisOk && features.isLastAccessTimeEnabledForUser(uid)
return devices.map(device => {
const token = redisSessionTokens[device.sessionTokenId]
const mergedInfo = Object.assign({}, device, token)
@ -558,9 +582,7 @@ module.exports = (
// update the hash with the new token
sessionTokens = res ? JSON.parse(res) : {}
sessionTokens[token.id] = newToken
return sessionTokens
})
.then(() => {
return this.redis.setAsync(uid, JSON.stringify(sessionTokens))
})
.then(() => sessionTokens)

Просмотреть файл

@ -16,8 +16,8 @@
"shrink": "npmshrink && npm run postinstall",
"start": "NODE_ENV=dev scripts/start-local.sh 2>&1",
"start-mysql": "NODE_ENV=dev scripts/start-local-mysql.sh 2>&1",
"test": "NODE_ENV=dev CORS_ORIGIN=http://foo,http://bar VERIFIER_VERSION=0 MEMCACHE_METRICS_CONTEXT_ADDRESS=none NO_COVERAGE=1 scripts/test-local.sh",
"test-ci": "NODE_ENV=dev CORS_ORIGIN=http://foo,http://bar scripts/test-local.sh",
"test": "NODE_ENV=dev CORS_ORIGIN=http://foo,http://bar VERIFIER_VERSION=0 MEMCACHE_METRICS_CONTEXT_ADDRESS=none NO_COVERAGE=1 USE_REDIS=false scripts/test-local.sh",
"test-ci": "NODE_ENV=dev CORS_ORIGIN=http://foo,http://bar USE_REDIS=false scripts/test-local.sh",
"test-e2e": "NODE_ENV=dev mocha test/e2e",
"test-remote": "MAILER_HOST=restmail.net MAILER_PORT=80 CORS_ORIGIN=http://baz mocha --timeout=300000 test/remote"
},

Просмотреть файл

@ -17,7 +17,7 @@ describe('db, session tokens expire:', () => {
sessionTokenWithoutDevice: 2419200000
}
let results, pool, redis, log, tokens, db
let results, pool, log, tokens, db
beforeEach(() => {
results = {}
@ -26,15 +26,10 @@ describe('db, session tokens expire:', () => {
post: sinon.spy(() => P.resolve()),
put: sinon.spy(() => P.resolve())
}
redis = {
getAsync: sinon.spy(() => P.resolve(results.redis)),
setAsync: sinon.spy(() => P.resolve())
}
log = mocks.mockLog()
tokens = require(`${LIB_DIR}/tokens`)(log, { tokenLifetimes })
const DB = proxyquire(`${LIB_DIR}/db`, {
'./pool': function () { return pool },
redis: { createClient: () => redis }
'./pool': function () { return pool }
})({ tokenLifetimes, redis: {} }, log, tokens, {})
return DB.connect({})
.then(result => db = result)
@ -51,7 +46,6 @@ describe('db, session tokens expire:', () => {
{ createdAt: now - tokenLifetimes.sessionTokenWithoutDevice + 1000, tokenId: 'baz' },
{ createdAt: now - tokenLifetimes.sessionTokenWithoutDevice - 1, tokenId: 'qux', deviceId: 'wibble' }
]
results.redis = []
return db.sessions()
.then(result => sessions = result)
})
@ -71,7 +65,7 @@ describe('db, session tokens do not expire:', () => {
sessionTokenWithoutDevice: 0
}
let results, pool, redis, log, tokens, db
let results, pool, log, tokens, db
beforeEach(() => {
results = {}
@ -80,15 +74,10 @@ describe('db, session tokens do not expire:', () => {
post: sinon.spy(() => P.resolve()),
put: sinon.spy(() => P.resolve())
}
redis = {
getAsync: sinon.spy(() => P.resolve(results.redis)),
setAsync: sinon.spy(() => P.resolve())
}
log = mocks.mockLog()
tokens = require(`${LIB_DIR}/tokens`)(log, { tokenLifetimes })
const DB = proxyquire(`${LIB_DIR}/db`, {
'./pool': function () { return pool },
redis: { createClient: () => redis }
'./pool': function () { return pool }
})({ tokenLifetimes, redis: {} }, log, tokens, {})
return DB.connect({})
.then(result => db = result)
@ -105,7 +94,6 @@ describe('db, session tokens do not expire:', () => {
{ createdAt: now - tokenLifetimes.sessionTokenWithoutDevice + 1000, tokenId: 'baz' },
{ createdAt: now - tokenLifetimes.sessionTokenWithoutDevice - 1, tokenId: 'qux', deviceId: 'wibble' }
]
results.redis = []
return db.sessions()
.then(result => sessions = result)
})
@ -137,6 +125,7 @@ describe('db with redis disabled', () => {
}
redis = {
on: sinon.spy(),
getAsync: sinon.spy(() => P.resolve(results.redis)),
setAsync: sinon.spy(() => P.resolve()),
del: sinon.spy(() => P.resolve())
@ -149,17 +138,11 @@ describe('db with redis disabled', () => {
redis: { createClient: () => redis }
})({ tokenLifetimes, redis: {enabled: false} }, log, tokens, {})
return DB.connect({})
.then(result => db = result)
})
.then(result => {
assert.equal(redis.on.callCount, 0, 'redis.on was not called')
afterEach(() => {
pool.get.reset()
pool.post.reset()
pool.del.reset()
redis.getAsync.reset()
redis.setAsync.reset()
redis.del.reset()
db = result
})
})
it('should not call redis when reading sessions', () => {
@ -225,18 +208,44 @@ describe('redis enabled', () => {
del: sinon.spy(() => P.resolve())
}
redis = {
on: sinon.spy(),
getAsync: sinon.spy(() => P.resolve()),
setAsync: sinon.spy(() => P.resolve()),
del: sinon.spy(() => P.resolve())
}
const createClient = sinon.spy(() => redis)
log = mocks.mockLog()
tokens = require(`${LIB_DIR}/tokens`)(log, { tokenLifetimes })
const DB = proxyquire(`${LIB_DIR}/db`, {
'./pool': function () { return pool },
redis: { createClient: () => redis }
})({ tokenLifetimes, redis: {enabled: false} }, log, tokens, {})
redis: { createClient }
})({
tokenLifetimes,
redis: {
enabled: true,
host: 'foo',
port: 'bar',
sessionsKeyPrefix: 'baz'
}
}, log, tokens, {})
return DB.connect({})
.then(result => db = result)
.then(result => {
assert.equal(createClient.callCount, 1, 'redis.createClient was called once')
assert.equal(createClient.args[0].length, 1, 'redis.createClient was passed one argument')
assert.deepEqual(createClient.args[0][0], {
host: 'foo',
port: 'bar',
prefix: 'baz',
enable_offline_queue: false
}, 'redis.createClient was passed correct settings')
assert.equal(redis.on.callCount, 1, 'redis.on was called once')
assert.equal(redis.on.args[0].length, 2, 'redis.on was passed two arguments')
assert.equal(redis.on.args[0][0], 'error', 'redis.on was called for the `error` event')
assert.equal(typeof redis.on.args[0][1], 'function', 'redis.on was passed event handler')
db = result
})
})
it('should not call redis or the db in db.devices if uid is falsey', () => {
@ -251,5 +260,30 @@ describe('redis enabled', () => {
}
)
})
it('should call redis and the db in db.devices if uid is not falsey', () => {
return db.devices('wibble')
.then(
result => assert.equal(result, 'db.devices should reject'),
() => {
assert.equal(pool.get.callCount, 1)
assert.equal(redis.getAsync.callCount, 1)
}
)
})
describe('redis error:', () => {
beforeEach(() => redis.on.args[0][1]({ message: 'foo', stack: 'bar' }))
it('should log the error', () => {
assert.equal(log.error.callCount, 1, 'log.error was called once')
assert.equal(log.error.args[0].length, 1, 'log.error was passed one argument')
assert.deepEqual(log.error.args[0][0], {
op: 'db.redis.error',
err: 'foo',
stack: 'bar'
}, 'log.error was passed the error details')
})
})
})

Просмотреть файл

@ -35,6 +35,7 @@ const redisDelSpy = sinon.stub()
const DB = proxyquire('../../lib/db', {
redis: {
createClient: () => ({
on () {},
getAsync: redisGetSpy,
setAsync: redisSetSpy,
del: redisDelSpy
@ -138,6 +139,9 @@ describe('remote db', function() {
() => {
let tokenId
// Simulate a cache miss in redis
redisGetSpy.returns(P.resolve(null))
// Fetch all sessions for the account
return db.sessions(account.uid)
.then(sessions => {
@ -163,9 +167,6 @@ describe('remote db', function() {
assert.deepEqual(sessionToken.uid, account.uid)
tokenId = sessionToken.id
// Simulate a cache miss in redis
redisGetSpy.returns(P.resolve(null))
// Fetch all sessions for the account
return db.sessions(account.uid)
})
@ -183,6 +184,19 @@ describe('remote db', function() {
assert.equal(sessions[0].uaFormFactor, null, 'uaFormFactor property is correct')
assert.equal(sessions[0].lastAccessTime, sessions[0].createdAt, 'lastAccessTime property is correct')
// Simulate a redis error
redisGetSpy.returns(P.reject({}))
// Fetch all sessions for the account
return db.sessions(account.uid)
})
.then(sessions => {
assert.equal(sessions.length, 1, 'sessions contains one item')
assert.equal(sessions[0].lastAccessTime, null, 'lastAccessTime property is not set')
// Reinstate redis success
redisGetSpy.returns(P.resolve())
// Fetch the session token
return db.sessionToken(tokenId)
})
@ -226,6 +240,26 @@ describe('remote db', function() {
return db.sessionToken(tokenId)
})
.then(sessionToken => {
// Simulate an error on redis.get
redisGetSpy.returns(P.reject({}))
// Attempt to update the session token
return db.updateSessionToken(sessionToken, '127.0.0.1', P.resolve({}))
.then(
() => assert(false, 'db.updateSessionToken should have failed'),
() => assert('db.updateSessionToken failed correctly')
)
})
.then(() => {
assert.equal(redisSetSpy.callCount, 0, 'redis.set was not called by updateSessionToken after redis.get failed')
// Fetch the session token
return db.sessionToken(tokenId)
})
.then(sessionToken => {
// Reinstate redis success
redisGetSpy.returns(P.resolve())
// Simulate an error on redis.set
redisSetSpy.returns(P.reject({}))
@ -237,6 +271,7 @@ describe('remote db', function() {
)
})
.then(() => {
// Reinstate redis success
redisSetSpy.returns(P.resolve())
// Fetch the session token
@ -312,10 +347,6 @@ describe('remote db', function() {
// Fetch all sessions for the account
return db.sessions(account.uid)
.then(
() => assert(false, 'db.sessions should have failed'),
() => assert('db.sessions failed correctly')
)
})
.then(() => {
// Fetch the session token
@ -327,8 +358,7 @@ describe('remote db', function() {
assert.equal(sessionToken.uaBrowserVersion, '41')
assert.equal(sessionToken.uaOS, 'Mac OS X')
assert.equal(sessionToken.uaOSVersion, '10.10')
assert.ok(sessionToken.lastAccessTime >= sessionToken.createdAt)
assert.ok(sessionToken.lastAccessTime <= Date.now())
assert.equal(sessionToken.lastAccessTime, sessionToken.createdAt)
const mockTokens = JSON.stringify({
idToNotDelete: {
@ -457,7 +487,19 @@ describe('remote db', function() {
})
.then((devices) => {
assert.equal(devices.length, 1, 'devices array contains one item')
return devices[0]
// Simulate a redis error
redisGetSpy.returns(P.reject({}))
return db.devices(account.uid)
.then(devices2 => {
assert.equal(devices.length, devices2.length, 'db.devices still returns devices array if redis fails')
assert.equal(devices2[0].lastAccessTime, null, 'db.devices does not return lastAccessTime if redis fails')
// Reinstate redis success
redisGetSpy.returns(P.resolve(null))
return devices[0]
})
})
.then((device) => {
assert.ok(device.id, 'device.id is set')