Merge "Attempt to fix the verify job problem"
[clamp.git] / src / main / java / org / onap / clamp / clds / util / LoggingUtils.java
index cbe7eba..0ac1a14 100644 (file)
 
 package org.onap.clamp.clds.util;
 
-import com.att.eelf.configuration.EELFLogger;
-import com.att.eelf.configuration.EELFManager;
-
 import java.net.HttpURLConnection;
 import java.net.InetAddress;
+import java.net.URLConnection;
 import java.net.UnknownHostException;
 import java.text.DateFormat;
 import java.text.SimpleDateFormat;
@@ -38,12 +36,12 @@ import java.time.temporal.ChronoUnit;
 import java.util.Date;
 import java.util.TimeZone;
 import java.util.UUID;
-
 import javax.net.ssl.HttpsURLConnection;
 import javax.servlet.http.HttpServletRequest;
 import javax.validation.constraints.NotNull;
-
-import org.onap.clamp.clds.service.DefaultUserNameHandler;
+import org.onap.clamp.authorization.AuthorizationController;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
 import org.slf4j.event.Level;
 import org.springframework.security.core.context.SecurityContextHolder;
@@ -53,15 +51,18 @@ import org.springframework.security.core.context.SecurityContextHolder;
  * time context, ...
  */
 public class LoggingUtils {
-    protected static final EELFLogger logger = EELFManager.getInstance().getLogger(LoggingUtils.class);
+
+    protected static final Logger logger = LoggerFactory.getLogger(LoggingUtils.class);
 
     private static final DateFormat DATE_FORMAT = createDateFormat();
 
+    private static final String DATE_FORMATTER_ISO = "yyyy-MM-dd'T'HH:mm:ss.SSSXXX";
+
     /** String constant for messages <tt>ENTERING</tt>, <tt>EXITING</tt>, etc. */
     private static final String EMPTY_MESSAGE = "";
 
     /** Logger delegate. */
-    private EELFLogger mlogger;
+    private Logger mlogger;
 
     /** Automatic UUID, overrideable per adapter or per invocation. */
     private static UUID sInstanceUUID = UUID.randomUUID();
@@ -69,7 +70,7 @@ public class LoggingUtils {
     /**
      * Constructor.
      */
-    public LoggingUtils(final EELFLogger loggerP) {
+    public LoggingUtils(final Logger loggerP) {
         this.mlogger = checkNotNull(loggerP);
     }
 
@@ -83,7 +84,7 @@ public class LoggingUtils {
         MDC.put("RequestId", UUID.randomUUID().toString());
         MDC.put("ServiceName", service);
         MDC.put("PartnerName", partner);
-        //Defaulting to HTTP/1.1 protocol
+        // Defaulting to HTTP/1.1 protocol
         MDC.put("Protocol", "HTTP/1.1");
         try {
             MDC.put("ServerFQDN", InetAddress.getLocalHost().getCanonicalHostName());
@@ -114,7 +115,7 @@ public class LoggingUtils {
      */
     public static void setResponseContext(String code, String description, String className) {
         MDC.put("ResponseCode", code);
-        MDC.put("StatusCode", code.equals("0") ? "COMPLETE" : "ERROR");
+        MDC.put("StatusCode", "0".equals(code) ? "COMPLETE" : "ERROR");
         MDC.put("ResponseDescription", description != null ? description : "");
         MDC.put("ClassName", className != null ? className : "");
     }
@@ -153,10 +154,10 @@ public class LoggingUtils {
      * @return A string with the request ID
      */
     public static String getRequestId() {
-        String requestId = MDC.get(ONAPLogConstants.MDCs.REQUEST_ID);
+        String requestId = MDC.get(OnapLogConstants.Mdcs.REQUEST_ID);
         if (requestId == null || requestId.isEmpty()) {
             requestId = UUID.randomUUID().toString();
-            MDC.put(ONAPLogConstants.MDCs.REQUEST_ID, requestId);
+            MDC.put(OnapLogConstants.Mdcs.REQUEST_ID, requestId);
         }
         return requestId;
     }
@@ -167,8 +168,6 @@ public class LoggingUtils {
         return dateFormat;
     }
 
-
-
     /*********************************************************************************************
      * Method for ONAP Application Logging Specification v1.2
      ********************************************************************************************/
@@ -180,73 +179,84 @@ public class LoggingUtils {
      * @param serviceName service name
      */
     public void entering(HttpServletRequest request, String serviceName) {
-        MDC.clear();
+        // MDC.clear();
         checkNotNull(request);
         // Extract MDC values from standard HTTP headers.
-        final String requestId = defaultToUUID(request.getHeader(ONAPLogConstants.Headers.REQUEST_ID));
-        final String invocationId = defaultToUUID(request.getHeader(ONAPLogConstants.Headers.INVOCATION_ID));
-        final String partnerName = defaultToEmpty(request.getHeader(ONAPLogConstants.Headers.PARTNER_NAME));
+        final String requestId =
+            defaultToUuid(request.getHeader(OnapLogConstants.Headers.REQUEST_ID));
+        final String invocationId =
+            defaultToUuid(request.getHeader(OnapLogConstants.Headers.INVOCATION_ID));
+        final String partnerName =
+            defaultToEmpty(request.getHeader(OnapLogConstants.Headers.PARTNER_NAME));
 
         // Default the partner name to the user name used to login to clamp
         if (partnerName.equalsIgnoreCase(EMPTY_MESSAGE)) {
-            MDC.put(ONAPLogConstants.MDCs.PARTNER_NAME, new DefaultUserNameHandler()
-                    .retrieveUserName(SecurityContextHolder.getContext()));
+            MDC.put(OnapLogConstants.Mdcs.PARTNER_NAME,
+                AuthorizationController.getPrincipalName(SecurityContextHolder.getContext()));
         }
 
         // Set standard MDCs. Override this entire method if you want to set
         // others, OR set them BEFORE or AFTER the invocation of #entering,
         // depending on where you need them to appear, OR extend the
         // ServiceDescriptor to add them.
-        MDC.put(ONAPLogConstants.MDCs.ENTRY_TIMESTAMP,
-            ZonedDateTime.now(ZoneOffset.UTC)
-            .format(DateTimeFormatter.ISO_INSTANT));
-        MDC.put(ONAPLogConstants.MDCs.REQUEST_ID, requestId);
-        MDC.put(ONAPLogConstants.MDCs.INVOCATION_ID, invocationId);
-        MDC.put(ONAPLogConstants.MDCs.CLIENT_IP_ADDRESS, defaultToEmpty(request.getRemoteAddr()));
-        MDC.put(ONAPLogConstants.MDCs.SERVER_FQDN, defaultToEmpty(request.getServerName()));
-        MDC.put(ONAPLogConstants.MDCs.INSTANCE_UUID, defaultToEmpty(sInstanceUUID));
+        MDC.put(OnapLogConstants.Mdcs.ENTRY_TIMESTAMP, ZonedDateTime.now(ZoneOffset.UTC)
+            .format(DateTimeFormatter.ofPattern(DATE_FORMATTER_ISO)));
+        MDC.put(OnapLogConstants.Mdcs.REQUEST_ID, requestId);
+        MDC.put(OnapLogConstants.Mdcs.INVOCATION_ID, invocationId);
+        MDC.put(OnapLogConstants.Mdcs.CLIENT_IP_ADDRESS, defaultToEmpty(request.getRemoteAddr()));
+        MDC.put(OnapLogConstants.Mdcs.SERVER_FQDN, defaultToEmpty(request.getServerName()));
+        MDC.put(OnapLogConstants.Mdcs.INSTANCE_UUID, defaultToEmpty(sInstanceUUID));
 
         // Default the service name to the requestURI, in the event that
         // no value has been provided.
-        if (serviceName == null
-                || serviceName.equalsIgnoreCase(EMPTY_MESSAGE)) {
-            MDC.put(ONAPLogConstants.MDCs.SERVICE_NAME, request.getRequestURI());
+        if (serviceName == null || serviceName.equalsIgnoreCase(EMPTY_MESSAGE)) {
+            MDC.put(OnapLogConstants.Mdcs.SERVICE_NAME, request.getRequestURI());
         } else {
-            MDC.put(ONAPLogConstants.MDCs.SERVICE_NAME, serviceName);
+            MDC.put(OnapLogConstants.Mdcs.SERVICE_NAME, serviceName);
         }
 
-        this.mlogger.info(ONAPLogConstants.Markers.ENTRY);
+        // Set the Response Status code to in progress
+        MDC.put(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE,
+            OnapLogConstants.ResponseStatus.INPROGRESS.toString());
+        setElapsedTime();
+
+        this.mlogger.info(OnapLogConstants.Markers.ENTRY, "Entering");
     }
 
     /**
      * Report <tt>EXITING</tt> marker.
      *
-
+     *
      * @param code response code
      * @param descrption response description
      * @param severity response severity
      * @param status response status code
      */
-    public void exiting(String code, String descrption, Level severity, ONAPLogConstants.ResponseStatus status) {
+    public void exiting(int code, String descrption, Level severity,
+        OnapLogConstants.ResponseStatus status) {
         try {
-            MDC.put(ONAPLogConstants.MDCs.RESPONSE_CODE, defaultToEmpty(code));
-            MDC.put(ONAPLogConstants.MDCs.RESPONSE_DESCRIPTION, defaultToEmpty(descrption));
-            MDC.put(ONAPLogConstants.MDCs.RESPONSE_SEVERITY, defaultToEmpty(severity));
-            MDC.put(ONAPLogConstants.MDCs.RESPONSE_STATUS_CODE, defaultToEmpty(status));
-
-            ZonedDateTime startTime = ZonedDateTime.parse(MDC.get(ONAPLogConstants.MDCs.ENTRY_TIMESTAMP),
-                DateTimeFormatter.ISO_INSTANT.withZone(ZoneOffset.UTC));
-            ZonedDateTime endTime = ZonedDateTime.now(ZoneOffset.UTC);
-            MDC.put(ONAPLogConstants.MDCs.END_TIMESTAMP, endTime.format(DateTimeFormatter.ISO_INSTANT));
-            long duration = ChronoUnit.MILLIS.between(startTime, endTime);
-            MDC.put(ONAPLogConstants.MDCs.ELAPSED_TIMESTAMP, String.valueOf(duration)); 
-            this.mlogger.info(ONAPLogConstants.Markers.EXIT);
-        }
-        finally {
+
+            MDC.put(OnapLogConstants.Mdcs.RESPONSE_CODE, defaultToEmpty(code));
+            MDC.put(OnapLogConstants.Mdcs.RESPONSE_DESCRIPTION, defaultToEmpty(descrption));
+            MDC.put(OnapLogConstants.Mdcs.RESPONSE_SEVERITY, defaultToEmpty(severity));
+            MDC.put(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE, defaultToEmpty(status));
+
+            setElapsedTime();
+            this.mlogger.info(OnapLogConstants.Markers.EXIT, "Exiting");
+        } finally {
             MDC.clear();
         }
     }
 
+    private void setElapsedTime() {
+        ZonedDateTime startTime =
+            ZonedDateTime.parse(MDC.get(OnapLogConstants.Mdcs.ENTRY_TIMESTAMP),
+                DateTimeFormatter.ISO_DATE_TIME.withZone(ZoneOffset.UTC));
+        ZonedDateTime endTime = ZonedDateTime.now(ZoneOffset.UTC);
+        long duration = ChronoUnit.MILLIS.between(startTime, endTime);
+        MDC.put(OnapLogConstants.Mdcs.ELAPSED_TIME, String.valueOf(duration));
+    }
+
     /**
      * Get the property value.
      *
@@ -256,7 +266,7 @@ public class LoggingUtils {
     public String getProperties(String name) {
         return MDC.get(name);
     }
-    
+
     /**
      * Report pending invocation with <tt>INVOKE</tt> marker,
      * setting standard ONAP logging headers automatically.
@@ -266,25 +276,9 @@ public class LoggingUtils {
      * @param targetServiceName The target service name
      * @return The HTTP url connection
      */
-    public HttpURLConnection invoke(final HttpURLConnection con, String targetEntity, String targetServiceName) {
-        final String invocationId = UUID.randomUUID().toString();
-
-        // Set standard HTTP headers on (southbound request) builder.
-        con.setRequestProperty(ONAPLogConstants.Headers.REQUEST_ID,
-            defaultToEmpty(MDC.get(ONAPLogConstants.MDCs.REQUEST_ID)));
-        con.setRequestProperty(ONAPLogConstants.Headers.INVOCATION_ID,
-            invocationId);
-        con.setRequestProperty(ONAPLogConstants.Headers.PARTNER_NAME,
-            defaultToEmpty(MDC.get(ONAPLogConstants.MDCs.PARTNER_NAME)));
-
-        invokeContext(targetEntity, targetServiceName, invocationId);
-
-        // Log INVOKE*, with the invocationID as the message body.
-        // (We didn't really want this kind of behavior in the standard,
-        // but is it worse than new, single-message MDC?)
-        this.mlogger.info(ONAPLogConstants.Markers.INVOKE);
-        this.mlogger.info(ONAPLogConstants.Markers.INVOKE_SYNC + "{" + invocationId + "}");
-        return con;
+    public HttpURLConnection invoke(final HttpURLConnection con, String targetEntity,
+        String targetServiceName) {
+        return this.invokeGeneric(con, targetEntity, targetServiceName);
     }
 
     /**
@@ -302,8 +296,8 @@ public class LoggingUtils {
         // Log INVOKE*, with the invocationID as the message body.
         // (We didn't really want this kind of behavior in the standard,
         // but is it worse than new, single-message MDC?)
-        this.mlogger.info(ONAPLogConstants.Markers.INVOKE);
-        this.mlogger.info(ONAPLogConstants.Markers.INVOKE_SYNC + "{" + invocationId + "}");
+        this.mlogger.info(OnapLogConstants.Markers.INVOKE, "INVOKE");
+        this.mlogger.info(OnapLogConstants.Markers.INVOKE_SYNCHRONOUS + "{" + invocationId + "}");
     }
 
     /**
@@ -315,33 +309,19 @@ public class LoggingUtils {
      * @param targetServiceName The target service name
      * @return The HTTPS url connection
      */
-    public HttpsURLConnection invokeHttps(final HttpsURLConnection con, String targetEntity, String targetServiceName) {
-        final String invocationId = UUID.randomUUID().toString();
-
-        // Set standard HTTP headers on (southbound request) builder.
-        con.setRequestProperty(ONAPLogConstants.Headers.REQUEST_ID,
-            defaultToEmpty(MDC.get(ONAPLogConstants.MDCs.REQUEST_ID)));
-        con.setRequestProperty(ONAPLogConstants.Headers.INVOCATION_ID,
-            invocationId);
-        con.setRequestProperty(ONAPLogConstants.Headers.PARTNER_NAME,
-            defaultToEmpty(MDC.get(ONAPLogConstants.MDCs.PARTNER_NAME)));
-
-        invokeContext(targetEntity, targetServiceName, invocationId);
-
-        // Log INVOKE*, with the invocationID as the message body.
-        // (We didn't really want this kind of behavior in the standard,
-        // but is it worse than new, single-message MDC?)
-        this.mlogger.info(ONAPLogConstants.Markers.INVOKE);
-        this.mlogger.info(ONAPLogConstants.Markers.INVOKE_SYNC + "{" + invocationId + "}");
-        return con;
+    public HttpsURLConnection invokeHttps(final HttpsURLConnection con, String targetEntity,
+        String targetServiceName) {
+        return this.invokeGeneric(con, targetEntity, targetServiceName);
     }
 
     /**
      * Report pending invocation with <tt>INVOKE-RETURN</tt> marker.
      */
     public void invokeReturn() {
+        MDC.put(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE,
+            OnapLogConstants.ResponseStatus.COMPLETE.toString());
         // Add the Invoke-return marker and clear the needed MDC
-        this.mlogger.info(ONAPLogConstants.Markers.INVOKE_RETURN);
+        this.mlogger.info(OnapLogConstants.Markers.INVOKE_RETURN, "INVOKE-RETURN");
         invokeReturnContext();
     }
 
@@ -378,7 +358,7 @@ public class LoggingUtils {
      * @param in to be filtered
      * @return input string or null
      */
-    private static String defaultToUUID(final String in) {
+    private static String defaultToUuid(final String in) {
         if (in == null) {
             return UUID.randomUUID().toString();
         }
@@ -390,24 +370,45 @@ public class LoggingUtils {
      *
      * @param targetEntity Target entity (an external/sub component, for ex. "sdc")
      * @param targetServiceName Target service name (name of API invoked on target)
-     * @param invocationID The invocation ID
+     * @param invocationId The invocation ID
      */
-    private void invokeContext(String targetEntity, String targetServiceName, String invocationID) {
-        MDC.put(ONAPLogConstants.MDCs.TARGET_ENTITY, defaultToEmpty(targetEntity));
-        MDC.put(ONAPLogConstants.MDCs.TARGET_SERVICE_NAME, defaultToEmpty(targetServiceName));
-        MDC.put(ONAPLogConstants.MDCs.INVOCATIONID_OUT, invocationID);
-        MDC.put(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP,
-            ZonedDateTime.now(ZoneOffset.UTC)
-            .format(DateTimeFormatter.ISO_INSTANT));
+    private void invokeContext(String targetEntity, String targetServiceName, String invocationId) {
+        MDC.put(OnapLogConstants.Mdcs.TARGET_ENTITY, defaultToEmpty(targetEntity));
+        MDC.put(OnapLogConstants.Mdcs.TARGET_SERVICE_NAME, defaultToEmpty(targetServiceName));
+        MDC.put(OnapLogConstants.Mdcs.INVOCATIONID_OUT, invocationId);
+        MDC.put(OnapLogConstants.Mdcs.INVOKE_TIMESTAMP, ZonedDateTime.now(ZoneOffset.UTC)
+            .format(DateTimeFormatter.ofPattern(DATE_FORMATTER_ISO)));
     }
 
     /**
      * Clear target related logging variables in thread local data via MDC.
      */
     private void invokeReturnContext() {
-        MDC.remove(ONAPLogConstants.MDCs.TARGET_ENTITY);
-        MDC.remove(ONAPLogConstants.MDCs.TARGET_SERVICE_NAME);
-        MDC.remove(ONAPLogConstants.MDCs.INVOCATIONID_OUT);
-        MDC.remove(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP);
+        MDC.remove(OnapLogConstants.Mdcs.TARGET_ENTITY);
+        MDC.remove(OnapLogConstants.Mdcs.TARGET_SERVICE_NAME);
+        MDC.remove(OnapLogConstants.Mdcs.INVOCATIONID_OUT);
+        MDC.remove(OnapLogConstants.Mdcs.INVOKE_TIMESTAMP);
+        MDC.remove(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE);
+    }
+
+    private <T extends URLConnection> T invokeGeneric(final T con, String targetEntity,
+        String targetServiceName) {
+        final String invocationId = UUID.randomUUID().toString();
+
+        // Set standard HTTP headers on (southbound request) builder.
+        con.setRequestProperty(OnapLogConstants.Headers.REQUEST_ID,
+            defaultToEmpty(MDC.get(OnapLogConstants.Mdcs.REQUEST_ID)));
+        con.setRequestProperty(OnapLogConstants.Headers.INVOCATION_ID, invocationId);
+        con.setRequestProperty(OnapLogConstants.Headers.PARTNER_NAME,
+            defaultToEmpty(MDC.get(OnapLogConstants.Mdcs.PARTNER_NAME)));
+
+        invokeContext(targetEntity, targetServiceName, invocationId);
+
+        // Log INVOKE*, with the invocationID as the message body.
+        // (We didn't really want this kind of behavior in the standard,
+        // but is it worse than new, single-message MDC?)
+        this.mlogger.info(OnapLogConstants.Markers.INVOKE, "");
+        this.mlogger.info(OnapLogConstants.Markers.INVOKE_SYNCHRONOUS + "{" + invocationId + "}");
+        return con;
     }
 }