Skip to content

Commit a4158aa

Browse files
guyeisenbachguyeisenbach
committed
Extension for version 6.7.0. Added logging for runtime of functions inside pxVerify 
1 parent 74d54c1 commit a4158aa

File tree

10 files changed

+120
-63
lines changed

10 files changed

+120
-63
lines changed

‎pom.xml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@
77
<name>PerimeterX JAVA SDK</name>
88
<groupId>com.perimeterx</groupId>
99
<artifactId>perimeterx-sdk</artifactId>
10-
<version>6.7.0</version>
10+
<version>6.7.0-rc-extended-logging</version>
1111

1212
<packaging>jar</packaging>
1313
<description>PerimeterX Java SDK</description>

‎src/main/java/com/perimeterx/api/PerimeterX.java

Lines changed: 12 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,7 @@
6969
import java.util.Base64;
7070

7171
import static com.perimeterx.utils.Constants.*;
72+
import static com.perimeterx.utils.PXCommonUtils.logTime;
7273
import static java.util.Objects.isNull;
7374

7475
/**
@@ -159,8 +160,8 @@ public PXContext pxVerify(HttpServletRequest req, HttpServletResponseWrapper res
159160
logger.debug(PXLogger.LogReason.DEBUG_STARTING_REQUEST_VERIFICATION);
160161

161162
try {
162-
if (isValidTelemetryRequest(req)) {
163-
activityHandler.handleEnforcerTelemetryActivity(this.configuration, UpdateReason.COMMAND);
163+
if (logTime("isValidTelemetryRequest", () -> isValidTelemetryRequest(req))) {
164+
logTime("activityHandler.handleEnforcerTelemetryActivity", () -> activityHandler.handleEnforcerTelemetryActivity(this.configuration, UpdateReason.COMMAND));
164165
return null;
165166
}
166167

@@ -169,9 +170,9 @@ public PXContext pxVerify(HttpServletRequest req, HttpServletResponseWrapper res
169170
return null;
170171
}
171172

172-
context = new PXContext(req, this.ipProvider, this.hostnameProvider, configuration);
173+
context = logTime("new PXContext", () -> new PXContext(req, this.ipProvider, this.hostnameProvider, configuration));
173174

174-
if (shouldReverseRequest(req, responseWrapper)) {
175+
if (logTime("shouldReverseRequest", () -> shouldReverseRequest(req, responseWrapper))) {
175176
context.setFirstPartyRequest(true);
176177
return context;
177178
}
@@ -181,18 +182,20 @@ public PXContext pxVerify(HttpServletRequest req, HttpServletResponseWrapper res
181182
return null;
182183
}
183184

184-
handleCookies(context);
185-
addCustomHeadersToRequest(req, context);
185+
final PXContext finalContext = context;
186+
logTime("handleCookies" , () -> handleCookies(finalContext));
187+
logTime("addCustomHeadersToRequest",() -> addCustomHeadersToRequest(req, finalContext));
186188

187-
context.setVerified(verificationHandler.handleVerification(context, responseWrapper));
189+
context.setVerified(logTime("verificationHandler.handleVerification", () -> verificationHandler.handleVerification(finalContext, responseWrapper)));
188190
} catch (Exception e) {
191+
final PXContext finalContext = context;
189192
// If any general exception is being thrown, notify in page_request activity
190193
if (context != null) {
191194
if (!context.getS2sErrorReasonInfo().isErrorSet()) {
192-
EnforcerErrorUtils.handleEnforcerError(context, "Unexpected error", e);
195+
logTime("EnforcerErrorUtils.handleEnforcerError", () -> EnforcerErrorUtils.handleEnforcerError(finalContext, "Unexpected error", e));
193196
}
194197

195-
activityHandler.handlePageRequestedActivity(context);
198+
logTime("activityHandler.handlePageRequestedActivity", () -> activityHandler.handlePageRequestedActivity(finalContext));
196199
context.setVerified(true);
197200
}
198201
}

‎src/main/java/com/perimeterx/api/verificationhandler/DefaultVerificationHandler.java

Lines changed: 19 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313
import java.io.UnsupportedEncodingException;
1414
import java.net.URLEncoder;
1515

16+
import static com.perimeterx.utils.PXCommonUtils.logTime;
1617
import static com.perimeterx.utils.PXLogger.LogReason.DEBUG_S2S_SCORE_IS_HIGHER_THAN_BLOCK;
1718
import static com.perimeterx.utils.PXLogger.LogReason.DEBUG_S2S_SCORE_IS_LOWER_THAN_BLOCK;
1819

@@ -35,29 +36,31 @@ public DefaultVerificationHandler(PXConfiguration pxConfiguration, ActivityHandl
3536

3637
@Override
3738
public boolean handleVerification(PXContext context, HttpServletResponseWrapper responseWrapper) throws PXException {
38-
boolean verified = shouldPassRequest(context);
39+
boolean verified = logTime("shouldPassRequest", () -> shouldPassRequest(context));
3940

40-
setPxhdCookie(context, responseWrapper);
41+
logTime("setPxhdCookie", () -> setPxhdCookie(context, responseWrapper));
4142

4243
if (!verified && !context.isMonitoredRequest()) {
43-
this.blockHandler.handleBlocking(context, this.pxConfiguration, responseWrapper);
44+
logTime("blockHandler.handleBlocking",() -> this.blockHandler.handleBlocking(context, this.pxConfiguration, responseWrapper));
4445
}
4546

46-
try {
47-
if (verified) {
48-
logger.debug("Passing request {} {}", verified, this.pxConfiguration.getModuleMode());
49-
50-
// Not blocking request and sending page_requested activity to px if configured as true
51-
if (this.pxConfiguration.isSendPageActivities()) {
52-
this.activityHandler.handlePageRequestedActivity(context);
47+
logTime("anonymousAsyncActivitiesSender" , () -> {
48+
try {
49+
if (verified) {
50+
logger.debug("Passing request {} {}", verified, this.pxConfiguration.getModuleMode());
51+
52+
// Not blocking request and sending page_requested activity to px if configured as true
53+
if (this.pxConfiguration.isSendPageActivities()) {
54+
this.activityHandler.handlePageRequestedActivity(context);
55+
}
56+
} else {
57+
logger.debug("Request invalid");
58+
this.activityHandler.handleBlockActivity(context);
5359
}
54-
} else {
55-
logger.debug("Request invalid");
56-
this.activityHandler.handleBlockActivity(context);
60+
} catch (PXException pxException) {
61+
logger.error("Error occurred while handle activities", pxException);
5762
}
58-
} catch (PXException pxException) {
59-
logger.error("Error occurred while handle activities", pxException);
60-
}
63+
});
6164

6265
return verified || context.isMonitoredRequest();
6366
}

‎src/main/java/com/perimeterx/internals/PXCookieValidator.java

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,8 @@
1111
import com.perimeterx.utils.PXLogger;
1212
import org.apache.commons.lang3.StringUtils;
1313

14+
import static com.perimeterx.utils.PXCommonUtils.logTime;
15+
1416
/**
1517
* PXCookieValidator
1618
* <p>
@@ -40,7 +42,7 @@ public boolean verify(PXContext context) {
4042
if (context.isMobileToken()) {
4143
PXCookieOriginalTokenValidator mobileVerifier = new PXCookieOriginalTokenValidator(pxConfiguration);
4244
mobileError = mobileVerifier.getMobileError(context);
43-
mobileVerifier.verify(context);
45+
logTime("mobileVerifier.verify", () -> mobileVerifier.verify(context));
4446
if (!StringUtils.isEmpty(mobileError)) {
4547
context.setS2sCallReason("mobile_error_" + mobileError);
4648
return false;

‎src/main/java/com/perimeterx/internals/PXS2SValidator.java

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@
1515
import com.perimeterx.utils.PXLogger;
1616
import org.apache.http.conn.ConnectTimeoutException;
1717

18+
import static com.perimeterx.utils.PXCommonUtils.logTime;
1819
import static org.apache.commons.lang3.StringUtils.*;
1920

2021
/**
@@ -48,7 +49,7 @@ public boolean verify(PXContext pxContext) {
4849
long rtt;
4950

5051
try {
51-
response = pxClient.riskApiCall(pxContext);
52+
response = logTime("pxClient.riskApiCall", () -> pxClient.riskApiCall(pxContext));
5253
} catch (ConnectTimeoutException e) {
5354
// Timeout handling - report pass reason and proceed with request
5455
pxContext.setPassReason(PassReason.S2S_TIMEOUT);

‎src/main/java/com/perimeterx/models/PXContext.java

Lines changed: 40 additions & 34 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,7 @@
3333

3434
import static com.perimeterx.utils.Constants.BREACHED_ACCOUNT_KEY_NAME;
3535
import static com.perimeterx.utils.PXCommonUtils.cookieHeadersNames;
36+
import static com.perimeterx.utils.PXCommonUtils.logTime;
3637

3738
/**
3839
* PXContext - Populate relevant data from HttpRequest
@@ -226,20 +227,20 @@ public PXContext(final HttpServletRequest request, final IPProvider ipProvider,
226227
}
227228

228229
private void initContext(final HttpServletRequest request, PXConfiguration pxConfiguration) {
229-
this.headers = PXCommonUtils.getHeadersFromRequest(request);
230+
this.headers = logTime("PXCommonUtils.getHeadersFromRequest", () -> PXCommonUtils.getHeadersFromRequest(request));
230231

231232
if (headers.containsKey(Constants.MOBILE_SDK_AUTHORIZATION_HEADER) || headers.containsKey(Constants.MOBILE_SDK_TOKENS_HEADER)) {
232233
logger.debug(PXLogger.LogReason.DEBUG_MOBILE_SDK_DETECTED);
233234
this.isMobileToken = true;
234235
this.cookieOrigin = Constants.HEADER_ORIGIN;
235236
}
236-
parseCookies(request, isMobileToken);
237-
generateLoginData(request, pxConfiguration);
237+
logTime("parseCookies", () -> parseCookies(request, isMobileToken));
238+
logTime("generateLoginData", () -> generateLoginData(request, pxConfiguration));
238239

239240
this.firstPartyRequest = false;
240241
this.userAgent = request.getHeader("user-agent");
241242
this.uri = request.getRequestURI();
242-
this.fullUrl = extractURL(request); //full URL with query string
243+
this.fullUrl = logTime("extractURL", () ->extractURL(request)); //full URL with query string
243244
this.blockReason = BlockReason.NONE;
244245
this.passReason = PassReason.NONE;
245246
this.s2sErrorReasonInfo = new S2SErrorReasonInfo();
@@ -257,9 +258,9 @@ private void initContext(final HttpServletRequest request, PXConfiguration pxCon
257258
Function<? super HttpServletRequest, ? extends CustomParameters> customParametersExtraction = pxConfiguration.getCustomParametersExtraction();
258259
try {
259260
if (customParametersExtraction != null) {
260-
this.customParameters = customParametersExtraction.apply(this.request);
261+
this.customParameters = logTime("customParametersExtraction.apply", () -> customParametersExtraction.apply(this.request));
261262
} else {
262-
this.customParameters = customParametersProvider.buildCustomParameters(pxConfiguration, this);
263+
this.customParameters = logTime("customParametersProvider.buildCustomParameters", () -> customParametersProvider.buildCustomParameters(pxConfiguration, this));
263264
}
264265
} catch (Exception e) {
265266
logger.debug("failed to extract custom parameters from custom function", e);
@@ -327,41 +328,46 @@ private void parseCookies(HttpServletRequest request, boolean isMobileToken) {
327328
List<RawCookieData> tokens = new ArrayList<>();
328329
List<RawCookieData> originalTokens = new ArrayList<>();
329330
if (isMobileToken) {
330-
headerParser = new MobileCookieHeaderParser();
331+
logTime("anonymousParseCookiesMobile", () -> {
332+
// This was changed because it is not possible to override a value inside a function.
333+
HeaderParser hp = new MobileCookieHeaderParser();
331334

332-
String tokensHeader = request.getHeader(Constants.MOBILE_SDK_TOKENS_HEADER);
333-
tokens.addAll(headerParser.createRawCookieDataList(tokensHeader));
335+
String tokensHeader = request.getHeader(Constants.MOBILE_SDK_TOKENS_HEADER);
336+
tokens.addAll(hp.createRawCookieDataList(tokensHeader));
334337

335-
String authCookieHeader = request.getHeader(Constants.MOBILE_SDK_AUTHORIZATION_HEADER);
336-
tokens.addAll(headerParser.createRawCookieDataList(authCookieHeader));
338+
String authCookieHeader = request.getHeader(Constants.MOBILE_SDK_AUTHORIZATION_HEADER);
339+
tokens.addAll(hp.createRawCookieDataList(authCookieHeader));
337340

338-
String originalTokensHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKENS_HEADER);
339-
originalTokens.addAll(headerParser.createRawCookieDataList(originalTokensHeader));
341+
String originalTokensHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKENS_HEADER);
342+
originalTokens.addAll(hp.createRawCookieDataList(originalTokensHeader));
340343

341-
String originalTokenHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKEN_HEADER);
342-
originalTokens.addAll(headerParser.createRawCookieDataList(originalTokenHeader));
344+
String originalTokenHeader = request.getHeader(Constants.MOBILE_SDK_ORIGINAL_TOKEN_HEADER);
345+
originalTokens.addAll(hp.createRawCookieDataList(originalTokenHeader));
343346

344-
this.tokens = tokens;
345-
if (!originalTokens.isEmpty()) {
346-
this.originalTokens = originalTokens;
347-
}
347+
this.tokens = tokens;
348+
if (!originalTokens.isEmpty()) {
349+
this.originalTokens = originalTokens;
350+
}
348351

349-
ObjectMapper mapper = new ObjectMapper();
350-
this.pxde = mapper.createObjectNode();
351-
this.pxdeVerified = true;
352+
ObjectMapper mapper = new ObjectMapper();
353+
this.pxde = mapper.createObjectNode();
354+
this.pxdeVerified = true;
355+
});
352356
} else {
353-
Cookie[] cookies = request.getCookies();
354-
String[] cookieHeaders = cookieHeadersNames(getPxConfiguration())
355-
.stream()
356-
.map(request::getHeader)
357-
.toArray(String[]::new);
358-
this.requestCookieNames = CookieNamesExtractor.extractCookieNames(cookies);
359-
setVidAndPxhd(cookies);
360-
tokens.addAll(headerParser.createRawCookieDataList(cookieHeaders));
361-
this.tokens = tokens;
362-
DataEnrichmentCookie deCookie = headerParser.getRawDataEnrichmentCookie(this.tokens, this.pxConfiguration.getCookieKey());
363-
this.pxde = deCookie.getJsonPayload();
364-
this.pxdeVerified = deCookie.isValid();
357+
logTime("anonymousParseCookiesElse", () -> {
358+
Cookie[] cookies = request.getCookies();
359+
String[] cookieHeaders = cookieHeadersNames(getPxConfiguration())
360+
.stream()
361+
.map(request::getHeader)
362+
.toArray(String[]::new);
363+
this.requestCookieNames = CookieNamesExtractor.extractCookieNames(cookies);
364+
setVidAndPxhd(cookies);
365+
tokens.addAll(headerParser.createRawCookieDataList(cookieHeaders));
366+
this.tokens = tokens;
367+
DataEnrichmentCookie deCookie = headerParser.getRawDataEnrichmentCookie(this.tokens, this.pxConfiguration.getCookieKey());
368+
this.pxde = deCookie.getJsonPayload();
369+
this.pxdeVerified = deCookie.isValid();
370+
});
365371
}
366372
}
367373

‎src/main/java/com/perimeterx/utils/PXCallable.java

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
package com.perimeterx.utils;
2+
3+
@FunctionalInterface
4+
public interface PXCallable<T,E extends Throwable> {
5+
T apply() throws E;
6+
}

‎src/main/java/com/perimeterx/utils/PXCallableVoid.java

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
package com.perimeterx.utils;
2+
3+
@FunctionalInterface
4+
public interface PXCallableVoid<E extends Throwable> {
5+
void apply() throws E;
6+
}

‎src/main/java/com/perimeterx/utils/PXCommonUtils.java

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@
1717
* Created by nitzangoldfeder on 16/07/2017.
1818
*/
1919
public class PXCommonUtils {
20+
private static final PXLogger logger = PXLogger.getLogger(PXCommonUtils.class);
2021

2122
public static List<Header> getDefaultHeaders(String authToken) {
2223
Header contentType = new BasicHeader(HttpHeaders.CONTENT_TYPE, "application/json");
@@ -59,4 +60,33 @@ public static List<String> cookieHeadersNames(PXConfiguration configuration) {
5960

6061
return lst;
6162
}
63+
64+
/**
65+
* Logs the runtime of a given function. returns the result of the execution
66+
* whether it's a Throwable or value.
67+
*
68+
* @param methodName the name of the method to be logged
69+
* @param f the function to execute
70+
* @param <T> type of successful execution
71+
* @param <E> type of failed execution
72+
* @return the success result of the execution
73+
* @throws E the throwable that will be thrown if the function fails
74+
*/
75+
public static <T, E extends Throwable> T logTime(String methodName, PXCallable<T, E> f) throws E {
76+
long s = System.currentTimeMillis();
77+
try {
78+
return f.apply();
79+
} finally {
80+
long e = System.currentTimeMillis();
81+
logger.debug(String.format("TIMELOGGER - %s execution time is (%d)ms", methodName, e - s));
82+
}
83+
}
84+
85+
public static <E extends Throwable> void logTime(String methodName, PXCallableVoid<E> f) throws E {
86+
// Using the other signature.
87+
logTime(methodName, () -> {
88+
f.apply();
89+
return null;
90+
});
91+
}
6292
}

‎web/pom.xml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,7 @@
2525
<dependency>
2626
<groupId>com.perimeterx</groupId>
2727
<artifactId>perimeterx-sdk</artifactId>
28-
<version>6.7.0</version>
28+
<version>6.7.0-rc-extended-logging</version>
2929
<scope>compile</scope>
3030
</dependency>
3131
<dependency>

0 commit comments

Comments
 (0)