detailed logging

instrumentation-security/akka-http-2.11_10.0.0/src/main/scala/akka/http/scaladsl/marshalling/AkkaHttpToResponseMarshallable.java

@@ -23,8 +23,13 @@ public abstract class AkkaHttpToResponseMarshallable {
     public Token token;
 
     public Marshaller<Object, HttpResponse> marshaller() {
-        Marshaller<Object, HttpResponse> marshaller = Weaver.callOriginal();
-        return marshaller.map(new AkkaResponseHelper());
+        try {
+            Marshaller<Object, HttpResponse> marshaller = Weaver.callOriginal();
+            return marshaller.map(new AkkaResponseHelper());
+        } catch (Exception e){
+            new AkkaResponseHelper().apply(null);
+            throw e;
+        }
     }
 
 }

instrumentation-security/servlet-2.4/src/main/java/javax/servlet/Filter_Instrumentation.java

@@ -28,19 +28,22 @@ public abstract class Filter_Instrumentation {
     public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
             throws IOException, ServletException {
         boolean isServletLockAcquired = acquireServletLockIfPossible();
+        Exception originalCallFailledWithException = null;
         if(isServletLockAcquired) {
             preprocessSecurityHook(request, response);
         }
         try {
             Weaver.callOriginal();
-        } finally {
+        } catch (Exception e){
+            originalCallFailledWithException = e;
+            throw e;
+        }
+        finally {
             if(isServletLockAcquired){
+                postProcessSecurityHook(request, response, originalCallFailledWithException);
                 releaseServletLock();
             }
         }
-        if(isServletLockAcquired) {
-            postProcessSecurityHook(request, response);
-        }
     }
 
     private void preprocessSecurityHook(ServletRequest request, ServletResponse response) {
@@ -92,11 +95,8 @@ private void preprocessSecurityHook(ServletRequest request, ServletResponse resp
         }
     }
 
-    private void postProcessSecurityHook(ServletRequest request, ServletResponse response) {
+    private void postProcessSecurityHook(ServletRequest request, ServletResponse response, Exception originalCallFailledWithException) {
         try {
-            if(NewRelicSecurity.getAgent().getIastDetectionCategory().getRxssEnabled()){
-                return;
-            }
             if (!NewRelicSecurity.isHookProcessingActive() || Boolean.TRUE.equals(NewRelicSecurity.getAgent().getSecurityMetaData().getCustomAttribute("RXSS_PROCESSED", Boolean.class))
             ) {
                 return;
@@ -107,6 +107,15 @@ private void postProcessSecurityHook(ServletRequest request, ServletResponse res
             }
             ServletHelper.executeBeforeExitingTransaction();
             //Add request URI hash to low severity event filter
+
+            if(NewRelicSecurity.getAgent().getIastDetectionCategory().getRxssEnabled()){
+                return;
+            }
+            if(originalCallFailledWithException != null){
+                NewRelicSecurity.getAgent().getSecurityMetaData().getResponse().setException(originalCallFailledWithException);
+                return;
+            }
+
             LowSeverityHelper.addRrequestUriToEventFilter(NewRelicSecurity.getAgent().getSecurityMetaData().getRequest());
 
             if(!ServletHelper.isResponseContentTypeExcluded(NewRelicSecurity.getAgent().getSecurityMetaData().getResponse().getResponseContentType())) {

newrelic-security-agent/src/main/java/com/newrelic/agent/security/instrumentator/httpclient/IASTDataTransferRequestProcessor.java

@@ -43,17 +43,18 @@ public class IASTDataTransferRequestProcessor {
 
     private static final Object syncLock = new Object();
 
-    private final AtomicLong cooldownTillTimestamp = new AtomicLong();
+    private static final AtomicLong cooldownTillTimestamp = new AtomicLong();
 
-    private final AtomicLong lastFuzzCCTimestamp = new AtomicLong();
+    private static final AtomicLong lastFuzzCCTimestamp = new AtomicLong();
 
-    private int currentFetchThresholdPerMin = 3600;
+    private static int currentFetchThresholdPerMin = 3600;
 
-    private long controlCommandRequestedAtEpochMilli = 0;
+    private static long controlCommandRequestedAtEpochMilli = 0;
 
-    private void task() {
+    private static void task() {
         IASTDataTransferRequest request = null;
         try {
+            logger.log(LogLevel.FINEST, "IAST data pull request task started", IASTDataTransferRequestProcessor.class.getName());
             if(!AgentUsageMetric.isIASTRequestProcessingActive()){
                 logger.log(LogLevel.FINER, "IAST request processing deactivated for the moment.", IASTDataTransferRequestProcessor.class.getName());
                 return;
@@ -78,15 +79,18 @@ private void task() {
             // Sleep if under cooldown
             long cooldownSleepTime = cooldownTillTimestamp.get() - currentTimestamp;
             if(cooldownSleepTime > 0) {
+                logger.log(LogLevel.FINEST, String.format("IAST data pull request is under cooldown. Sleeping for %sms", cooldownSleepTime), IASTDataTransferRequestProcessor.class.getName());
                 Thread.sleep(cooldownSleepTime);
             }
 
             if (currentTimestamp - lastFuzzCCTimestamp.get() < TimeUnit.SECONDS.toMillis(5)) {
+                logger.log(LogLevel.FINEST, "IAST data pull request is under fuzz control command processing. Sleeping for 5 seconds", IASTDataTransferRequestProcessor.class.getName());
                 return;
             }
 
             int currentFetchThreshold = Math.round((float) currentFetchThresholdPerMin/12);
             if (currentFetchThreshold <= 0){
+                logger.log(LogLevel.FINEST, String.format("IAST data pull request is canceled. due to low fetch threshold %s", currentFetchThreshold), IASTDataTransferRequestProcessor.class.getName());
                 return;
             }
 
@@ -126,14 +130,15 @@ private void task() {
                 logger.log(LogLevel.FINEST, "IAST data pull request to be sent: " + JsonConverter.toJSON(request), IASTDataTransferRequestProcessor.class.getName());
                 WSClient.getInstance().send(request.toString());
             }
+            logger.log(LogLevel.FINEST, "IAST data pull request task completed", IASTDataTransferRequestProcessor.class.getName());
         } catch (Throwable e) {
-            logger.log(LogLevel.SEVERE, String.format(UNABLE_TO_SEND_IAST_DATA_REQUEST_DUE_TO_ERROR_S_S, e.toString(), e.getCause().toString()), this.getClass().getName());
-            logger.log(LogLevel.FINEST, String.format(UNABLE_TO_SEND_IAST_DATA_REQUEST_DUE_TO_ERROR, request), e, this.getClass().getName());
-            logger.postLogMessageIfNecessary(LogLevel.SEVERE, String.format(UNABLE_TO_SEND_IAST_DATA_REQUEST_DUE_TO_ERROR, JsonConverter.toJSON(request)), e, this.getClass().getName());
+            logger.log(LogLevel.SEVERE, String.format(UNABLE_TO_SEND_IAST_DATA_REQUEST_DUE_TO_ERROR_S_S, e.toString(), e.getCause().toString()), IASTDataTransferRequestProcessor.class.getName());
+            logger.log(LogLevel.FINEST, String.format(UNABLE_TO_SEND_IAST_DATA_REQUEST_DUE_TO_ERROR, request), e, IASTDataTransferRequestProcessor.class.getName());
+            logger.postLogMessageIfNecessary(LogLevel.SEVERE, String.format(UNABLE_TO_SEND_IAST_DATA_REQUEST_DUE_TO_ERROR, JsonConverter.toJSON(request)), e, IASTDataTransferRequestProcessor.class.getName());
         }
     }
 
-    private Map<String, Set<String>> getEffectiveCompletedRequests() {
+    private static Map<String, Set<String>> getEffectiveCompletedRequests() {
         Map<String, Set<String>> completedRequest = new HashMap<>();
         completedRequest.putAll(RestRequestThreadPool.getInstance().getProcessedIds());
         completedRequest.putAll(GrpcClientRequestReplayHelper.getInstance().getProcessedIds());
@@ -189,7 +194,7 @@ public void startDataRequestSchedule(long delay, TimeUnit timeUnit){
                 logger.log(LogLevel.WARNING, String.format("Error while reading Configuration security.scan_request_rate_limit : %s,  Using default value %s replay request per min.", e.getMessage(), currentFetchThresholdPerMin), e, this.getClass().getName());
             }
             logger.log(LogLevel.INFO, String.format("IAST data pull request is scheduled at %s, after delay of %s seconds", AgentConfig.getInstance().getAgentMode().getScanSchedule().getDataCollectionTime(), initialDelay), IASTDataTransferRequestProcessor.class.getName());
-            future = executorService.scheduleWithFixedDelay(this::task, initialDelay, delay, timeUnit);
+            future = executorService.scheduleWithFixedDelay(IASTDataTransferRequestProcessor::task, initialDelay, delay, timeUnit);
         } catch (Throwable ignored){}
     }
 

newrelic-security-api/src/main/java/com/newrelic/api/agent/security/schema/HttpResponse.java

@@ -1,5 +1,7 @@
 package com.newrelic.api.agent.security.schema;
 
+import com.newrelic.api.agent.security.schema.annotations.JsonIgnore;
+
 import java.util.Map;
 import java.util.concurrent.ConcurrentHashMap;
 
@@ -13,6 +15,9 @@ public class HttpResponse {
 
     private int responseCode;
 
+    @JsonIgnore
+    private Exception exception;
+
     public HttpResponse() {
         this.headers = new ConcurrentHashMap<>();
         this.responseBody = new StringBuilder();
@@ -24,6 +29,7 @@ public HttpResponse(HttpResponse httpResponse) {
         this.responseBody = new StringBuilder(httpResponse.responseBody);
         this.contentType = new String(httpResponse.contentType.trim());
         this.responseCode = httpResponse.responseCode;
+        this.exception = httpResponse.exception;
     }
 
     public Map<String, String> getHeaders() {
@@ -62,6 +68,14 @@ public void setResponseContentType(String responseContentType) {
         }
     }
 
+    public Exception getException() {
+        return exception;
+    }
+
+    public void setException(Exception exception) {
+        this.exception = exception;
+    }
+
     public boolean isEmpty() {
         return StringUtils.isAnyBlank(responseBody, contentType);
     }