diff --git a/services/web/app/src/Features/User/UserAuditLogHandler.mjs b/services/web/app/src/Features/User/UserAuditLogHandler.mjs index 21e4ac85c2..12fe990608 100644 --- a/services/web/app/src/Features/User/UserAuditLogHandler.mjs +++ b/services/web/app/src/Features/User/UserAuditLogHandler.mjs @@ -102,12 +102,29 @@ async function addEntry(userId, operation, initiatorId, ipAddress, info = {}) { await UserAuditLogEntry.create(entry) } +function addEntryInBackground( + userId, + operation, + initiatorId, + ipAddress, + info = {} +) { + // Intentionally not awaited + addEntry(userId, operation, initiatorId, ipAddress, info).catch(err => { + logger.error( + { err, userId, operation, initiatorId, ipAddress, info }, + 'error adding user audit log entry' + ) + }) +} + const UserAuditLogHandler = { MANAGED_GROUP_USER_EVENTS, addEntry: callbackify(addEntry), promises: { addEntry, }, + addEntryInBackground, } export default UserAuditLogHandler diff --git a/services/web/app/src/Features/User/UserController.mjs b/services/web/app/src/Features/User/UserController.mjs index 88b09691d7..2c50334aba 100644 --- a/services/web/app/src/Features/User/UserController.mjs +++ b/services/web/app/src/Features/User/UserController.mjs @@ -473,6 +473,16 @@ async function doLogout(req) { logger.debug({ user }, 'logging out') const sessionId = req.sessionID + if (user != null) { + UserAuditLogHandler.addEntryInBackground( + user._id, + 'logout', + user._id, + req.ip, + {} + ) + } + if (typeof req.logout === 'function') { // passport logout const logout = promisify(req.logout.bind(req)) diff --git a/services/web/test/acceptance/src/SessionTests.mjs b/services/web/test/acceptance/src/SessionTests.mjs index 9a265020db..a106a14368 100644 --- a/services/web/test/acceptance/src/SessionTests.mjs +++ b/services/web/test/acceptance/src/SessionTests.mjs @@ -68,6 +68,70 @@ describe('Sessions', function () { } ) }) + + it('should update audit log on logout', function (done) { + async.series( + [ + next => { + redis.clearUserSessions(this.user1, next) + }, + + // login + next => { + this.user1.login(err => next(err)) + }, + + // logout, should add logout audit log entry (happens in background) + next => { + this.user1.logout(err => next(err)) + }, + + // poll for audit log entry since it's written in the background + next => { + let attempts = 0 + const checkAuditLog = () => { + this.user1.getAuditLogWithoutNoise((error, auditLog) => { + if (error) return next(error) + + const logoutEntries = auditLog.filter( + entry => entry.operation === 'logout' + ) + + // If we found the logout entry, we're done + if (logoutEntries.length > 0) { + expect(logoutEntries.length).to.be.greaterThan(0) + const lastLogout = logoutEntries[logoutEntries.length - 1] + expect(lastLogout.operation).to.equal('logout') + expect(lastLogout.ipAddress).to.exist + expect(lastLogout.initiatorId).to.exist + expect(lastLogout.timestamp).to.exist + return next() + } + + // Otherwise retry up to 10 times + attempts++ + if (attempts >= 10) { + return next( + new Error( + 'Logout audit log entry not found after 10 attempts' + ) + ) + } + + setTimeout(checkAuditLog, 25) + }) + } + checkAuditLog() + }, + ], + (err, result) => { + if (err) { + throw err + } + done() + } + ) + }) }) describe('two sessions', function () { @@ -465,11 +529,19 @@ describe('Sessions', function () { this.user1.getAuditLogWithoutNoise((error, auditLog) => { expect(error).not.to.exist expect(auditLog).to.exist - expect(auditLog[0].operation).to.equal('clear-sessions') - expect(auditLog[0].ipAddress).to.exist - expect(auditLog[0].initiatorId).to.exist - expect(auditLog[0].timestamp).to.exist - expect(auditLog[0].info.sessions.length).to.equal(2) + + // find the clear-sessions entry + const clearSessionsEntries = auditLog.filter( + entry => entry.operation === 'clear-sessions' + ) + expect(clearSessionsEntries.length).to.equal(1) + expect(clearSessionsEntries[0].operation).to.equal( + 'clear-sessions' + ) + expect(clearSessionsEntries[0].ipAddress).to.exist + expect(clearSessionsEntries[0].initiatorId).to.exist + expect(clearSessionsEntries[0].timestamp).to.exist + expect(clearSessionsEntries[0].info.sessions.length).to.equal(2) next() }) }, diff --git a/services/web/test/acceptance/src/helpers/UserHelper.mjs b/services/web/test/acceptance/src/helpers/UserHelper.mjs index aea5ca66ee..d14d41c4c3 100644 --- a/services/web/test/acceptance/src/helpers/UserHelper.mjs +++ b/services/web/test/acceptance/src/helpers/UserHelper.mjs @@ -58,6 +58,16 @@ class UserHelper { }) } + /** + * Get auditLog by operation + * @return {object[]} + */ + getAuditLogByOperation(operation) { + return (this.user.auditLog || []).filter(entry => { + return entry.operation === operation + }) + } + /** * Generate default email from unique (per instantiation) user number * @returns {string} email diff --git a/services/web/test/unit/src/User/UserController.test.mjs b/services/web/test/unit/src/User/UserController.test.mjs index 22a371723c..303f767a08 100644 --- a/services/web/test/unit/src/User/UserController.test.mjs +++ b/services/web/test/unit/src/User/UserController.test.mjs @@ -120,6 +120,7 @@ describe('UserController', function () { promises: { addEntry: sinon.stub().resolves(), }, + addEntryInBackground: sinon.stub(), } ctx.RequestContentTypeDetection = {