diff --git a/pom.xml b/pom.xml index 39cc6616..62250148 100644 --- a/pom.xml +++ b/pom.xml @@ -7,7 +7,7 @@ PerimeterX JAVA SDK com.perimeterx perimeterx-sdk - 6.7.0 + 6.7.0-rc-extended-logging jar PerimeterX Java SDK diff --git a/src/main/java/com/perimeterx/api/PerimeterX.java b/src/main/java/com/perimeterx/api/PerimeterX.java index e85a9eee..c65ed947 100644 --- a/src/main/java/com/perimeterx/api/PerimeterX.java +++ b/src/main/java/com/perimeterx/api/PerimeterX.java @@ -69,6 +69,7 @@ import java.util.Base64; import static com.perimeterx.utils.Constants.*; +import static com.perimeterx.utils.PXCommonUtils.logTime; import static java.util.Objects.isNull; /** @@ -155,49 +156,53 @@ public PerimeterX(PXConfiguration configuration, HostnameProvider hostnameProvid * @throws PXException - PXException */ public PXContext pxVerify(HttpServletRequest req, HttpServletResponseWrapper responseWrapper) throws PXException { - PXContext context = null; - logger.debug(PXLogger.LogReason.DEBUG_STARTING_REQUEST_VERIFICATION); - - try { - if (isValidTelemetryRequest(req)) { - activityHandler.handleEnforcerTelemetryActivity(this.configuration, UpdateReason.COMMAND); - return null; - } - - if (!moduleEnabled()) { - logger.debug(PXLogger.LogReason.DEBUG_MODULE_DISABLED); - return null; - } - - context = new PXContext(req, this.ipProvider, this.hostnameProvider, configuration); + return logTime("pxVerify", () -> { + PXContext context = null; + logger.debug(PXLogger.LogReason.DEBUG_STARTING_REQUEST_VERIFICATION); + + try { + if (logTime("isValidTelemetryRequest", () -> isValidTelemetryRequest(req))) { + logTime("activityHandler.handleEnforcerTelemetryActivity", () -> activityHandler.handleEnforcerTelemetryActivity(this.configuration, UpdateReason.COMMAND)); + return null; + } - if (shouldReverseRequest(req, responseWrapper)) { - context.setFirstPartyRequest(true); - return context; - } + if (!moduleEnabled()) { + logger.debug(PXLogger.LogReason.DEBUG_MODULE_DISABLED); + return null; + } - //if path ext is defined at whitelist, let the request pass - if (configuration.isExtWhiteListed(req.getRequestURI())) { - return null; - } + context = logTime("new PXContext", () -> new PXContext(req, this.ipProvider, this.hostnameProvider, configuration)); - handleCookies(context); - addCustomHeadersToRequest(req, context); + if (logTime("shouldReverseRequest", () -> shouldReverseRequest(req, responseWrapper))) { + context.setFirstPartyRequest(true); + return context; + } - context.setVerified(verificationHandler.handleVerification(context, responseWrapper)); - } catch (Exception e) { - // If any general exception is being thrown, notify in page_request activity - if (context != null) { - if (!context.getS2sErrorReasonInfo().isErrorSet()) { - EnforcerErrorUtils.handleEnforcerError(context, "Unexpected error", e); + //if path ext is defined at whitelist, let the request pass + if (configuration.isExtWhiteListed(req.getRequestURI())) { + return null; } - activityHandler.handlePageRequestedActivity(context); - context.setVerified(true); + final PXContext finalContext = context; + logTime("handleCookies", () -> handleCookies(finalContext)); + logTime("addCustomHeadersToRequest", () -> addCustomHeadersToRequest(req, finalContext)); + + context.setVerified(logTime("verificationHandler.handleVerification", () -> verificationHandler.handleVerification(finalContext, responseWrapper))); + } catch (Exception e) { + final PXContext finalContext = context; + // If any general exception is being thrown, notify in page_request activity + if (context != null) { + if (!context.getS2sErrorReasonInfo().isErrorSet()) { + logTime("EnforcerErrorUtils.handleEnforcerError", () -> EnforcerErrorUtils.handleEnforcerError(finalContext, "Unexpected error", e)); + } + + logTime("activityHandler.handlePageRequestedActivity", () -> activityHandler.handlePageRequestedActivity(finalContext)); + context.setVerified(true); + } } - } - return context; + return context; + }); } private boolean moduleEnabled() { @@ -339,7 +344,7 @@ public void setVerificationHandler(VerificationHandler verificationHandler) { @Override public void close() throws IOException { - if(this.pxClient != null) { + if (this.pxClient != null) { this.pxClient.close(); } } diff --git a/src/main/java/com/perimeterx/api/verificationhandler/DefaultVerificationHandler.java b/src/main/java/com/perimeterx/api/verificationhandler/DefaultVerificationHandler.java index f4b27750..5d3e80fa 100644 --- a/src/main/java/com/perimeterx/api/verificationhandler/DefaultVerificationHandler.java +++ b/src/main/java/com/perimeterx/api/verificationhandler/DefaultVerificationHandler.java @@ -13,6 +13,7 @@ import java.io.UnsupportedEncodingException; import java.net.URLEncoder; +import static com.perimeterx.utils.PXCommonUtils.logTime; import static com.perimeterx.utils.PXLogger.LogReason.DEBUG_S2S_SCORE_IS_HIGHER_THAN_BLOCK; import static com.perimeterx.utils.PXLogger.LogReason.DEBUG_S2S_SCORE_IS_LOWER_THAN_BLOCK; @@ -35,29 +36,31 @@ public DefaultVerificationHandler(PXConfiguration pxConfiguration, ActivityHandl @Override public boolean handleVerification(PXContext context, HttpServletResponseWrapper responseWrapper) throws PXException { - boolean verified = shouldPassRequest(context); + boolean verified = logTime("shouldPassRequest", () -> shouldPassRequest(context)); - setPxhdCookie(context, responseWrapper); + logTime("setPxhdCookie", () -> setPxhdCookie(context, responseWrapper)); if (!verified && !context.isMonitoredRequest()) { - this.blockHandler.handleBlocking(context, this.pxConfiguration, responseWrapper); + logTime("blockHandler.handleBlocking",() -> this.blockHandler.handleBlocking(context, this.pxConfiguration, responseWrapper)); } - try { - if (verified) { - logger.debug("Passing request {} {}", verified, this.pxConfiguration.getModuleMode()); - - // Not blocking request and sending page_requested activity to px if configured as true - if (this.pxConfiguration.isSendPageActivities()) { - this.activityHandler.handlePageRequestedActivity(context); + logTime("anonymousAsyncActivitiesSender" , () -> { + try { + if (verified) { + logger.debug("Passing request {} {}", verified, this.pxConfiguration.getModuleMode()); + + // Not blocking request and sending page_requested activity to px if configured as true + if (this.pxConfiguration.isSendPageActivities()) { + this.activityHandler.handlePageRequestedActivity(context); + } + } else { + logger.debug("Request invalid"); + this.activityHandler.handleBlockActivity(context); } - } else { - logger.debug("Request invalid"); - this.activityHandler.handleBlockActivity(context); + } catch (PXException pxException) { + logger.error("Error occurred while handle activities", pxException); } - } catch (PXException pxException) { - logger.error("Error occurred while handle activities", pxException); - } + }); return verified || context.isMonitoredRequest(); } diff --git a/src/main/java/com/perimeterx/internals/PXCookieValidator.java b/src/main/java/com/perimeterx/internals/PXCookieValidator.java index 2a84d77e..66f1768b 100644 --- a/src/main/java/com/perimeterx/internals/PXCookieValidator.java +++ b/src/main/java/com/perimeterx/internals/PXCookieValidator.java @@ -11,6 +11,8 @@ import com.perimeterx.utils.PXLogger; import org.apache.commons.lang3.StringUtils; +import static com.perimeterx.utils.PXCommonUtils.logTime; + /** * PXCookieValidator *

@@ -40,7 +42,7 @@ public boolean verify(PXContext context) { if (context.isMobileToken()) { PXCookieOriginalTokenValidator mobileVerifier = new PXCookieOriginalTokenValidator(pxConfiguration); mobileError = mobileVerifier.getMobileError(context); - mobileVerifier.verify(context); + logTime("mobileVerifier.verify", () -> mobileVerifier.verify(context)); if (!StringUtils.isEmpty(mobileError)) { context.setS2sCallReason("mobile_error_" + mobileError); return false; diff --git a/src/main/java/com/perimeterx/internals/PXS2SValidator.java b/src/main/java/com/perimeterx/internals/PXS2SValidator.java index 6bbad4ef..1b4b2f46 100644 --- a/src/main/java/com/perimeterx/internals/PXS2SValidator.java +++ b/src/main/java/com/perimeterx/internals/PXS2SValidator.java @@ -15,6 +15,7 @@ import com.perimeterx.utils.PXLogger; import org.apache.http.conn.ConnectTimeoutException; +import static com.perimeterx.utils.PXCommonUtils.logTime; import static org.apache.commons.lang3.StringUtils.*; /** @@ -48,7 +49,7 @@ public boolean verify(PXContext pxContext) { long rtt; try { - response = pxClient.riskApiCall(pxContext); + response = logTime("pxClient.riskApiCall", () -> pxClient.riskApiCall(pxContext)); } catch (ConnectTimeoutException e) { // Timeout handling - report pass reason and proceed with request pxContext.setPassReason(PassReason.S2S_TIMEOUT); diff --git a/src/main/java/com/perimeterx/models/PXContext.java b/src/main/java/com/perimeterx/models/PXContext.java index 8f4ce821..b169f0c6 100644 --- a/src/main/java/com/perimeterx/models/PXContext.java +++ b/src/main/java/com/perimeterx/models/PXContext.java @@ -33,6 +33,7 @@ import static com.perimeterx.utils.Constants.BREACHED_ACCOUNT_KEY_NAME; import static com.perimeterx.utils.PXCommonUtils.cookieHeadersNames; +import static com.perimeterx.utils.PXCommonUtils.logTime; /** * PXContext - Populate relevant data from HttpRequest @@ -226,20 +227,20 @@ public PXContext(final HttpServletRequest request, final IPProvider ipProvider, } private void initContext(final HttpServletRequest request, PXConfiguration pxConfiguration) { - this.headers = PXCommonUtils.getHeadersFromRequest(request); + this.headers = logTime("PXCommonUtils.getHeadersFromRequest", () -> PXCommonUtils.getHeadersFromRequest(request)); if (headers.containsKey(Constants.MOBILE_SDK_AUTHORIZATION_HEADER) || headers.containsKey(Constants.MOBILE_SDK_TOKENS_HEADER)) { logger.debug(PXLogger.LogReason.DEBUG_MOBILE_SDK_DETECTED); this.isMobileToken = true; this.cookieOrigin = Constants.HEADER_ORIGIN; } - parseCookies(request, isMobileToken); - generateLoginData(request, pxConfiguration); + logTime("parseCookies", () -> parseCookies(request, isMobileToken)); + logTime("generateLoginData", () -> generateLoginData(request, pxConfiguration)); this.firstPartyRequest = false; this.userAgent = request.getHeader("user-agent"); this.uri = request.getRequestURI(); - this.fullUrl = extractURL(request); //full URL with query string + this.fullUrl = logTime("extractURL", () ->extractURL(request)); //full URL with query string this.blockReason = BlockReason.NONE; this.passReason = PassReason.NONE; this.s2sErrorReasonInfo = new S2SErrorReasonInfo(); @@ -257,9 +258,9 @@ private void initContext(final HttpServletRequest request, PXConfiguration pxCon Function customParametersExtraction = pxConfiguration.getCustomParametersExtraction(); try { if (customParametersExtraction != null) { - this.customParameters = customParametersExtraction.apply(this.request); + this.customParameters = logTime("customParametersExtraction.apply", () -> customParametersExtraction.apply(this.request)); } else { - this.customParameters = customParametersProvider.buildCustomParameters(pxConfiguration, this); + this.customParameters = logTime("customParametersProvider.buildCustomParameters", () -> customParametersProvider.buildCustomParameters(pxConfiguration, this)); } } catch (Exception e) { logger.debug("failed to extract custom parameters from custom function", e); @@ -327,41 +328,46 @@ private void parseCookies(HttpServletRequest request, boolean isMobileToken) { List tokens = new ArrayList<>(); List originalTokens = new ArrayList<>(); if (isMobileToken) { - headerParser = new MobileCookieHeaderParser(); + logTime("anonymousParseCookiesMobile", () -> { + // This was changed because it is not possible to override a value inside a function. + HeaderParser hp = new MobileCookieHeaderParser(); - String tokensHeader = request.getHeader(Constants.MOBILE_SDK_TOKENS_HEADER); - tokens.addAll(headerParser.createRawCookieDataList(tokensHeader)); + String tokensHeader = request.getHeader(Constants.MOBILE_SDK_TOKENS_HEADER); + tokens.addAll(hp.createRawCookieDataList(tokensHeader)); - String authCookieHeader = request.getHeader(Constants.MOBILE_SDK_AUTHORIZATION_HEADER); - tokens.addAll(headerParser.createRawCookieDataList(authCookieHeader)); + String authCookieHeader = request.getHeader(Constants.MOBILE_SDK_AUTHORIZATION_HEADER); + tokens.addAll(hp.createRawCookieDataList(authCookieHeader)); - String originalTokensHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKENS_HEADER); - originalTokens.addAll(headerParser.createRawCookieDataList(originalTokensHeader)); + String originalTokensHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKENS_HEADER); + originalTokens.addAll(hp.createRawCookieDataList(originalTokensHeader)); - String originalTokenHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKEN_HEADER); - originalTokens.addAll(headerParser.createRawCookieDataList(originalTokenHeader)); + String originalTokenHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKEN_HEADER); + originalTokens.addAll(hp.createRawCookieDataList(originalTokenHeader)); - this.tokens = tokens; - if (!originalTokens.isEmpty()) { - this.originalTokens = originalTokens; - } + this.tokens = tokens; + if (!originalTokens.isEmpty()) { + this.originalTokens = originalTokens; + } - ObjectMapper mapper = new ObjectMapper(); - this.pxde = mapper.createObjectNode(); - this.pxdeVerified = true; + ObjectMapper mapper = new ObjectMapper(); + this.pxde = mapper.createObjectNode(); + this.pxdeVerified = true; + }); } else { - Cookie[] cookies = request.getCookies(); - String[] cookieHeaders = cookieHeadersNames(getPxConfiguration()) - .stream() - .map(request::getHeader) - .toArray(String[]::new); - this.requestCookieNames = CookieNamesExtractor.extractCookieNames(cookies); - setVidAndPxhd(cookies); - tokens.addAll(headerParser.createRawCookieDataList(cookieHeaders)); - this.tokens = tokens; - DataEnrichmentCookie deCookie = headerParser.getRawDataEnrichmentCookie(this.tokens, this.pxConfiguration.getCookieKey()); - this.pxde = deCookie.getJsonPayload(); - this.pxdeVerified = deCookie.isValid(); + logTime("anonymousParseCookiesElse", () -> { + Cookie[] cookies = request.getCookies(); + String[] cookieHeaders = cookieHeadersNames(getPxConfiguration()) + .stream() + .map(request::getHeader) + .toArray(String[]::new); + this.requestCookieNames = CookieNamesExtractor.extractCookieNames(cookies); + setVidAndPxhd(cookies); + tokens.addAll(headerParser.createRawCookieDataList(cookieHeaders)); + this.tokens = tokens; + DataEnrichmentCookie deCookie = headerParser.getRawDataEnrichmentCookie(this.tokens, this.pxConfiguration.getCookieKey()); + this.pxde = deCookie.getJsonPayload(); + this.pxdeVerified = deCookie.isValid(); + }); } } diff --git a/src/main/java/com/perimeterx/utils/PXCallable.java b/src/main/java/com/perimeterx/utils/PXCallable.java new file mode 100644 index 00000000..e0776c98 --- /dev/null +++ b/src/main/java/com/perimeterx/utils/PXCallable.java @@ -0,0 +1,6 @@ +package com.perimeterx.utils; + +@FunctionalInterface +public interface PXCallable { + T apply() throws E; +} diff --git a/src/main/java/com/perimeterx/utils/PXCallableVoid.java b/src/main/java/com/perimeterx/utils/PXCallableVoid.java new file mode 100644 index 00000000..031950b7 --- /dev/null +++ b/src/main/java/com/perimeterx/utils/PXCallableVoid.java @@ -0,0 +1,6 @@ +package com.perimeterx.utils; + +@FunctionalInterface +public interface PXCallableVoid { + void apply() throws E; +} diff --git a/src/main/java/com/perimeterx/utils/PXCommonUtils.java b/src/main/java/com/perimeterx/utils/PXCommonUtils.java index 2a780681..c289c44f 100644 --- a/src/main/java/com/perimeterx/utils/PXCommonUtils.java +++ b/src/main/java/com/perimeterx/utils/PXCommonUtils.java @@ -17,6 +17,7 @@ * Created by nitzangoldfeder on 16/07/2017. */ public class PXCommonUtils { + private static final PXLogger logger = PXLogger.getLogger(PXCommonUtils.class); public static List

getDefaultHeaders(String authToken) { Header contentType = new BasicHeader(HttpHeaders.CONTENT_TYPE, "application/json"); @@ -59,4 +60,33 @@ public static List cookieHeadersNames(PXConfiguration configuration) { return lst; } + + /** + * Logs the runtime of a given function. returns the result of the execution + * whether it's a Throwable or value. + * + * @param methodName the name of the method to be logged + * @param f the function to execute + * @param type of successful execution + * @param type of failed execution + * @return the success result of the execution + * @throws E the throwable that will be thrown if the function fails + */ + public static T logTime(String methodName, PXCallable f) throws E { + long s = System.currentTimeMillis(); + try { + return f.apply(); + } finally { + long e = System.currentTimeMillis(); + logger.debug(String.format("TIMELOGGER - %s execution time is (%d)ms", methodName, e - s)); + } + } + + public static void logTime(String methodName, PXCallableVoid f) throws E { + // Using the other signature. + logTime(methodName, () -> { + f.apply(); + return null; + }); + } } diff --git a/web/pom.xml b/web/pom.xml index 8efd396a..b03aedaa 100644 --- a/web/pom.xml +++ b/web/pom.xml @@ -25,7 +25,7 @@ com.perimeterx perimeterx-sdk - 6.7.0 + 6.7.0-rc-extended-logging compile