Improved user authentication log and added 'authlog' tracing.

Ylian Saint-Hilaire committed Sep 1, 2022 at 22:06 UTC 49e04bd454587f1cef44d5c4bfccdc964cbd9811
3 files changed +38 -30
meshcentral.js
+10 -5
@@ -739,7 +739,6 @@ function CreateMeshCentralServer(config, args) {
739 obj.syslogjson.log(obj.syslogjson.LOG_INFO, "MeshCentral v" + getCurrentVersion() + " Server Start");
740 }
741 if (typeof config.settings.syslogauth == 'string') {
742 - obj.authlog = true;
742 obj.syslogauth = require('modern-syslog');
743 console.log('Starting ' + config.settings.syslogauth + ' auth syslog.');
744 obj.syslogauth.init(config.settings.syslogauth, obj.syslogauth.LOG_PID | obj.syslogauth.LOG_ODELAY, obj.syslogauth.LOG_LOCAL0);
@@ -1231,7 +1230,7 @@ function CreateMeshCentralServer(config, args) {
1230 // Linux format /var/log/auth.log
1231 if (obj.config.settings.authlog != null) {
1232 obj.fs.open(obj.config.settings.authlog, 'a', function (err, fd) {
1234 - if (err == null) { obj.authlogfile = fd; obj.authlog = true; } else { console.log('ERROR: Unable to open: ' + obj.config.settings.authlog); }
1233 + if (err == null) { obj.authlogfile = fd; } else { console.log('ERROR: Unable to open: ' + obj.config.settings.authlog); }
1234 })
1235 }
1236
@@ -3642,14 +3641,20 @@ function CreateMeshCentralServer(config, args) {
3641 obj.addServerWarning = function (msg, id, args, print) { serverWarnings.push({ msg: msg, id: id, args: args }); if (print !== false) { console.log("WARNING: " + msg); } }
3642
3643 // auth.log functions
3645 - obj.authLog = function (server, msg) {
3644 + obj.authLog = function (server, msg, args) {
3645 if (typeof msg != 'string') return;
3647 - if (obj.syslogauth != null) { try { obj.syslogauth.log(obj.syslogauth.LOG_INFO, msg); } catch (ex) { } }
3646 + var str = msg;
3647 + if (args != null) {
3648 + if (typeof args.sessionid == 'string') { str += ', SessionID: ' + args.sessionid; }
3649 + if (typeof args.useragent == 'string') { const userAgentInfo = obj.webserver.getUserAgentInfo(args.useragent); str += ', Browser: ' + userAgentInfo.browserStr + ', OS: ' + userAgentInfo.osStr; }
3650 + }
3651 + obj.debug('authlog', str);
3652 + if (obj.syslogauth != null) { try { obj.syslogauth.log(obj.syslogauth.LOG_INFO, str); } catch (ex) { } }
3653 if (obj.authlogfile != null) { // Write authlog to file
3654 try {
3655 const d = new Date(), month = ['Jan', 'Feb', 'Mar', 'Apr', 'May', 'Jun', 'Jul', 'Aug', 'Sep', 'Oct', 'Nov', 'Dec'][d.getMonth()];
3656 msg = month + ' ' + d.getDate() + ' ' + obj.common.zeroPad(d.getHours(), 2) + ':' + obj.common.zeroPad(d.getMinutes(), 2) + ':' + d.getSeconds() + ' meshcentral ' + server + '[' + process.pid + ']: ' + msg + ((obj.platform == 'win32') ? '\r\n' : '\n');
3652 - obj.fs.write(obj.authlogfile, msg, function (err, written, string) { });
3657 + obj.fs.write(obj.authlogfile, str, function (err, written, string) { });
3658 } catch (ex) { console.log(ex); }
3659 }
3660 }
views/default.handlebars
+3 -2
@@ -17325,6 +17325,7 @@
17325 x += '<div><label><input type=checkbox id=p41c6 ' + ((serverTraceSources.indexOf('webrequest') >= 0) ? 'checked' : '') + '>' + "Web Server Requests" + '</label></div>';
17326 x += '<div><label><input type=checkbox id=p41c7 ' + ((serverTraceSources.indexOf('relay') >= 0) ? 'checked' : '') + '>' + "Web Socket Relay" + '</label></div>';
17327 x += '<div><label><input type=checkbox id=p41c20 ' + ((serverTraceSources.indexOf('httpheaders') >= 0) ? 'checked' : '') + '>' + "Web Server HTTP Headers" + '</label></div>';
17328 + x += '<div><label><input type=checkbox id=p41c21 ' + ((serverTraceSources.indexOf('authlog') >= 0) ? 'checked' : '') + '>' + "User Authentication Log" + '</label></div>';
17329 //x += '<div><label><input type=checkbox id=p41c8 ' + ((serverTraceSources.indexOf('webrelaydata') >= 0) ? 'checked' : '') + '>' + "Traffic Relay 2 Data" + '</label></div>';
17330 x += '<div style="width:100%;border-bottom:1px solid gray;margin-bottom:5px;margin-top:5px"><b>' + "Intel&reg; AMT" + '</b></div>';
17331 x += '<div><label><input type=checkbox id=p41c19 ' + ((serverTraceSources.indexOf('amt') >= 0) ? 'checked' : '') + '>' + "Intel AMT manager" + '</label></div>';
@@ -17339,8 +17340,8 @@
17340 }
17341
17342 function setServerTracingEx(b) {
17342 - var sources = [], allsources = ['cookie', 'dispatch', 'main', 'peer', 'web', 'webrequest', 'relay', 'webrelaydata', 'webrelay', 'mps', 'mpscmd', 'swarm', 'swarmcmd', 'agentupdate', 'agent', 'cert', 'db', 'email', 'amt', 'httpheaders'];
17343 - if (b == 1) { for (var i = 1; i < 21; i++) { try { if (Q('p41c' + i).checked) { sources.push(allsources[i - 1]); } } catch (ex) { } } }
17343 + var sources = [], allsources = ['cookie', 'dispatch', 'main', 'peer', 'web', 'webrequest', 'relay', 'webrelaydata', 'webrelay', 'mps', 'mpscmd', 'swarm', 'swarmcmd', 'agentupdate', 'agent', 'cert', 'db', 'email', 'amt', 'httpheaders', 'authlog'];
17344 + if (b == 1) { for (var i = 1; i < 22; i++) { try { if (Q('p41c' + i).checked) { sources.push(allsources[i - 1]); } } catch (ex) { } } }
17345 meshserver.send({ action: 'traceinfo', traceSources: sources });
17346 }
17347
webserver.js
+25 -23
@@ -788,7 +788,10 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
788 var userid = req.session.userid;
789 if (req.session.userid) {
790 var user = obj.users[req.session.userid];
791 - if (user != null) { obj.parent.DispatchEvent(['*'], obj, { etype: 'user', userid: user._id, username: user.name, action: 'logout', msgid: 2, msg: 'Account logout', domain: domain.id }); }
791 + if (user != null) {
792 + obj.parent.authLog('https', 'User ' + user.name + ' logout from ' + req.clientIp + ' port ' + req.connection.remotePort, { sessionid: req.session.x, useragent: req.headers['user-agent'] });
793 + obj.parent.DispatchEvent(['*'], obj, { etype: 'user', userid: user._id, username: user.name, action: 'logout', msgid: 2, msg: 'Account logout', domain: domain.id });
794 + }
795 if (req.session.x) { clearDestroyedSessions(); obj.destroyedSessions[req.session.userid + '/' + req.session.x] = Date.now(); } // Destroy this session
796 }
797 req.session = null;
@@ -1175,9 +1178,9 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1178 if ((req.body.token != null) || (req.body.hwtoken != null)) {
1179 randomWaitTime = 2000 + (obj.crypto.randomBytes(2).readUInt16BE(0) % 4095); // This is a fail, wait a random time. 2 to 6 seconds.
1180 req.session.messageid = 108; // Invalid token, try again.
1178 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Failed 2FA for ' + xusername + ' from ' + cleanRemoteAddr(req.clientIp) + ' port ' + req.port); }
1181 + obj.parent.authLog('https', 'Failed 2FA for ' + xusername + ' from ' + cleanRemoteAddr(req.clientIp) + ' port ' + req.port, { useragent: req.headers['user-agent'] });
1182 parent.debug('web', 'handleLoginRequest: invalid 2FA token');
1180 - const ua = getUserAgentInfo(req);
1183 + const ua = obj.getUserAgentInfo(req);
1184 obj.parent.DispatchEvent(['*', 'server-users', user._id], obj, { action: 'authfail', username: user.name, userid: user._id, domain: domain.id, msg: 'User login attempt with incorrect 2nd factor from ' + req.clientIp, msgid: 108, msgArgs: [req.clientIp, ua.browserStr, ua.osStr] });
1185 obj.setbad2Fa(req);
1186 } else {
@@ -1215,7 +1218,6 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1218 }
1219
1220 // Login successful
1218 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Accepted password for ' + xusername + ' from ' + req.clientIp + ' port ' + req.connection.remotePort); }
1221 parent.debug('web', 'handleLoginRequest: successful 2FA login');
1222 if (authData != null) { if (loginOptions == null) { loginOptions = {}; } loginOptions.twoFactorType = authData.twoFactorType; }
1223 completeLoginRequest(req, res, domain, user, userid, xusername, xpassword, direct, loginOptions);
@@ -1237,13 +1239,12 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1239 }
1240
1241 // Login successful
1240 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Accepted password for ' + xusername + ' from ' + req.clientIp + ' port ' + req.connection.remotePort); }
1242 parent.debug('web', 'handleLoginRequest: successful login');
1243 if (twoFactorSkip != null) { if (loginOptions == null) { loginOptions = {}; } loginOptions.twoFactorType = twoFactorSkip.twoFactorType; }
1244 completeLoginRequest(req, res, domain, user, userid, xusername, xpassword, direct, loginOptions);
1245 } else {
1246 // Login failed, log the error
1246 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Failed password for ' + xusername + ' from ' + req.clientIp + ' port ' + req.connection.remotePort); }
1247 + obj.parent.authLog('https', 'Failed password for ' + xusername + ' from ' + req.clientIp + ' port ' + req.connection.remotePort, { useragent: req.headers['user-agent'] });
1248
1249 // Wait a random delay
1250 setTimeout(function () {
@@ -1253,19 +1254,19 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1254 if (err == 'locked') {
1255 parent.debug('web', 'handleLoginRequest: login failed, locked account');
1256 req.session.messageid = 110; // Account locked.
1256 - const ua = getUserAgentInfo(req);
1257 + const ua = obj.getUserAgentInfo(req);
1258 obj.parent.DispatchEvent(['*', 'server-users', xuserid], obj, { action: 'authfail', userid: xuserid, username: xusername, domain: domain.id, msg: 'User login attempt on locked account from ' + req.clientIp, msgid: 109, msgArgs: [req.clientIp, ua.browserStr, ua.osStr] });
1259 obj.setbadLogin(req);
1260 } else if (err == 'denied') {
1261 parent.debug('web', 'handleLoginRequest: login failed, access denied');
1262 req.session.messageid = 111; // Access denied.
1262 - const ua = getUserAgentInfo(req);
1263 + const ua = obj.getUserAgentInfo(req);
1264 obj.parent.DispatchEvent(['*', 'server-users', xuserid], obj, { action: 'authfail', userid: xuserid, username: xusername, domain: domain.id, msg: 'Denied user login from ' + req.clientIp, msgid: 155, msgArgs: [req.clientIp, ua.browserStr, ua.osStr] });
1265 obj.setbadLogin(req);
1266 } else {
1267 parent.debug('web', 'handleLoginRequest: login failed, bad username and password');
1268 req.session.messageid = 112; // Login failed, check username and password.
1268 - const ua = getUserAgentInfo(req);
1269 + const ua = obj.getUserAgentInfo(req);
1270 obj.parent.DispatchEvent(['*', 'server-users', xuserid], obj, { action: 'authfail', userid: xuserid, username: xusername, domain: domain.id, msg: 'Invalid user login attempt from ' + req.clientIp, msgid: 110, msgArgs: [req.clientIp, ua.browserStr, ua.osStr] });
1271 obj.setbadLogin(req);
1272 }
@@ -1311,7 +1312,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1312 // Notify account login
1313 const targets = ['*', 'server-users', user._id];
1314 if (user.groups) { for (var i in user.groups) { targets.push('server-users:' + i); } }
1314 - const ua = getUserAgentInfo(req);
1315 + const ua = obj.getUserAgentInfo(req);
1316 const loginEvent = { etype: 'user', userid: user._id, username: user.name, account: obj.CloneSafeUser(user), action: 'login', msgid: 107, msgArgs: [req.clientIp, ua.browserStr, ua.osStr], msg: 'Account login from ' + req.clientIp + ', ' + ua.browserStr + ', ' + ua.osStr, domain: domain.id, ip: req.clientIp, userAgent: req.headers['user-agent'], rport: req.connection.remotePort };
1317 if (loginOptions != null) {
1318 if ((loginOptions.tokenName != null) && (loginOptions.tokenUser != null)) { loginEvent.tokenName = loginOptions.tokenName; loginEvent.tokenUser = loginOptions.tokenUser; } // If a login token was used, add it to the event.
@@ -1339,6 +1340,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1340 req.session.userid = userid;
1341 req.session.ip = req.clientIp;
1342 setSessionRandom(req);
1343 + obj.parent.authLog('https', 'Accepted password for ' + xusername + ' from ' + req.clientIp + ' port ' + req.connection.remotePort, { useragent: req.headers['user-agent'], sessionid: req.session.x });
1344
1345 // If a login token was used, add this information and expire time to the session.
1346 if ((loginOptions != null) && (loginOptions.tokenName != null) && (loginOptions.tokenUser != null)) {
@@ -1731,7 +1733,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1733 req.session.messageid = 4; // SMS sent.
1734 } else {
1735 req.session.messageid = 108; // Invalid token, try again.
1734 - const ua = getUserAgentInfo(req);
1736 + const ua = obj.getUserAgentInfo(req);
1737 obj.parent.DispatchEvent(['*', 'server-users', user._id], obj, { action: 'authfail', username: user.name, userid: user._id, domain: domain.id, msg: 'User login attempt with incorrect 2nd factor from ' + req.clientIp, msgid: 108, msgArgs: [req.clientIp, ua.browserStr, ua.osStr] });
1738 obj.setbad2Fa(req);
1739 }
@@ -1917,7 +1919,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1919 obj.parent.DispatchEvent([user._id], obj, { action: 'notify', title: 'Email verified', value: user.email, nolog: 1, id: Math.random() });
1920
1921 // Send to authlog
1920 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Verified email address ' + user.email + ' for user ' + user.name); }
1922 + obj.parent.authLog('https', 'Verified email address ' + user.email + ' for user ' + user.name, { useragent: req.headers['user-agent'] });
1923 }
1924 });
1925 }
@@ -1953,7 +1955,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
1955 parent.debug('web', 'handleCheckMailRequest: send temporary password.');
1956
1957 // Send to authlog
1956 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Performed account reset for user ' + user.name); }
1958 + obj.parent.authLog('https', 'Performed account reset for user ' + user.name);
1959 }, 0);
1960 });
1961 } else {
@@ -2558,7 +2560,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
2560 // Notify account login using SSO
2561 var targets = ['*', 'server-users', user._id];
2562 if (user.groups) { for (var i in user.groups) { targets.push('server-users:' + i); } }
2561 - const ua = getUserAgentInfo(req);
2563 + const ua = obj.getUserAgentInfo(req);
2564 const loginEvent = { etype: 'user', userid: user._id, username: user.name, account: obj.CloneSafeUser(user), action: 'login', msgid: 107, msgArgs: [req.clientIp, ua.browserStr, ua.osStr], msg: 'Account login', domain: domain.id, ip: req.clientIp, userAgent: req.headers['user-agent'], twoFactorType: 'sso' };
2565 obj.parent.DispatchEvent(targets, obj, loginEvent);
2566 } else {
@@ -2590,7 +2592,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
2592 // Notify account login using SSO
2593 var targets = ['*', 'server-users', user._id];
2594 if (user.groups) { for (var i in user.groups) { targets.push('server-users:' + i); } }
2593 - const ua = getUserAgentInfo(req);
2595 + const ua = obj.getUserAgentInfo(req);
2596 const loginEvent = { etype: 'user', userid: user._id, username: user.name, account: obj.CloneSafeUser(user), action: 'login', msgid: 107, msgArgs: [req.clientIp, ua.browserStr, ua.osStr], msg: 'Account login', domain: domain.id, ip: req.clientIp, userAgent: req.headers['user-agent'], twoFactorType: 'sso' };
2597 obj.parent.DispatchEvent(targets, obj, loginEvent);
2598 }
@@ -2630,11 +2632,10 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
2632 // Login using SSPI
2633 domain.sspi.authenticate(req, res, function (err) {
2634 if ((err != null) || (req.connection.user == null)) {
2633 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Failed SSPI-auth for ' + req.connection.user + ' from ' + req.clientIp + ' port ' + req.connection.remotePort); }
2635 + obj.parent.authLog('https', 'Failed SSPI-auth for ' + req.connection.user + ' from ' + req.clientIp + ' port ' + req.connection.remotePort, { useragent: req.headers['user-agent'] });
2636 parent.debug('web', 'handleRootRequest: SSPI auth required.');
2637 res.sendStatus(401);
2638 } else {
2637 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Accepted SSPI-auth for ' + req.connection.user + ' from ' + req.clientIp + ' port ' + req.connection.remotePort); }
2639 parent.debug('web', 'handleRootRequest: SSPI auth ok.');
2640 handleRootRequestEx(req, res, domain, direct);
2641 }
@@ -2644,12 +2645,12 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
2645 obj.authenticate(req.query.user, req.query.pass, domain, function (err, userid, passhint, loginOptions) {
2646 if ((userid != null) && (err == null)) {
2647 // Login success
2647 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Accepted password for ' + userid + ' from ' + req.clientIp + ' port ' + req.connection.remotePort); }
2648 parent.debug('web', 'handleRootRequest: user/pass in URL auth ok.');
2649 req.session.userid = userid;
2650 delete req.session.currentNode;
2651 req.session.ip = req.clientIp; // Bind this session to the IP address of the request
2652 setSessionRandom(req);
2653 + obj.parent.authLog('https', 'Accepted password for ' + userid + ' from ' + req.clientIp + ' port ' + req.connection.remotePort, { useragent: req.headers['user-agent'], sessionid: req.session.x });
2654 handleRootRequestEx(req, res, domain, direct);
2655 } else {
2656 // Login failed
@@ -2728,6 +2729,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
2729 delete req.session.currentNode;
2730 req.session.ip = req.clientIp; // Bind this session to the IP address of the request
2731 setSessionRandom(req);
2732 + obj.parent.authLog('https', 'Accepted SSPI-auth for ' + req.connection.user + ' from ' + req.clientIp + ' port ' + req.connection.remotePort, { useragent: req.headers['user-agent'], sessionid: req.session.x });
2733
2734 // Check if this user exists, create it if not.
2735 user = obj.users[req.session.userid];
@@ -7508,7 +7510,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
7510 });
7511 obj.parent.updateServerState('servername', certificates.CommonName);
7512 }
7511 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Server listening on ' + ((addr != null) ? addr : '0.0.0.0') + ' port ' + port + '.'); }
7513 + obj.parent.authLog('https', 'Server listening on ' + ((addr != null) ? addr : '0.0.0.0') + ' port ' + port + '.');
7514 obj.parent.updateServerState('https-port', port);
7515 if (args.aliasport != null) { obj.parent.updateServerState('https-aliasport', args.aliasport); }
7516 } else {
@@ -7545,7 +7547,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
7547 } else {
7548 obj.tcpAltServer = obj.tlsAltServer.listen(port, addr, function () { console.log('MeshCentral HTTPS agent-only server running on ' + certificates.CommonName + ':' + port + ((agentAliasPort != null) ? (', alias port ' + agentAliasPort) : '') + '.'); });
7549 }
7548 - if (obj.parent.authlog) { obj.parent.authLog('https', 'Server listening on 0.0.0.0 port ' + port + '.'); }
7550 + obj.parent.authLog('https', 'Server listening on 0.0.0.0 port ' + port + '.');
7551 obj.parent.updateServerState('https-agent-port', port);
7552 } else {
7553 obj.tcpAltServer = obj.agentapp.listen(port, addr, function () { console.log('MeshCentral HTTP agent-only server running on port ' + port + ((agentAliasPort != null) ? (', alias port ' + agentAliasPort) : '') + '.'); });
@@ -8511,10 +8513,10 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
8513 }
8514
8515 // Return decoded user agent information
8514 - function getUserAgentInfo(req) {
8516 + obj.getUserAgentInfo = function(req) {
8517 var browser = 'Unknown', os = 'Unknown';
8518 try {
8517 - const ua = obj.uaparser(req.headers['user-agent']);
8519 + const ua = obj.uaparser((typeof req == 'string') ? req : req.headers['user-agent']);
8520 if (ua.browser && ua.browser.name) { ua.browserStr = ua.browser.name; if (ua.browser.version) { ua.browserStr += '/' + ua.browser.version } }
8521 if (ua.os && ua.os.name) { ua.osStr = ua.os.name; if (ua.os.version) { ua.osStr += '/' + ua.os.version } }
8522 return ua;
@@ -8837,7 +8839,7 @@ module.exports.CreateWebServer = function (parent, db, args, certificates, doneF
8839 parent.DispatchEvent(['*', ugrpid, user._id], obj, event); // Even if DB change stream is active, this event must be acted upon.
8840
8841 // Log in the auth log
8840 - if (parent.authlog) { parent.authLog('https', 'Created ' + userMembershipType + ' user group ' + ugrp.name); }
8842 + parent.authLog('https', 'Created ' + userMembershipType + ' user group ' + ugrp.name);
8843 }
8844
8845 if (existingUserMemberships[ugrpid] == null) {