diff --git a/CHANGES_NEXT_RELEASE b/CHANGES_NEXT_RELEASE index f1486f6c..3aded622 100644 --- a/CHANGES_NEXT_RELEASE +++ b/CHANGES_NEXT_RELEASE @@ -1,2 +1,6 @@ +- Add: user name, request path, query and body to AccessLogger (#541) +- Add: Access Logger Patterns to match to Access Logger (#541) +- Fix: ensure Origin of AccesLogger show x-forwarderd-for header if exists +- Fix: use pipe-separeted format in Access Logger instead of JSON (closer to pep regular log) - Upgrade body-parser dep from 1.20.0 to 1.20.3 - Upgrade express from 4.19.2 to 4.20.0 diff --git a/README.md b/README.md index a0c460e0..5ec962b4 100644 --- a/README.md +++ b/README.md @@ -25,7 +25,7 @@ * [Development documentation](#development) ## Overview -The Orion Policy Enforcement Point (PEP) is a proxy meant to secure independent FiWare components, by intercepting every request sent to the component, validating it against the Access Control component. This validation is based in several pieces of data: +The Policy Enforcement Point (PEP) is a proxy meant to secure independent FiWare components, by intercepting every request sent to the component, validating it against the Access Control component. This validation is based in several pieces of data: * User token: comes from the OAuth authorization server and is taken from the `x-auth-token` header. * ServiceId: is read from the `fiware-service` header and identifies the protected component. @@ -439,23 +439,80 @@ In order to have the proxy running, there are several basic pieces of informatio port: 7070, path: '/pdp/v3', account: false, - accountFile: '/tmp/pepAccount.log' + accountFile: '/tmp/pepAccount.log', + accountMode: 'all' } ``` -Accounting log is only activated when account flag is true, and the logs are produced in a fixed INFO level for accountLogger, redardless of the pep log level. -Note that accunting log is not rotate, so you should make sure you configure your own rotation system. -Accounting access log include daba about: +Accounting log is only activated when account flag is true, and the logs are produced in a fixed INFO level for accessLogger, redardless of the pep log level. +Note that accounting log is not rotated, so you should make sure you configure your own rotation system. +Accounting access log include data about: * Attempt was right or not * Token * Origin * UserId +* UserName * ServiceId +* Service * SubServiceId +* SubService * Action +* Path +* Body * Date +* Query Example of access log: ``` -Right Attempt | ResponseStatus=200 | Token=860864fb6d1a4c8a8cb7d59d16daaa52 | Origin=192.168.1.125 | UserId=62c63ada8694451fb67a341346172499 | ServiceId=a9b38dd2a97e4944b2daebdb74ed60ff | Service=smartgondor | SubServiceId=/ | SubService=/ | Action=read | Date=2017-09-21T12:46:57.844Z +"Right Attempt | ResponseStatus=200 | Token=gAAAAABnBPgPrgwpcAkbQOZIryu5ADUIScyorN3vbPYbTJxTE5AF3RO1y25Tf-sL3EKzvfr_1U3u8IL8ylB4e4B_vD5yZjc9rnrSIqoiC77B7uZ1O1xZCyukq_MkjRxJLqA9yQ5lQtAQCC6ig7Kn5uPhpPD-mhVb7kyQjUw1QjtCiyP7UKXZvKU | Origin=172.17.0.22 | UserId=753b954985bf460fabbd6953c71d50c7 | UserName=adm1 | ServiceId=9f710408f5944c3993db600810e97c83 | Service=smartcity | SubServiceId=/ | SubService=/ | Action=read | Path=/v2/entities | Query={\"limit\":\"15\",\"offset\":\"0\",\"options\":\"count\"} | Body={} | Date=2024-10-08T09:25:30.441Z" +``` + +Note that the above format is not the same than the regular PEP log (although it is also based in fields separated by `|`, the fields themselves are not the same). + +Additionally a file configAccessMatch could be provided to pep to check matches about some elements involved in current access, regardless is right or not right access. For example: +* List for users involved +* List of headers and values +* List of subpaths in URL request +* List of subqueries in query request +* List of strings in body + +PEP reloads this file each time it changes without needing restarting PEP itself. + +This is an example of file `configAccessMatch.js` (full path `/opt/fiware-pep-steelskin/configAccessMatch.js` i.e. in a docker image): + +``` +// Activity related with a list of users +configAccessMatch.users = [ + 'cracker1', 'cracker2', +]; + +// Activity related with request which the following headers +configAccessMatch.headers = [ + { "fiware-service": "smartcity" }, + { "x-real-ip": "127.0.0.1" } +]; + +// Activity related with request including the following subpaths +configAccessMatch.subpaths = [ + '/v1', +]; + +// Activity related with request including the following subqueries +configAccessMatch.subqueries = [ + 'flowControl', 'options', +]; + +// Activity related with request including the following strings in body +configAccessMatch.body = [ + 'legacy', +]; +``` + +When any of theses patterns matches in current access, message access is added with `MATCHED ` , where `` would be: `USER`, `HEADER `, `SUBPATH`, `SUBQUERY`, `BODY` and `` the value which matches. For example: + +``` +Right Attempt MATCHED HEADER fiware-service smartcity | ResponseStatus=200 | Token=gAAAAABnBPgPrgwpcAkbQOZIryu5ADUIScyorN3vbPYbTJxTE5AF3RO1y25Tf-sL3EKzvfr_1U3u8IL8ylB4e4B_vD5yZjc9rnrSIqoiC77B7uZ1O1xZCyukq_MkjRxJLqA9yQ5lQtAQCC6ig7Kn5uPhpPD-mhVb7kyQjUw1QjtCiyP7UKXZvKU | Origin=172.17.0.22 | UserId=753b954985bf460fabbd6953c71d50c7 | UserName=adm1 | ServiceId=9f710408f5944c3993db600810e97c83 | Service=smartcity | SubServiceId=/ | SubService=/ | Action=read | Path=/v2/entities | Query={\"limit\":\"15\",\"offset\":\"0\",\"options\":\"count\"} | Body={} | Date=2024-10-08T09:25:30.441Z" +``` +Account log has three modes: `all`, `matched`, `wrong`. First one `all` includes right and wrong access regardles if matches or not. Second one `matched` includes all wrong and just rigth matches acess. And `wrong` mode only includes all wrong access, regardless is matches or not with patterns. + ``` * `config.componentName`: name of the component that will be used to compose the FRN that will identify the resource to be accessed. E.g.: `orion`. * `config.resourceNamePrefix`: string prefix that will be used to compose the FRN that will identify the resource to be accessed. E.g.: `fiware:`. diff --git a/bin/pepProxy b/bin/pepProxy index b74da75f..19068beb 100755 --- a/bin/pepProxy +++ b/bin/pepProxy @@ -48,6 +48,7 @@ function loadConfiguration() { 'ACCESS_PROTOCOL', 'ACCESS_ACCOUNT', 'ACCESS_ACCOUNTFILE', + 'ACCESS_ACCOUNTMODE', 'ADMIN_PORT', 'AUTHENTICATION_HOST', 'AUTHENTICATION_PORT', @@ -103,6 +104,9 @@ function loadConfiguration() { if (process.env.ACCESS_ACCOUNTFILE) { config.access.accountFile = process.env.ACCESS_ACCOUNTFILE; } + if (process.env.ACCESS_ACCOUNTMODE) { + config.access.accountMode = process.env.ACCESS_ACCOUNTMODE; + } if (process.env.AUTHENTICATION_HOST) { config.authentication.options.host = process.env.AUTHENTICATION_HOST; } diff --git a/config.js b/config.js index 8c03e488..233446ff 100644 --- a/config.js +++ b/config.js @@ -64,7 +64,11 @@ config.access = { /** * Log Account file */ - accountFile: '/tmp/pepAccount.log' + accountFile: '/tmp/pepAccount.log', + /** + * Account mode: `all`, `matched`, `wrong` + */ + accountMode: 'all' }; // User identity configuration diff --git a/configAccessMatch.js b/configAccessMatch.js new file mode 100644 index 00000000..7a945182 --- /dev/null +++ b/configAccessMatch.js @@ -0,0 +1,35 @@ +'use strict'; + +/** + * List of access match + */ +var configAccessMatch = {}; + +// Activity related with a list of users +configAccessMatch.users = [ + // 'user1', 'user2', +]; + +// Activity related with request which the following headers +configAccessMatch.headers = [ + // { "fiware-service": "smartcity" }, + // { "x-real-ip": "127.0.0.1" } +]; + +// Activity related with request including the following subpaths +configAccessMatch.subpaths = [ + // '/v1', +]; + +// Activity related with request including the following subqueries +configAccessMatch.subqueries = [ + // 'flowControl', +]; + +// Activity related with request including the following strings in body +configAccessMatch.body = [ + // 'legacy' +]; + + +exports.configAccessMatch = configAccessMatch; diff --git a/lib/constants.js b/lib/constants.js index 83f71072..d955013b 100644 --- a/lib/constants.js +++ b/lib/constants.js @@ -32,7 +32,8 @@ var constants = { X_REAL_IP_HEADER: 'x-real-ip', CORRELATOR_HEADER: 'fiware-correlator', - GET_ROLES_PATH: '/user' + GET_ROLES_PATH: '/user', + NA: 'N/A' }; diff --git a/lib/fiware-pep-steelskin.js b/lib/fiware-pep-steelskin.js index 6be28ed3..65e7ee86 100644 --- a/lib/fiware-pep-steelskin.js +++ b/lib/fiware-pep-steelskin.js @@ -74,14 +74,22 @@ function handleError(error, req, res, next) { * @param {Function} next Call to the next error handler in the chain. */ function accountInfoError(error, req, res, next) { - accessLogger.info('Wrong Attempt' + + var accessMsg = 'Wrong Attempt'; + accessMsg = proxyMiddleware.checkAccessMatches(req, accessMsg); + accessLogger.info(accessMsg + ' | Error=' + error.name + ' | Token=' + req.headers['x-auth-token'] + - ' | Origin=' + req.connection.remoteAddress + + ' | Origin=' + (req.ip || req.connection.remoteAddress) + ' | UserId=' + req.userId + + ' | ServiceId=' + req.serviceId + + ' | UserName=' + req.userName + ' | Service=' + req.service + + ' | SubServiceId=' + req.subserviceId + ' | SubService=' + req.subService + ' | Action=' + req.action + + ' | Path=' + req.path + + ' | Query=' + JSON.stringify(req.query) + + ' | Body=' + JSON.stringify(req.body) + ' | Date=' + new Date().toJSON()); next(error); } @@ -114,10 +122,14 @@ function setAccessLogger() { level: 'info', transports: [ new(winston.transports.File)({ - filename: config.access.accountFile + filename: config.access.accountFile, + json: false, + timestamp: false, + showLevel: false }) ] }); + proxyMiddleware.watchConfigAccessMatchFile(); } /** diff --git a/lib/middleware/proxy.js b/lib/middleware/proxy.js index 86878da7..d600795b 100644 --- a/lib/middleware/proxy.js +++ b/lib/middleware/proxy.js @@ -36,8 +36,30 @@ var config = require('../../config'), 'x-auth-token' ], winston = require('winston'), + logger = require('logops'), + configAccessMatch = require('../../configAccessMatch.js').configAccessMatch, accessLogger; +const fs = require('fs'); +const configAccessMatchFilePath = './configAccessMatch.js'; + +function requireUncached(module) { + delete require.cache[require.resolve(module)]; + return require(module); +} + +function watchConfigAccessMatchFile() { + fs.watch(configAccessMatchFilePath, (event, filename) => { + logger.info('watchConfigAccessMatchFile changed by %s detected in file %s', event, filename); + try { + configAccessMatch = requireUncached('../../configAccessMatch.js').configAccessMatch; + logger.debug('reloaded configAccessMatch %j', configAccessMatch); + } catch (err) { + logger.error('Error %s reloading module: %s ', err, filename); + } + }); +} + /** * Middleware to extract the organization data from the request. * @@ -175,6 +197,44 @@ function sendRequest(req, res, next) { next(); } +/** + * Check here MATCH file patterns + * + * @param {Object} req Incoming request. + * @param {String} accessMsg Incoming accessMsg + * @return {String} String message corresponding with accessMsg and found matches + */ +function checkAccessMatches(req, accessMsg) { + if (req.userName in configAccessMatch.users ) { + accessMsg += ' MATCHED USER ' + req.userName; + } + for (var header of configAccessMatch.headers) { + var headerName = Object.keys(header)[0]; + if (Object.keys(req.headers).includes(headerName)) { + if (req.headers[headerName] === header[headerName]) { + accessMsg += ' MATCHED HEADER ' + headerName + ' ' + header[headerName]; + } + } + } + for (var subpath of configAccessMatch.subpaths) { + if (req.path.includes(subpath)) { + accessMsg += ' MATCHED SUBPATH ' + subpath; + } + } + for (var subquery of configAccessMatch.subqueries) { + if (JSON.stringify(req.query).includes(subquery)) { + accessMsg += ' MATCHED SUBQUERY ' + subquery; + } + } + for (var text of configAccessMatch.body) { + if (JSON.stringify(req.body).includes(text)) { + accessMsg += ' MATCHED BODY ' + text; + } + } + return accessMsg; +} + + /** * Account Log * read to guess its type. @@ -190,23 +250,40 @@ function accountInfo(req, res, next) { level: 'info', transports: [ new(winston.transports.File)({ - filename: config.access.accountFile + filename: config.access.accountFile, + json: false, + timestamp: false, + showLevel: false }) ] }); } req.fwdResponse = req.fwdResponse.on('response', function(res) { - accessLogger.info('Right Attempt' + - ' | ResponseStatus=' + req.fwdResponse.response.statusCode + - ' | Token=' + req.headers['x-auth-token'] + - ' | Origin=' + req.connection.remoteAddress + - ' | UserId=' + req.userId + - ' | ServiceId=' + req.serviceId + - ' | Service=' + req.service + - ' | SubServiceId=' + req.subserviceId + - ' | SubService=' + req.subService + - ' | Action=' + req.action + - ' | Date=' + new Date().toJSON()); + var accessMsgOrig = 'Right Attempt'; + var accessMsg = accessMsgOrig; + if (! ['wrong'].includes(config.access.accountMode) ) { + accessMsg = checkAccessMatches(req, accessMsgOrig); + } + if ( ['all'].includes(config.access.accountMode) || + (['matched'].includes(config.access.accountMode) && + accessMsgOrig.length < accessMsg.length) ){ + + accessLogger.info(accessMsg + + ' | ResponseStatus=' + req.fwdResponse.response.statusCode + + ' | Token=' + req.headers['x-auth-token'] + + ' | Origin=' + (req.ip || req.connection.remoteAddress) + + ' | UserId=' + req.userId + + ' | UserName=' + req.userName + + ' | ServiceId=' + req.serviceId + + ' | Service=' + req.service + + ' | SubServiceId=' + req.subserviceId + + ' | SubService=' + req.subService + + ' | Action=' + req.action + + ' | Path=' + req.path + + ' | Query=' + JSON.stringify(req.query) + + ' | Body=' + JSON.stringify(req.body).slice(0, 100) + // not all body + ' | Date=' + new Date().toJSON()); + } }); } next(); @@ -257,3 +334,5 @@ exports.sendResponse = sendResponse; exports.accountInfo = accountInfo; exports.checkMandatoryHeaders = checkMandatoryHeaders(validationHeaders); exports.checkAuthorizationHeader = checkMandatoryHeaders(authorizationHeaders); +exports.watchConfigAccessMatchFile = watchConfigAccessMatchFile; +exports.checkAccessMatches = checkAccessMatches; diff --git a/lib/services/keystoneAuth.js b/lib/services/keystoneAuth.js index a695d677..f95f813d 100644 --- a/lib/services/keystoneAuth.js +++ b/lib/services/keystoneAuth.js @@ -191,6 +191,7 @@ function retrieveUser(req, callback) { req.serviceId = cachedValue.serviceId; req.domainName = cachedValue.domainName; req.userId = cachedValue.userId; + req.userName = cachedValue.userName; logger.debug('User value processed with value: %j', cachedValue); @@ -245,9 +246,12 @@ function retrieveUser(req, callback) { cachedValue = { domainName: body.token.project.domain.name, serviceId: body.token.project.domain.id, - userId: body.token['OS-TRUST:trust'].trustor_user.id + userId: body.token['OS-TRUST:trust'].trustor_user.id, + userName: constants.NA }; - + if (body.token.user) { + cachedValue.userName = body.token.user.name; + } innerCb(null, cachedValue); } else if (body.token && body.token.user && body.token.user.domain && @@ -256,7 +260,8 @@ function retrieveUser(req, callback) { cachedValue = { domainName: body.token.user.domain.name, serviceId: body.token.user.domain.id, - userId: body.token.user.id + userId: body.token.user.id, + userName: body.token.user.name }; req.userData = cachedValue; diff --git a/operations.md b/operations.md index 3e3b9252..7f6b7c03 100644 --- a/operations.md +++ b/operations.md @@ -26,6 +26,8 @@ curl -X GET "http://localhost:11211/admin/log" Every error message is identified with a prefix code in brackets. The code convention can be found in Apendix A. +There is another log about accounting access which is produced when access.account flag is enabled and is done over access.accountFile file. This accounting access logs right and wrong access attempts, providing for each one user, service, subservice, path, date and other relevant info about access. Additionally, some patterns could be configured in order to mark some of these access. + ## Cache management PEP keeps a memory cache with some access about roles, domains, users and subservices. Related with this info is possible