From 05485b46fe257ee4bd433c2eb278b3687ddcb736 Mon Sep 17 00:00:00 2001 From: Sean McArthur Date: Tue, 6 Sep 2016 10:31:33 -0700 Subject: [PATCH] feat(security): record event names and ip addresses for important events --- config/index.js | 7 ++ lib/db.js | 18 ++++ lib/routes/account.js | 114 ++++++++++++++++++++++++- lib/routes/utils/request_helper.js | 2 +- npm-shrinkwrap.json | 7 +- test/local/account_routes.js | 131 ++++++++++++++++++++++++++++- test/mocks.js | 11 ++- 7 files changed, 280 insertions(+), 10 deletions(-) diff --git a/config/index.js b/config/index.js index 7b0c71078..a54b1a450 100644 --- a/config/index.js +++ b/config/index.js @@ -465,6 +465,13 @@ var conf = convict({ ], env: 'SIGNIN_CONFIRMATION_FORCE_EMAIL_REGEX' } + }, + securityHistory: { + enabled: { + doc: 'enable security history', + default: true, + env: 'SECURITY_HISTORY_ENABLED' + } } }) diff --git a/lib/db.js b/lib/db.js index d4bb5bd27..38696c790 100644 --- a/lib/db.js +++ b/lib/db.js @@ -772,6 +772,24 @@ module.exports = function ( return this.pool.del('/verificationReminders', reminderData) } + DB.prototype.securityEvent = function (event) { + log.trace({ + op: 'DB.securityEvent', + securityEvent: event + }) + + return this.pool.post('/securityEvents', event) + } + + DB.prototype.securityEvents = function (params) { + log.trace({ + op: 'DB.securityEvents', + params: params + }) + + return this.pool.get('/securityEvents', params) + } + return DB } diff --git a/lib/routes/account.js b/lib/routes/account.js index e5c56ce28..ec033a498 100644 --- a/lib/routes/account.js +++ b/lib/routes/account.js @@ -13,6 +13,10 @@ var PUSH_PAYLOADS_SCHEMA_PATH = '../../docs/pushpayloads.schema.json' // Currently only for metrics purposes, not enforced. var MAX_ACTIVE_SESSIONS = 200 +var MS_ONE_DAY = 1000 * 60 * 60 * 24 +var MS_ONE_WEEK = MS_ONE_DAY * 7 +var MS_ONE_MONTH = MS_ONE_DAY * 30 + var path = require('path') var ajv = require('ajv')() var fs = require('fs') @@ -51,6 +55,8 @@ module.exports = function ( defaultLanguage: config.i18n.defaultLanguage }) + var securityHistoryEnabled = config.securityHistory && config.securityHistory.enabled + var routes = [ { method: 'POST', @@ -103,6 +109,7 @@ module.exports = function ( .then(createSessionToken) .then(sendVerifyCode) .then(createKeyFetchToken) + .then(recordSecurityEvent) .then(createResponse) .done(reply, reply) @@ -307,6 +314,18 @@ module.exports = function ( } } + function recordSecurityEvent() { + if (securityHistoryEnabled) { + // don't block response recording db event + db.securityEvent({ + name: 'account.create', + uid: account.uid, + ipAddr: request.app.clientAddress, + sessionTokenId: sessionToken.tokenId + }) + } + } + function createResponse () { var response = { uid: account.uid.toString('hex'), @@ -377,6 +396,7 @@ module.exports = function ( customs.check(request, email, 'accountLogin') .then(readEmailRecord) + .then(checkSecurityHistory) .then(checkNumberOfActiveSessions) .then(createSessionToken) .then(createKeyFetchToken) @@ -384,6 +404,7 @@ module.exports = function ( .then(sendVerifyAccountEmail) .then(sendNewDeviceLoginNotification) .then(sendVerifyLoginEmail) + .then(recordSecurityEvent) .then(createResponse) .done(reply, reply) @@ -444,6 +465,72 @@ module.exports = function ( ) } + function checkSecurityHistory () { + if (!securityHistoryEnabled) { + return + } + return db.securityEvents({ + uid: emailRecord.uid, + ipAddr: request.app.clientAddress + }) + .then( + function (events) { + // if we've seen this address for this user before, we + // can skip signin confirmation + // + // for now, just log that we *could* have done so + if (events.length > 0) { + var latest = 0 + var verified = false + + events.forEach(function(ev) { + if (ev.verified) { + verified = true + if (ev.createdAt > latest) { + latest = ev.createdAt + } + } + }) + if (verified) { + var since = Date.now() - latest + var recency + if (since < MS_ONE_DAY) { + recency = 'day' + } else if (since < MS_ONE_WEEK) { + recency = 'week' + } else if (since < MS_ONE_MONTH) { + recency = 'month' + } else { + recency = 'old' + } + + log.info({ + op: 'Account.history.verified', + uid: emailRecord.uid.toString('hex'), + events: events.length, + recency: recency + }) + } else { + log.info({ + op: 'Account.history.unverified', + uid: emailRecord.uid.toString('hex'), + events: events.length + }) + } + } + }, + function (err) { + // for now, security events are purely for metrics + // so errors shouldn't stop the login attempt + log.error({ + op: 'Account.history.error', + err: err, + uid: emailRecord.uid.toString('hex') + }) + } + ) + } + function checkNumberOfActiveSessions () { return db.sessions(emailRecord.uid) .then( @@ -619,6 +706,18 @@ module.exports = function ( } } + function recordSecurityEvent() { + if (securityHistoryEnabled) { + // don't block response recording db event + db.securityEvent({ + name: 'account.login', + uid: emailRecord.uid, + ipAddr: request.app.clientAddress, + sessionTokenId: sessionToken && sessionToken.tokenId + }) + } + } + function createResponse () { var response = { uid: sessionToken.uid.toString('hex'), @@ -644,7 +743,6 @@ module.exports = function ( response.verificationMethod = 'email' response.verificationReason = 'login' } - return P.resolve(response) } } @@ -1458,6 +1556,7 @@ module.exports = function ( .then(resetAccountData) .then(createSessionToken) .then(createKeyFetchToken) + .then(recordSecurityEvent) .then(createResponse) .done(reply, reply) @@ -1572,6 +1671,18 @@ module.exports = function ( } } + function recordSecurityEvent() { + if (securityHistoryEnabled) { + // don't block response recording db event + db.securityEvent({ + name: 'account.reset', + uid: account.uid, + ipAddr: request.app.clientAddress, + sessionTokenId: sessionToken && sessionToken.tokenId + }) + } + } + function createResponse () { // If no sessionToken, this could be a legacy client // attempting to reset an account password, return legacy response. @@ -1579,6 +1690,7 @@ module.exports = function ( return {} } + var response = { uid: sessionToken.uid.toString('hex'), sessionToken: sessionToken.data.toString('hex'), diff --git a/lib/routes/utils/request_helper.js b/lib/routes/utils/request_helper.js index fae4966be..d97bde8e4 100644 --- a/lib/routes/utils/request_helper.js +++ b/lib/routes/utils/request_helper.js @@ -9,7 +9,7 @@ * @returns {boolean} */ function wantsKeys (request) { - return request.query.keys === 'true' + return request.query && request.query.keys === 'true' } /** diff --git a/npm-shrinkwrap.json b/npm-shrinkwrap.json index f7824b8db..102b42b6b 100644 --- a/npm-shrinkwrap.json +++ b/npm-shrinkwrap.json @@ -300,7 +300,7 @@ "fxa-auth-db-mysql": { "version": "0.69.0", "from": "git+https://github.com/mozilla/fxa-auth-db-mysql.git#master", - "resolved": "git+https://github.com/mozilla/fxa-auth-db-mysql.git#22e27d16d635927d2facfe8382030ec10447e600", + "resolved": "git+https://github.com/mozilla/fxa-auth-db-mysql.git#7de6154e9a1898480a2ee31ad19699c5c0e864e1", "dependencies": { "base64url": { "version": "2.0.0", @@ -428,6 +428,11 @@ } } }, + "ip": { + "version": "1.1.3", + "from": "https://registry.npmjs.org/ip/-/ip-1.1.3.tgz", + "resolved": "https://registry.npmjs.org/ip/-/ip-1.1.3.tgz" + }, "mysql": { "version": "2.11.1", "from": "https://registry.npmjs.org/mysql/-/mysql-2.11.1.tgz", diff --git a/test/local/account_routes.js b/test/local/account_routes.js index d4f370a71..5de819054 100644 --- a/test/local/account_routes.js +++ b/test/local/account_routes.js @@ -233,7 +233,8 @@ test('/account/reset', function (t) { }) var mockDB = mocks.mockDB({ uid: uid, - email: TEST_EMAIL + email: TEST_EMAIL, + wrapWrapKb: crypto.randomBytes(32) }) var mockCustoms = { reset: sinon.spy(function () { @@ -243,6 +244,11 @@ test('/account/reset', function (t) { var mockLog = mocks.spyLog() var mockPush = mocks.mockPush() var accountRoutes = makeRoutes({ + config: { + securityHistory: { + enabled: true + } + }, customs: mockCustoms, db: mockDB, log: mockLog, @@ -250,7 +256,8 @@ test('/account/reset', function (t) { }) var route = getRoute(accountRoutes, '/account/reset') - return runTest(route, mockRequest, function () { + var clientAddress = mockRequest.app.clientAddress + return runTest(route, mockRequest, function (res) { t.equal(mockDB.resetAccount.callCount, 1) t.equal(mockPush.notifyPasswordReset.callCount, 1) @@ -265,6 +272,12 @@ test('/account/reset', function (t) { t.equal(args[0], 'account.reset', 'first argument was event name') t.equal(args[1], mockRequest, 'second argument was request object') t.deepEqual(args[2], { uid: uid.toString('hex') }, 'third argument contained uid') + + t.equal(mockDB.securityEvent.callCount, 1, 'db.securityEvent was called') + var securityEvent = mockDB.securityEvent.args[0][0] + t.equal(securityEvent.uid, uid) + t.equal(securityEvent.ipAddr, clientAddress) + t.equal(securityEvent.name, 'account.reset') }) }) @@ -572,6 +585,7 @@ test('/account/create', function (t) { keys: 'true' } }) + var clientAddress = mockRequest.app.clientAddress var emailCode = crypto.randomBytes(16) var keyFetchTokenId = crypto.randomBytes(16) var sessionTokenId = crypto.randomBytes(16) @@ -610,6 +624,11 @@ test('/account/create', function (t) { var mockMailer = mocks.mockMailer() var mockPush = mocks.mockPush() var accountRoutes = makeRoutes({ + config: { + securityHistory: { + enabled: true + } + }, db: mockDB, log: mockLog, mailer: mockMailer, @@ -672,15 +691,25 @@ test('/account/create', function (t) { t.deepEqual(args[0].uid, uid, 'keyFetchToken.uid was correct') t.deepEqual(args[1], 'account.keyfetch', 'second argument was event name') t.equal(args[2], mockRequest.payload.metricsContext, 'third argument was metrics context') + + var securityEvent = mockDB.securityEvent + t.equal(securityEvent.callCount, 1, 'db.securityEvent is called') + securityEvent = securityEvent.args[0][0] + t.equal(securityEvent.name, 'account.create') + t.equal(securityEvent.uid, uid) + t.equal(securityEvent.ipAddr, clientAddress) }).finally(function () { mockLog.close() }) }) test('/account/login', function (t) { - t.plan(3) + t.plan(5) var config = { - newLoginNotificationEnabled: true + newLoginNotificationEnabled: true, + securityHistory: { + enabled: true + } } var mockRequest = mocks.mockRequest({ query: { @@ -1383,6 +1412,100 @@ test('/account/login', function (t) { }) }) + t.test('checks security history', function (t) { + t.plan(3) + var record + mockLog.info = sinon.spy(function(arg) { + if (arg.op.indexOf('Account.history') === 0) { + record = arg + } + }) + var clientAddress = mockRequest.app.clientAddress + + t.test('with a seen ip address', function (t) { + record = undefined + var securityQuery + mockDB.securityEvents = sinon.spy(function (arg) { + securityQuery = arg + return P.resolve([ + { + name: 'account.login', + createdAt: Date.now(), + verified: true + } + ]) + }) + return runTest(route, mockRequest, function (response) { + t.equal(mockDB.securityEvents.callCount, 1, 'db.securityEvents was called') + t.equal(securityQuery.uid, uid) + t.equal(securityQuery.ipAddr, clientAddress) + + t.equal(!!record, true, 'log.info was called for Account.history') + t.equal(record.op, 'Account.history.verified') + t.equal(record.uid, uid.toString('hex')) + t.equal(record.events, 1) + t.equal(record.recency, 'day') + }) + }) + + t.test('with a seen, unverified ip address', function (t) { + record = undefined + var securityQuery + mockDB.securityEvents = sinon.spy(function (arg) { + securityQuery = arg + return P.resolve([ + { + name: 'account.login', + createdAt: Date.now(), + verified: false + } + ]) + }) + return runTest(route, mockRequest, function (response) { + t.equal(mockDB.securityEvents.callCount, 1, 'db.securityEvents was called') + t.equal(securityQuery.uid, uid) + t.equal(securityQuery.ipAddr, clientAddress) + + t.equal(!!record, true, 'log.info was called for Account.history') + t.equal(record.op, 'Account.history.unverified') + t.equal(record.uid, uid.toString('hex')) + t.equal(record.events, 1) + }) + }) + + t.test('with a new ip address', function (t) { + record = undefined + + var securityQuery + mockDB.securityEvents = sinon.spy(function (arg) { + securityQuery = arg + return P.resolve([]) + }) + return runTest(route, mockRequest, function (response) { + t.equal(mockDB.securityEvents.callCount, 1, 'db.securityEvents was called') + t.equal(securityQuery.uid, uid) + t.equal(securityQuery.ipAddr, clientAddress) + + t.equal(record, undefined, 'log.info was not called for Account.history.verified') + }) + }) + + }) + + t.test('records security event', function (t) { + var clientAddress = mockRequest.app.clientAddress + var securityQuery + mockDB.securityEvent = sinon.spy(function (arg) { + securityQuery = arg + return P.resolve() + }) + return runTest(route, mockRequest, function (response) { + t.equal(mockDB.securityEvent.callCount, 1, 'db.securityEvent was called') + t.equal(securityQuery.uid, uid) + t.equal(securityQuery.ipAddr, clientAddress) + t.equal(securityQuery.name, 'account.login') + }) + }) }) test('/recovery_email/verify_code', function (t) { diff --git a/test/mocks.js b/test/mocks.js index 63c042124..69a64bffb 100644 --- a/test/mocks.js +++ b/test/mocks.js @@ -15,8 +15,9 @@ var DB_METHOD_NAMES = ['account', 'createAccount', 'createDevice', 'createKeyFet 'createPasswordForgotToken', 'createSessionToken', 'deleteAccount', 'deleteDevice', 'deleteKeyFetchToken', 'deletePasswordChangeToken', 'deleteVerificationReminder', 'devices', 'emailRecord', 'resetAccount', - 'sessions', 'sessionTokenWithVerificationStatus', 'updateDevice', - 'updateLocale', 'updateSessionToken', 'verifyEmail', 'verifyTokens'] + 'securityEvent', 'securityEvents', 'sessions', + 'sessionTokenWithVerificationStatus', 'updateDevice', 'updateLocale', + 'updateSessionToken', 'verifyEmail', 'verifyTokens'] var LOG_METHOD_NAMES = ['trace', 'increment', 'info', 'error', 'begin', 'warn', 'timing', 'activityEvent', 'flowEvent', 'notifyAttachedServices'] @@ -53,7 +54,8 @@ function mockDB (data, errors) { emailCode: data.emailCode, emailVerified: data.emailVerified, uid: data.uid, - verifierSetAt: Date.now() + verifierSetAt: Date.now(), + wrapWrapKb: data.wrapWrapKb }) }), createAccount: sinon.spy(function () { @@ -124,6 +126,9 @@ function mockDB (data, errors) { wrapWrapKb: crypto.randomBytes(32) }) }), + securityEvents: sinon.spy(function () { + return P.resolve([]) + }), sessions: sinon.spy(function () { return P.resolve(data.sessions || []) }),