auth: add logs when auth fails or succeeds

src/users.js

@@ -18,7 +18,7 @@ exports = module.exports = {
     getAdmins,
     getSuperadmins,
 
-    verify,
+    verifyWithId,
     verifyWithUsername,
     verifyWithEmail,
 
@@ -357,21 +357,23 @@ async function verifyAppPassword(userId, password, identifier) {
 }
 
 // identifier is only used to check if password is valid for a specific app
-async function verify(userId, password, identifier, options) {
-    assert.strictEqual(typeof userId, 'string');
+async function verify(user, password, identifier, options) {
+    assert.strictEqual(typeof user, 'object');
     assert.strictEqual(typeof password, 'string');
     assert.strictEqual(typeof identifier, 'string');
     assert.strictEqual(typeof options, 'object');
 
-    const user = await get(userId);
-    if (!user) throw new BoxError(BoxError.NOT_FOUND, 'User not found');
-    if (!user.active) throw new BoxError(BoxError.NOT_FOUND, 'User not active');
+    if (!user.active) {
+        debug(`verify: ${user.username} is not active`);
+        throw new BoxError(BoxError.NOT_FOUND, 'User not active');
+    }
 
     // for just invited users the username may be still null
     if (user.username) {
         const valid = await verifyGhost(user.username, password);
 
         if (valid) {
+            debug(`verify: ${user.username} authenticated via impersonation`);
             user.ghost = true;
             return user;
         }
@@ -379,6 +381,7 @@ async function verify(userId, password, identifier, options) {
 
     const [error] = await safe(verifyAppPassword(user.id, password, identifier));
     if (!error) { // matched app password
+        debug(`verify: ${user.username || user.id} matched app password`);
         user.appPassword = true;
         return user;
     }
@@ -394,7 +397,10 @@ async function verify(userId, password, identifier, options) {
         if (error) throw new BoxError(BoxError.CRYPTO_ERROR, error);
 
         const derivedKeyHex = Buffer.from(derivedKey, 'binary').toString('hex');
-        if (derivedKeyHex !== user.password) throw new BoxError(BoxError.INVALID_CREDENTIALS, 'Wrong password');
+        if (derivedKeyHex !== user.password) {
+            debug(`verify: ${user.username || user.id} provided incorrect password`);
+            throw new BoxError(BoxError.INVALID_CREDENTIALS, 'Wrong password');
+        }
 
         localTotpCheck = user.twoFactorAuthenticationEnabled;
     }
@@ -405,9 +411,25 @@ async function verify(userId, password, identifier, options) {
         if (!verified) throw new BoxError(BoxError.INVALID_CREDENTIALS, 'Invalid totpToken');
     }
 
+    debug(`verify: ${user.username || user.id} authenticated`);
     return user;
 }
 
+async function verifyWithId(id, password, identifier, options) {
+    assert.strictEqual(typeof id, 'string');
+    assert.strictEqual(typeof password, 'string');
+    assert.strictEqual(typeof identifier, 'string');
+    assert.strictEqual(typeof options, 'object');
+
+    const user = await get(id);
+    if (!user) {
+        debug(`verifyWithId: ${id} not found`);
+        throw new BoxError(BoxError.NOT_FOUND, 'User not found');
+    }
+
+    return await verify(user, password, identifier, options);
+}
+
 async function verifyWithUsername(username, password, identifier, options) {
     assert.strictEqual(typeof username, 'string');
     assert.strictEqual(typeof password, 'string');
@@ -415,16 +437,19 @@ async function verifyWithUsername(username, password, identifier, options) {
     assert.strictEqual(typeof options, 'object');
 
     const user = await getByUsername(username.toLowerCase());
-    if (user) return await verify(user.id, password, identifier, options);
+    if (user) return await verify(user, password, identifier, options);
 
     const [error, newUserId] = await safe(externalLdap.maybeCreateUser(username.toLowerCase()));
-    if (error && error.reason === BoxError.BAD_STATE) throw new BoxError(BoxError.NOT_FOUND, 'User not found'); // no external ldap or no auto create
+    if (error && error.reason === BoxError.BAD_STATE) {
+        debug(`verifyWithUsername: ${username} not found`);
+        throw new BoxError(BoxError.NOT_FOUND, 'User not found'); // no external ldap or no auto create
+    }
     if (error) {
         debug(`verifyWithUsername: failed to auto create user ${username}. %o`, error);
         throw new BoxError(BoxError.NOT_FOUND, 'User not found');
     }
 
-    return await verify(newUserId, password, identifier, options);
+    return await verifyWithId(newUserId, password, identifier, options);
 }
 
 async function verifyWithEmail(email, password, identifier, options) {
@@ -434,9 +459,12 @@ async function verifyWithEmail(email, password, identifier, options) {
     assert.strictEqual(typeof options, 'object');
 
     const user = await getByEmail(email.toLowerCase());
-    if (!user) throw new BoxError(BoxError.NOT_FOUND, 'User not found');
+    if (!user) {
+        debug(`verifyWithEmail: ${email} no such user`);
+        throw new BoxError(BoxError.NOT_FOUND, 'User not found');
+    }
 
-    return await verify(user.id, password, identifier, options);
+    return await verify(user, password, identifier, options);
 }
 
 async function del(user, auditSource) {