Merge pull request #290 from PerimeterX/feature/header-based-logger

Feature/header based logger and added start_enforcer_timestamp&sending_risk_timestamp
PerimeterX · Dec 2, 2023 · d72329d · d72329d
2 parents ec05ce3 + fd13db7
commit d72329d
Show file tree

Hide file tree

Showing 15 changed files with 106 additions and 35 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -5,6 +5,16 @@ All notable changes to this project will be documented in this file.
 The format is based on [Keep a Changelog](http://keepachangelog.com/)
 and this project adheres to [Semantic Versioning](http://semver.org/).
 
+
+## [3.12.0] - 2023-XX-XX
+
+### Added 
+- Support for header-based logger feature
+- Added `risk_start_time` and `enforcer_start_time` fields to enforcer activities.
+
+### Changed
+- Changed the structure of the headers field on async activities to array
+
 ## [3.11.0] - 2023-05-16
 
 ### Changed

diff --git a/lib/enums/CookieOrigin.js b/lib/enums/CookieOrigin.js
@@ -1,5 +1,4 @@
 const CookieOrigin = {
-    NONE: undefined,
     COOKIE: 'cookie',
     HEADER: 'header'
 };

diff --git a/lib/pxapi.js b/lib/pxapi.js
@@ -120,7 +120,7 @@ function buildRequestData(ctx, config) {
         data.vid = vid;
     }
     if (uuid) {
-        data.uuid = uuid;
+        data.client_uuid = uuid;
     }
     if (pxhd) {
         data.pxhd = pxhd;
@@ -150,6 +150,11 @@ function buildRequestData(ctx, config) {
     if (ctx.hmac) {
         data.additional['px_cookie_hmac'] = ctx.hmac;
     }
+
+    data.additional['enforcer_start_time'] = ctx.enforcerStartTime;
+    ctx.riskStartTime = Date.now();
+    data.additional['risk_start_time'] = ctx.riskStartTime;
+
     return data;
 }
 

diff --git a/lib/pxclient.js b/lib/pxclient.js
@@ -45,9 +45,13 @@ class PxClient {
 
         this.addAdditionalFieldsToActivity(details, ctx);
         if (activityType !== ActivityType.ADDITIONAL_S2S) {
-            activity.headers = ctx.headers;
+            activity.headers = pxUtil.formatHeaders(ctx.headers, config.SENSITIVE_HEADERS);
             activity.pxhd = (ctx.pxhdServer ? ctx.pxhdServer : ctx.pxhdClient) || undefined;
             pxUtil.prepareCustomParams(config, details, ctx.originalRequest);
+
+            if (ctx.riskStartTime) {
+                details['risk_start_time'] = ctx.riskStartTime;
+            }
         }
 
         activity.details = details;

diff --git a/lib/pxconfig.js b/lib/pxconfig.js
@@ -102,7 +102,8 @@ class PxConfig {
             ['JWT_HEADER_NAME', 'px_jwt_header_name'],
             ['JWT_HEADER_USER_ID_FIELD_NAME', 'px_jwt_header_user_id_field_name'],
             ['JWT_HEADER_ADDITIONAL_FIELD_NAMES', 'px_jwt_header_additional_field_names'],
-            ['CUSTOM_IS_SENSITIVE_REQUEST', 'px_custom_is_sensitive_request']
+            ['CUSTOM_IS_SENSITIVE_REQUEST', 'px_custom_is_sensitive_request'],
+            ['LOGGER_AUTH_TOKEN', 'px_logger_auth_token']
         ];
 
         configKeyMapping.forEach(([targetKey, sourceKey]) => {
@@ -361,7 +362,8 @@ function pxDefaultConfig() {
         JWT_HEADER_NAME: '',
         JWT_HEADER_USER_ID_FIELD_NAME: '',
         JWT_HEADER_ADDITIONAL_FIELD_NAMES: [],
-        CUSTOM_IS_SENSITIVE_REQUEST: ''
+        CUSTOM_IS_SENSITIVE_REQUEST: '',
+        LOGGER_AUTH_TOKEN: ''
     };
 }
 
@@ -434,7 +436,8 @@ const allowedConfigKeys = [
     'px_jwt_header_name',
     'px_jwt_header_user_id_field_name',
     'px_jwt_header_additional_field_names',
-    'px_custom_is_sensitive_request'
+    'px_custom_is_sensitive_request',
+    'px_logger_auth_token'
 ];
 
 module.exports = PxConfig;
diff --git a/lib/pxcontext.js b/lib/pxcontext.js
@@ -11,7 +11,7 @@ class PxContext {
         const mobileSdkHeader = 'x-px-authorization';
         const mobileSdkOriginalTokenHeader = 'x-px-original-token';
         const vidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/;
-
+        this.enforcerStartTime = Date.now();
         this.cookies = {};
         this.score = 0;
         this.ip = pxUtil.extractIP(config, req);

diff --git a/lib/pxcookie.js b/lib/pxcookie.js
@@ -25,7 +25,6 @@ function evalCookie(ctx, config) {
         if (!pxCookie) {
             config.logger.debug('Cookie is missing');
             ctx.s2sCallReason = 'no_cookie';
-            ctx.cookieOrigin = CookieOrigin.NONE;
             return ScoreEvaluateAction.NO_COOKIE;
         }
 

diff --git a/lib/pxenforcer.js b/lib/pxenforcer.js
@@ -30,6 +30,7 @@ const {
     CI_CREDENTIALS_COMPROMISED_FIELD,
 } = require('./utils/constants');
 const pxCors = require('./pxcors');
+const { LogServiceClient } = require('./pxlogserviceclient');
 
 class PxEnforcer {
     constructor(params, client) {
@@ -44,8 +45,11 @@ class PxEnforcer {
             this.config.configLoader = new ConfigLoader(this.pxConfig, this.pxClient);
             this.config.configLoader.init();
         }
+
         this.reversePrefix = this.pxConfig.conf.PX_APP_ID.substring(2);
         this.initializeCredentialsIntelligence(this.logger, this._config);
+
+        this.logServiceClient = new LogServiceClient(this._config, this.pxClient);
     }
 
     initializeCredentialsIntelligence(logger, config) {
@@ -178,12 +182,12 @@ class PxEnforcer {
         if (this._config.WHITELIST_ROUTES && this._config.WHITELIST_ROUTES.length > 0) {
             for (const whitelistRoute of this._config.WHITELIST_ROUTES) {
                 if (whitelistRoute instanceof RegExp && req.originalUrl.match(whitelistRoute)) {
-                    this.logger.debug(`Found whitelist route by Regex ${req.originalUrl}`);
+                    this.logger.debug(`Filter request due to whitelist route by Regex ${req.originalUrl}`);
                     return true;
                 }
 
                 if (typeof whitelistRoute === 'string' && req.originalUrl.startsWith(whitelistRoute)) {
-                    this.logger.debug(`Found whitelist route ${req.originalUrl}`);
+                    this.logger.debug(`Filter request due to whitelist route ${req.originalUrl}`);
                     return true;
                 }
             }
@@ -413,6 +417,7 @@ class PxEnforcer {
             cookie_origin: ctx.cookieOrigin,
             http_method: ctx.httpMethod,
             request_cookie_names: ctx.requestCookieNames,
+            enforcer_start_time: ctx.enforcerStartTime,
         };
     }
 
@@ -615,6 +620,14 @@ class PxEnforcer {
             cb(htmlTemplate);
         });
     }
+
+    sendHeaderBasedLogs(pxCtx, config, req) {
+        const headerValue = pxCtx ? pxCtx.headers[Constants.X_PX_ENFORCER_LOG_HEADER] : req.headers[Constants.X_PX_ENFORCER_LOG_HEADER];
+        if (headerValue && headerValue === config.LOGGER_AUTH_TOKEN) {
+            this.logServiceClient.sendLogs(pxCtx, config.logger.logs, req);
+        }
+        config.logger.logs = [];
+    }
 }
 
 module.exports = PxEnforcer;
diff --git a/lib/pxlogger.js b/lib/pxlogger.js
@@ -7,31 +7,34 @@ const { LoggerSeverity } = require('./enums/LoggerSeverity');
 
 class PxLogger {
     constructor(params) {
-        this.loggerEnabled = params.px_logger_severity !== LoggerSeverity.NONE;
-        this.debugMode = params.px_logger_severity === LoggerSeverity.DEBUG || false;
+        this.debugMode = params.px_logger_severity === LoggerSeverity.DEBUG;
+        this.loggerSeverity = params.px_logger_severity;
         this.appId = params.px_app_id || 'PX_APP_ID';
         this.internalLogger = params.customLogger || console;
+        this.logs = [];
     }
 
     debug(msg) {
-        if (!this.loggerEnabled) {
-            return;
-        }
+        this.recordLog(msg, LoggerSeverity.DEBUG);
         if (this.debugMode && typeof msg === 'string') {
             this.internalLogger.info(`[PerimeterX - DEBUG][${this.appId}] - ${msg}`);
         }
     }
 
     error(msg) {
-        if (!this.loggerEnabled) {
-            return;
-        }
-        if (typeof msg === 'string') {
+        this.recordLog(msg, LoggerSeverity.ERROR);
+        if (this.loggerSeverity !== LoggerSeverity.NONE && typeof msg === 'string') {
             this.internalLogger.error(
                 new Error(`[PerimeterX - ERROR][${this.appId}] - ${msg}`).stack
             );
         }
     }
+
+    recordLog(message, loggerSeverity) {
+        const logRecord = { message: message, severity: loggerSeverity, messageTimestamp: Date.now() };
+        this.logs.push(logRecord);
+    }
+
 }
 
 module.exports = PxLogger;
diff --git a/lib/pxlogserviceclient.js b/lib/pxlogserviceclient.js
@@ -0,0 +1,41 @@
+const { EXTERNAL_LOGGER_SERVICE_PATH } = require('./utils/constants');
+
+class LogServiceClient {
+    constructor(config, pxClient) {
+        this.config = config;
+        this.appId = config.PX_APP_ID;
+        this.pxClient = pxClient;
+    }
+
+    sendLogs(pxCtx, logs, req) {
+        try {
+            const enrichedLogs = logs.map((log) => this.enrichLogRecord(pxCtx, log, req));
+            this.postLogs(enrichedLogs);
+        } catch (e) {
+            this.config.logger.error(`unable to send logs: + ${e}`);
+        }
+    }
+
+    enrichLogRecord(pxCtx, logs, req) {
+        const logMetadata = {
+            container: 'enforcer',
+            appID: this.appId,
+            method: pxCtx ? pxCtx.httpMethod : req.method || '',
+            host: pxCtx ? pxCtx.hostname : req.hostname || req.get('host'),
+            path: pxCtx ? pxCtx.uri : req.originalUrl || '/',
+            requestId: pxCtx ? pxCtx.requestId : ''
+        };
+
+        return { ... logMetadata, ...logs };
+    }
+
+    postLogs(enrichLogs) {
+        const reqHeaders = {
+            Authorization: 'Bearer ' + this.config.LOGGER_AUTH_TOKEN
+        };
+
+        this.pxClient.callServer(enrichLogs, EXTERNAL_LOGGER_SERVICE_PATH, reqHeaders, this.config);
+    }
+}
+
+module.exports = { LogServiceClient };
diff --git a/lib/pxproxy.js b/lib/pxproxy.js
@@ -28,7 +28,7 @@ function getCaptcha(req, config, ip, reversePrefix, cb) {
     const searchMask = `/${reversePrefix}${config.FIRST_PARTY_CAPTCHA_PATH}`;
     const regEx = new RegExp(searchMask, 'ig');
     const pxRequestUri =  `/${config.PX_APP_ID}${req.originalUrl.replace(regEx, '')}`;
-    config.logger.debug(`Forwarding request from ${req.originalUrl} to xhr at ${config.CAPTCHA_HOST}${pxRequestUri}`);
+    config.logger.debug(`Forwarding first party request from ${req.originalUrl} to xhr at ${config.CAPTCHA_HOST}${pxRequestUri}`);
     const callData = {
         url: `https://${config.CAPTCHA_HOST}${pxRequestUri}`,
         headers: pxUtil.filterSensitiveHeaders(req.headers, config.SENSITIVE_HEADERS),
@@ -71,7 +71,7 @@ function getClient(req, config, ip, cb) {
     }
     let res = {};
     const clientRequestUri = `/${config.PX_APP_ID}/main.min.js`;
-    config.logger.debug(`Forwarding request from ${req.originalUrl.toLowerCase()} to client at ${config.CLIENT_HOST}${clientRequestUri}`);
+    config.logger.debug(`Forwarding first party request from ${req.originalUrl.toLowerCase()} to client at ${config.CLIENT_HOST}${clientRequestUri}`);
     const callData = {
         url: `https://${config.CLIENT_HOST}${clientRequestUri}`,
         headers: pxUtil.filterSensitiveHeaders(req.headers, config.SENSITIVE_HEADERS),
@@ -174,7 +174,7 @@ function sendXHR(req, config, ip, reversePrefix, cb) {
         const searchMask = `/${reversePrefix}${config.FIRST_PARTY_XHR_PATH}`;
         const regEx = new RegExp(searchMask, 'ig');
         const pxRequestUri = req.originalUrl.replace(regEx, '');
-        config.logger.debug(`Forwarding request from ${req.originalUrl} to xhr at ${config.COLLECTOR_HOST}${pxRequestUri}`);
+        config.logger.debug(`Forwarding first party request from ${req.originalUrl} to xhr at ${config.COLLECTOR_HOST}${pxRequestUri}`);
 
         const callData = {
             url: `https://${config.COLLECTOR_HOST}${pxRequestUri}`,

diff --git a/lib/utils/constants.js b/lib/utils/constants.js
@@ -36,6 +36,9 @@ const JWT_ADDITIONAL_FIELDS_FIELD_NAME = 'jwt_additional_fields';
 const CROSS_TAB_SESSION = 'cross_tab_session';
 const COOKIE_SEPARATOR = ';';
 
+const X_PX_ENFORCER_LOG_HEADER = 'x-px-enforcer-log';
+const EXTERNAL_LOGGER_SERVICE_PATH = '/enforcer-logs/';
+
 module.exports = {
     MILLISECONDS_IN_SECOND,
     SECONDS_IN_MINUTE,
@@ -66,4 +69,6 @@ module.exports = {
     JWT_ADDITIONAL_FIELDS_FIELD_NAME,
     CROSS_TAB_SESSION,
     COOKIE_SEPARATOR,
+    X_PX_ENFORCER_LOG_HEADER,
+    EXTERNAL_LOGGER_SERVICE_PATH
 };
diff --git a/package-lock.json b/package-lock.json
diff --git a/test/pxenforcer.test.js b/test/pxenforcer.test.js
@@ -433,7 +433,7 @@ describe('PX Enforcer - pxenforcer.js', () => {
         enforcer = new pxenforcer(curParams, pxClient);
         enforcer.enforce(req, null, (error, response) => {
             should(error).not.be.ok();
-            pxLoggerSpy.debug.calledWith('Found whitelist route /profile').should.equal(true);
+            pxLoggerSpy.debug.calledWith('Filter request due to whitelist route /profile').should.equal(true);
             (response === undefined).should.equal(true);
             done();
         });
@@ -459,7 +459,7 @@ describe('PX Enforcer - pxenforcer.js', () => {
         enforcer = new pxenforcer(curParams, pxClient);
         enforcer.enforce(req, null, (error, response) => {
             should(error).not.be.ok();
-            pxLoggerSpy.debug.calledWith('Found whitelist route by Regex /profile').should.equal(true);
+            pxLoggerSpy.debug.calledWith('Filter request due to whitelist route by Regex /profile').should.equal(true);
             (response === undefined).should.equal(true);
             done();
         });

diff --git a/test/pxlogger.test.js b/test/pxlogger.test.js
@@ -24,7 +24,6 @@ describe('PX Logger - pxlogger.js', () => {
     it('sets default properties', (done) => {
         logger = new PxLogger(params);
 
-        logger.debugMode.should.equal(false);
         logger.appId.should.equal('PX_APP_ID');
         logger.internalLogger.should.be.exactly(console);
         done();
@@ -48,8 +47,6 @@ describe('PX Logger - pxlogger.js', () => {
         params.px_logger_severity = false;
         logger = new PxLogger(params);
 
-        logger.debugMode.should.equal(false);
-
         logger.error('there was an error');
         console.error.calledOnce.should.equal(true);