Fix audit, metric and error logs as per logging specification 01/110601/2
authorAshwin Sharma <ashwin.shyam.sharma@att.com>
Mon, 27 Jul 2020 07:55:07 +0000 (07:55 +0000)
committerAshwin Sharma <ashwin.shyam.sharma@att.com>
Mon, 27 Jul 2020 16:54:29 +0000 (16:54 +0000)
Issue-ID: CLAMP-900
Signed-off-by: Ashwin Sharma <ashwin.shyam.sharma@att.com>
Change-Id: Ia911e16ecd4a5a03f44c45d32ebc874ff8882895

src/main/java/org/onap/clamp/authorization/AuthorizationController.java
src/main/java/org/onap/clamp/clds/service/CldsHealthcheckService.java
src/main/java/org/onap/clamp/clds/util/LoggingUtils.java
src/main/java/org/onap/clamp/clds/util/OnapLogConstants.java
src/main/java/org/onap/clamp/flow/log/FlowLogOperation.java
src/main/resources/logback-default.xml
src/test/java/org/onap/clamp/clds/util/LoggingUtilsTest.java

index e4a03fd..f4da09a 100644 (file)
@@ -47,9 +47,11 @@ import org.springframework.stereotype.Component;
 @Component
 public class AuthorizationController {
 
-    protected static final EELFLogger logger = EELFManager.getInstance().getLogger(AuthorizationController.class);
-    protected static final EELFLogger auditLogger = EELFManager.getInstance().getMetricsLogger();
-    protected static final EELFLogger securityLogger = EELFManager.getInstance().getSecurityLogger();
+    protected static final EELFLogger logger =
+        EELFManager.getInstance().getLogger(AuthorizationController.class);
+    protected static final EELFLogger auditLogger = EELFManager.getInstance().getAuditLogger();
+    protected static final EELFLogger securityLogger =
+        EELFManager.getInstance().getSecurityLogger();
 
     // By default we'll set it to a default handler
     @Autowired
@@ -66,11 +68,12 @@ public class AuthorizationController {
         }
         if ((securityContext.getAuthentication().getPrincipal()) instanceof String) {
             // anonymous case
-            return ((String)securityContext.getAuthentication().getPrincipal());
+            return ((String) securityContext.getAuthentication().getPrincipal());
         } else {
             return ((UserDetails) securityContext.getAuthentication().getPrincipal()).getUsername();
         }
     }
+
     /**
      * Get the principal name.
      *
@@ -89,11 +92,12 @@ public class AuthorizationController {
      * Insert authorize the api based on the permission.
      *
      * @param camelExchange The Camel Exchange object containing the properties
-     * @param typeVar       The type of the permissions
-     * @param instanceVar   The instance of the permissions. e.g. dev
-     * @param action        The action of the permissions. e.g. read
+     * @param typeVar The type of the permissions
+     * @param instanceVar The instance of the permissions. e.g. dev
+     * @param action The action of the permissions. e.g. read
      */
-    public void authorize(Exchange camelExchange, String typeVar, String instanceVar, String action) {
+    public void authorize(Exchange camelExchange, String typeVar, String instanceVar,
+        String action) {
         String type = refProp.getStringValue(PERM_PREFIX + typeVar);
         String instance = refProp.getStringValue(PERM_INSTANCE);
 
@@ -121,7 +125,7 @@ public class AuthorizationController {
 
     /**
      * Insert authorize the api based on the permission.
-     * 
+     *
      * @param inPermission Security permission in input
      * @return True if user is permitted
      */
@@ -131,18 +135,19 @@ public class AuthorizationController {
         // check if the user has the permission key or the permission key with a
         // combination of all instance and/or all action.
         if (hasRole(inPermission.getKey()) || hasRole(inPermission.getKeyAllInstance())) {
-            auditLogger.info("{} authorized because user has permission with * for instance: {}", principalName,
-                    inPermission.getKey());
+            auditLogger.info("{} authorized because user has permission with * for instance: {}",
+                principalName, inPermission.getKey().replace("|", ":"));
             return true;
             // the rest of these don't seem to be required - isUserInRole method
             // appears to take * as a wildcard
         } else if (hasRole(inPermission.getKeyAllInstanceAction())) {
-            auditLogger.info("{} authorized because user has permission with * for instance and * for action: {}",
-                    principalName, inPermission.getKey());
+            auditLogger.info(
+                "{} authorized because user has permission with * for instance and * for action: {}",
+                principalName, inPermission.getKey().replace("|", ":"));
             return true;
         } else if (hasRole(inPermission.getKeyAllAction())) {
-            auditLogger.info("{} authorized because user has permission with * for action: {}", principalName,
-                    inPermission.getKey());
+            auditLogger.info("{} authorized because user has permission with * for action: {}",
+                principalName, inPermission.getKey().replace("|", ":"));
             return true;
         } else {
             return false;
index 6203cdf..3fceace 100644 (file)
 
 package org.onap.clamp.clds.service;
 
-import com.att.eelf.configuration.EELFLogger;
-import com.att.eelf.configuration.EELFManager;
-
 import java.util.Date;
-
 import org.onap.clamp.clds.model.CldsHealthCheck;
 import org.onap.clamp.clds.util.LoggingUtils;
 import org.onap.clamp.clds.util.OnapLogConstants;
 import org.onap.clamp.loop.LoopController;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import org.slf4j.event.Level;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.http.HttpStatus;
@@ -46,7 +44,7 @@ public class CldsHealthcheckService {
     @Autowired
     private LoopController loopController;
 
-    protected static final EELFLogger logger = EELFManager.getInstance().getLogger(CldsHealthcheckService.class);
+    protected static final Logger logger = LoggerFactory.getLogger(CldsHealthcheckService.class);
 
     /**
      * REST service that retrieves clds healthcheck information.
@@ -64,17 +62,20 @@ public class CldsHealthcheckService {
             cldsHealthCheck.setHealthCheckComponent("CLDS-APP");
             cldsHealthCheck.setHealthCheckStatus("UP");
             cldsHealthCheck.setDescription("OK");
-            LoggingUtils.setResponseContext("0", "Get healthcheck success", this.getClass().getName());
-            util.exiting("200", "Healthcheck success", Level.INFO, OnapLogConstants.ResponseStatus.COMPLETED);
+            LoggingUtils.setResponseContext("0", "Get healthcheck success",
+                this.getClass().getName());
+            util.exiting(HttpStatus.OK.value(), "Healthcheck success", Level.INFO,
+                OnapLogConstants.ResponseStatus.COMPLETE);
         } catch (Exception e) {
             logger.error("CLAMP application Heath check failed", e);
-            LoggingUtils.setResponseContext("999", "Get healthcheck failed", this.getClass().getName());
+            LoggingUtils.setResponseContext("999", "Get healthcheck failed",
+                this.getClass().getName());
             cldsHealthCheck.setHealthCheckComponent("CLDS-APP");
             cldsHealthCheck.setHealthCheckStatus("DOWN");
             cldsHealthCheck.setDescription("NOT-OK");
-            util.exiting(HttpStatus.INTERNAL_SERVER_ERROR.toString(), "Healthcheck failed", Level.INFO,
-                    OnapLogConstants.ResponseStatus.ERROR);
+            util.exiting(HttpStatus.INTERNAL_SERVER_ERROR.value(), "Healthcheck failed", Level.INFO,
+                OnapLogConstants.ResponseStatus.ERROR);
         }
         return cldsHealthCheck;
     }
-}
\ No newline at end of file
+}
index a471b41..0ac1a14 100644 (file)
@@ -23,8 +23,6 @@
 
 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;
@@ -42,6 +40,8 @@ import javax.net.ssl.HttpsURLConnection;
 import javax.servlet.http.HttpServletRequest;
 import javax.validation.constraints.NotNull;
 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;
@@ -51,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();
@@ -67,7 +70,7 @@ public class LoggingUtils {
     /**
      * Constructor.
      */
-    public LoggingUtils(final EELFLogger loggerP) {
+    public LoggingUtils(final Logger loggerP) {
         this.mlogger = checkNotNull(loggerP);
     }
 
@@ -81,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());
@@ -176,26 +179,28 @@ 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,
-                    AuthorizationController.getPrincipalName(SecurityContextHolder.getContext()));
+                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.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()));
@@ -204,45 +209,54 @@ public class LoggingUtils {
 
         // Default the service name to the requestURI, in the event that
         // no value has been provided.
-        if (serviceName == null
-                || serviceName.equalsIgnoreCase(EMPTY_MESSAGE)) {
+        if (serviceName == null || serviceName.equalsIgnoreCase(EMPTY_MESSAGE)) {
             MDC.put(OnapLogConstants.Mdcs.SERVICE_NAME, request.getRequestURI());
         } else {
             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 {
+            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.
      *
@@ -262,7 +276,8 @@ public class LoggingUtils {
      * @param targetServiceName The target service name
      * @return The HTTP url connection
      */
-    public HttpURLConnection invoke(final HttpURLConnection con, String targetEntity, String targetServiceName) {
+    public HttpURLConnection invoke(final HttpURLConnection con, String targetEntity,
+        String targetServiceName) {
         return this.invokeGeneric(con, targetEntity, targetServiceName);
     }
 
@@ -281,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 + "}");
     }
 
     /**
@@ -294,7 +309,8 @@ public class LoggingUtils {
      * @param targetServiceName The target service name
      * @return The HTTPS url connection
      */
-    public HttpsURLConnection invokeHttps(final HttpsURLConnection con, String targetEntity, String targetServiceName) {
+    public HttpsURLConnection invokeHttps(final HttpsURLConnection con, String targetEntity,
+        String targetServiceName) {
         return this.invokeGeneric(con, targetEntity, targetServiceName);
     }
 
@@ -302,8 +318,10 @@ public class LoggingUtils {
      * 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();
     }
 
@@ -358,9 +376,8 @@ public class LoggingUtils {
         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));
+        MDC.put(OnapLogConstants.Mdcs.INVOKE_TIMESTAMP, ZonedDateTime.now(ZoneOffset.UTC)
+            .format(DateTimeFormatter.ofPattern(DATE_FORMATTER_ISO)));
     }
 
     /**
@@ -371,26 +388,27 @@ public class LoggingUtils {
         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) {
+    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);
+            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)));
+            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 + "}");
+        this.mlogger.info(OnapLogConstants.Markers.INVOKE, "");
+        this.mlogger.info(OnapLogConstants.Markers.INVOKE_SYNCHRONOUS + "{" + invocationId + "}");
         return con;
     }
 }
index 3c896b9..8952e5d 100644 (file)
@@ -23,6 +23,9 @@
 
 package org.onap.clamp.clds.util;
 
+import org.slf4j.Marker;
+import org.slf4j.MarkerFactory;
+
 /**
  * Constants for standard ONAP headers, MDCs, etc.
  */
@@ -41,6 +44,11 @@ public final class OnapLogConstants {
         throw new UnsupportedOperationException();
     }
 
+    ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
+    //
+    // Inner classes.
+    //
+    ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
 
     /**
      * Marker constants.
@@ -48,19 +56,35 @@ public final class OnapLogConstants {
     public static final class Markers {
 
         /** Marker reporting invocation. */
-        public static final String INVOKE = "INVOKE";
+        public static final Marker INVOKE = MarkerFactory.getMarker("INVOKE");
 
-        /** Marker reporting synchronous invocation. */
-        public static final String INVOKE_RETURN = "INVOKE-RETURN";
+        /** Marker reporting invocation return. */
+        public static final Marker INVOKE_RETURN = MarkerFactory.getMarker("INVOKE-RETURN");
 
         /** Marker reporting synchronous invocation. */
-        public static final String INVOKE_SYNC = "INVOKE-SYNCHRONOUS";
+        public static final Marker INVOKE_SYNCHRONOUS = build("INVOKE", "SYNCHRONOUS");
+
+        /** Marker reporting asynchronous invocation. */
+        public static final Marker INVOKE_ASYNCHRONOUS = build("INVOKE", "ASYNCHRONOUS");
 
         /** Marker reporting entry into a component. */
-        public static final String ENTRY = "ENTRY";
+        public static final Marker ENTRY = MarkerFactory.getMarker("ENTRY");
 
         /** Marker reporting exit from a component. */
-        public static final String EXIT = "EXIT";
+        public static final Marker EXIT = MarkerFactory.getMarker("EXIT");
+
+        /**
+         * Build nested, detached marker.
+         *
+         * @param m1 top token.
+         * @param m2 sub-token.
+         * @return detached Marker.
+         */
+        private static Marker build(final String m1, final String m2) {
+            final Marker marker = MarkerFactory.getDetachedMarker(m1);
+            marker.add(MarkerFactory.getDetachedMarker(m2));
+            return marker;
+        }
 
         /**
          * Hide and forbid construction.
@@ -80,10 +104,14 @@ public final class OnapLogConstants {
         /** MDC correlating messages for an invocation. */
         public static final String INVOCATION_ID = "InvocationID";
 
+        public static final String SERVER_INVOCATION_ID = "ServerInvocationId";
+
+        public static final String CLIENT_INVOCATION_ID = "ClientInvocationId";
+
         /** MDC correlating messages for a logical transaction. */
         public static final String REQUEST_ID = "RequestID";
 
-        /** MDC recording calling service. */
+        /** MDC recording calling partner name. */
         public static final String PARTNER_NAME = "PartnerName";
 
         /** MDC recording current service. */
@@ -96,51 +124,84 @@ public final class OnapLogConstants {
         public static final String INVOCATIONID_OUT = "InvocationIDOut";
 
         /** MDC recording target entity. */
-        public static final String TARGET_ENTITY = "TargetEngity";
+        public static final String TARGET_ENTITY = "TargetEntity";
 
-        /** MDC recording current service instance. */
-        public static final String INSTANCE_UUID = "InstanceUUID";
+        /** MDC recording target element. */
+        public static final String TARGET_ELEMENT = "TargetElement";
+
+        /** MDC recording current service instance id. */
+        public static final String SERVICE_INSTANCE_ID = "ServiceInstanceID";
+
+        /** MDC recording current instance id. */
+        public static final String INSTANCE_UUID = "InstanceID";
 
         // Network. ////////////////////////////////////////////////////////////
 
         /** MDC recording caller address. */
         public static final String CLIENT_IP_ADDRESS = "ClientIPAddress";
 
-        /** MDC recording server address. */
+        /** MDC recording server IP address. */
+        public static final String SERVER_IP_ADDRESS = "ServerIPAddress";
+
+        /** MDC recording server FQDN. */
         public static final String SERVER_FQDN = "ServerFQDN";
 
+        /** MDC recording virtual server name. */
+        public static final String VIRTUAL_SERVER_NAME = "VirtualServerName";
+
+        /** MDC recording context name. */
+        public static final String CONTEXT_NAME = "ContextName";
+
         /**
          * MDC recording timestamp at the start of the current request,
          * with the same scope as {@link #REQUEST_ID}.
          *
-         * <p>Open issues:
+         * <p>
+         * Open issues:
+         * <ul>
+         * <ul>
+         * Easily confused with {@link #INVOKE_TIMESTAMP}.
+         * </ul>
+         * <ul>
+         * No mechanism for propagation between components, e.g. via HTTP headers.
+         * </ul>
          * <ul>
-         *     <ul>Easily confused with {@link #INVOKE_TIMESTAMP}.</ul>
-         *     <ul>No mechanism for propagation between components, e.g. via HTTP headers.</ul>
-         *     <ul>Whatever mechanism we define, it's going to be costly.</ul>
+         * Whatever mechanism we define, it's going to be costly.
+         * </ul>
          * </ul>
          * </p>
-         * */
+         */
         public static final String ENTRY_TIMESTAMP = "EntryTimestamp";
-        public static final String END_TIMESTAMP = "EndTimestamp";
-        public static final String ELAPSED_TIMESTAMP = "ElapsedTime";
+
         /** MDC recording timestamp at the start of the current invocation. */
         public static final String INVOKE_TIMESTAMP = "InvokeTimestamp";
 
+        /** MDC recording elapsed time. */
+        public static final String ELAPSED_TIME = "ElapsedTime";
+
+        /** MDC recording log timestamp. */
+        public static final String LOG_TIMESTAMP = "LogTimestamp";
+
         // Outcomes. ///////////////////////////////////////////////////////////
 
         /** MDC reporting outcome code. */
         public static final String RESPONSE_CODE = "ResponseCode";
 
         /** MDC reporting outcome description. */
-        public static final String RESPONSE_DESCRIPTION = "ResponseDescription";
+        public static final String RESPONSE_DESCRIPTION = "ResponseDesc";
 
-        /** MDC reporting outcome error level. */
+        /** MDC reporting severity */
         public static final String RESPONSE_SEVERITY = "Severity";
 
-        /** MDC reporting outcome error level. */
+        /** MDC reporting response status code */
         public static final String RESPONSE_STATUS_CODE = "StatusCode";
 
+        /** MDC recording error code. */
+        public static final String ERROR_CODE = "ErrorCode";
+
+        /** MDC recording error description. */
+        public static final String ERROR_DESC = "ErrorDesc";
+
         // Unsorted. ///////////////////////////////////////////////////////////
 
         /**
@@ -159,7 +220,7 @@ public final class OnapLogConstants {
         /** HTTP <tt>X-ONAP-RequestID</tt> header. */
         public static final String REQUEST_ID = "X-ONAP-RequestID";
 
-        /** HTTP <tt>X-ONAP-InvocationID</tt> header. */
+        /** HTTP <tt>X-InvocationID</tt> header. */
         public static final String INVOCATION_ID = "X-ONAP-InvocationID";
 
         /** HTTP <tt>X-ONAP-PartnerName</tt> header. */
@@ -185,9 +246,59 @@ public final class OnapLogConstants {
     public enum ResponseStatus {
 
         /** Success. */
-        COMPLETED,
+        COMPLETE,
 
         /** Not. */
         ERROR,
+
+        /** In Progress. */
+        INPROGRESS
     }
+
+    /**
+     * Synchronous or asynchronous execution, for setting invocation marker.
+     */
+    public enum InvocationMode {
+
+        /** Synchronous, blocking. */
+        SYNCHRONOUS("SYNCHRONOUS", Markers.INVOKE_SYNCHRONOUS),
+
+        /** Asynchronous, non-blocking. */
+        ASYNCHRONOUS("ASYNCHRONOUS", Markers.INVOKE_ASYNCHRONOUS);
+
+        /** Enum value. */
+        private String mString;
+
+        /** Corresponding marker. */
+        private Marker mMarker;
+
+        /**
+         * Construct enum.
+         *
+         * @param s enum value.
+         * @param m corresponding Marker.
+         */
+        InvocationMode(final String s, final Marker m) {
+            this.mString = s;
+            this.mMarker = m;
+        }
+
+        /**
+         * Get Marker for enum.
+         *
+         * @return Marker.
+         */
+        public Marker getMarker() {
+            return this.mMarker;
+        }
+
+        /**
+         * {@inheritDoc}
+         */
+        @Override
+        public String toString() {
+            return this.mString;
+        }
+    }
+
 }
index 868e424..e31406b 100644 (file)
 
 package org.onap.clamp.flow.log;
 
-import com.att.eelf.configuration.EELFLogger;
-import com.att.eelf.configuration.EELFManager;
-
 import javax.servlet.http.HttpServletRequest;
-
 import org.apache.camel.Exchange;
 import org.onap.clamp.clds.util.LoggingUtils;
 import org.onap.clamp.clds.util.OnapLogConstants;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import org.slf4j.event.Level;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.http.HttpStatus;
@@ -42,8 +40,7 @@ import org.springframework.stereotype.Component;
 @Component
 public class FlowLogOperation {
 
-    protected static final EELFLogger logger = EELFManager.getInstance().getLogger(FlowLogOperation.class);
-    protected static final EELFLogger auditLogger = EELFManager.getInstance().getMetricsLogger();
+    protected static final Logger logger = LoggerFactory.getLogger(FlowLogOperation.class);
     private LoggingUtils util = new LoggingUtils(logger);
 
     @Autowired
@@ -57,7 +54,8 @@ public class FlowLogOperation {
      */
     public void startLog(Exchange exchange, String serviceDesc) {
         util.entering(request, serviceDesc);
-        exchange.setProperty(OnapLogConstants.Headers.REQUEST_ID, util.getProperties(OnapLogConstants.Mdcs.REQUEST_ID));
+        exchange.setProperty(OnapLogConstants.Headers.REQUEST_ID,
+            util.getProperties(OnapLogConstants.Mdcs.REQUEST_ID));
         exchange.setProperty(OnapLogConstants.Headers.INVOCATION_ID,
             util.getProperties(OnapLogConstants.Mdcs.INVOCATION_ID));
         exchange.setProperty(OnapLogConstants.Headers.PARTNER_NAME,
@@ -68,14 +66,15 @@ public class FlowLogOperation {
      * Generate the exiting log.
      */
     public void endLog() {
-        util.exiting(HttpStatus.OK.toString(), "Successful", Level.INFO, OnapLogConstants.ResponseStatus.COMPLETED);
+        util.exiting(HttpStatus.OK.value(), "Successful", Level.INFO,
+            OnapLogConstants.ResponseStatus.COMPLETE);
     }
 
     /**
      * Generate the error exiting log.
      */
     public void errorLog() {
-        util.exiting(HttpStatus.INTERNAL_SERVER_ERROR.toString(), "Failed", Level.INFO,
+        util.exiting(HttpStatus.INTERNAL_SERVER_ERROR.value(), "Failed", Level.INFO,
             OnapLogConstants.ResponseStatus.ERROR);
     }
 
index a91f957..e263a13 100644 (file)
        <property
                name="debugPattern"
                value="%nopexception${p_tim}|${p_lvl}|${p_mdc}|${p_exc}|%msg%n" />
+               
+       <property
+               name="errorPattern"
+               value="%X{EntryTimestamp}|%X{RequestID}|%thread|%X{ServiceName}|%X{PartnerName}|%X{TargetEntity}|%X{TargetServiceName}||||%msg%n" />
+               
+       <property
+               name="auditPattern"
+               value="%X{EntryTimestamp}|%date{yyyy-MM-dd'T'HH:mm:ss.SSSXXX,UTC}|%X{RequestID}|%X{ServiceInstanceId}|%thread|%X{VirtualServerName}|%X{ServiceName}|%X{PartnerName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDesc}|%X{InstanceUUID}|%.-5level|%X{Severity}|%X{ServerIPAddress}|%X{ElapsedTime}|%X{ServerFQDN}|%X{RemoteHost}||||%marker|%mdc|||%msg%n" />
+               
+       <property
+               name="metricPattern"
+               value="%X{InvokeTimestamp}|%date{yyyy-MM-dd'T'HH:mm:ss.SSSXXX,UTC}|%X{RequestID}|%X{ServiceInstanceId}|%thread||%X{ServiceName}|%X{PartnerName}|%X{TargetEntity}|%X{TargetServiceName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDesc}|%X{InstanceUUID}|%.-5level|%X{Severity}|%X{ServerIPAddress}|%X{ElapsedTime}|%X{ServerFQDN}|%X{RemoteHost}||||%X{TargetVirtualEntity}|%marker|%mdc|||%msg%n" />
+
 
        <!-- Example evaluator filter applied against console appender -->
        <appender
        <appender
                name="ERROR"
                class="ch.qos.logback.core.rolling.RollingFileAppender">
-               <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
-                       <level>INFO</level>
-               </filter>
+               <filter class="ch.qos.logback.classic.filter.LevelFilter">
+            <level>ERROR</level>
+            <onMatch>ACCEPT</onMatch>
+            <onMismatch>DENY</onMismatch>
+        </filter>
                <file>${logDirectory}/error.log</file>
                <append>true</append>
                <encoder>
-                       <pattern>${defaultPattern}</pattern>
+                       <pattern>${errorPattern}</pattern>
                </encoder>
                <rollingPolicy
                        class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <appender
                name="AUDIT"
                class="ch.qos.logback.core.rolling.RollingFileAppender">
+               <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
+            <evaluator class="ch.qos.logback.classic.boolex.OnMarkerEvaluator">
+                <marker>ENTRY</marker>
+                <marker>EXIT</marker>
+            </evaluator>
+            <onMismatch>DENY</onMismatch>
+            <onMatch>ACCEPT</onMatch>
+        </filter>
                <file>${logDirectory}/audit.log</file>
                <append>true</append>
                <encoder>
-                       <pattern>%X{BeginTimestamp}|%X{EndTimestamp}|%X{RequestId}|%X{ServiceInstanceId}|%.20thread|%X{VirtualServerName}|%X{ServiceName}|%X{PartnerName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDescription}|%X{InstanceUUID}|%.-5level|%X{AlertSeverity}|%X{ServerIPAddress}|%X{ElapsedTime}|%X{ServerFQDN}|%X{RemoteHost}|%X{ClassName}|%X{Unused}|%X{ProcessKey}|%X{CustomField1}|%X{CustomField2}|%X{CustomField3}|%X{CustomField4}|%msg%n
-                       </pattern>
+                       <pattern>${auditPattern}</pattern>
                </encoder>
                <rollingPolicy
                                class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <appender
                name="METRIC"
                class="ch.qos.logback.core.rolling.RollingFileAppender">
+               <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
+            <evaluator class="ch.qos.logback.classic.boolex.OnMarkerEvaluator">
+                <marker>INVOKE</marker>
+                <marker>INVOKE-RETURN</marker>
+            </evaluator>
+            <onMismatch>DENY</onMismatch>
+            <onMatch>ACCEPT</onMatch>
+        </filter>
                <file>${logDirectory}/metric.log</file>
                <append>true</append>
                <encoder>
-                       <pattern>%X{BeginTimestamp}|%X{EndTimestamp}|%X{RequestId}|%X{ServiceInstanceId}|%.20thread|%X{VirtualServerName}|%X{ServiceName}|%X{PartnerName}|%X{TargetEntity}|%X{TargetServiceName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDescription}|%X{InstanceUUID}|%.-5level|%X{AlertSeverity}|%X{ServerIPAddress}|%X{ElapsedTime}|%X{ServerFQDN}|%X{RemoteHost}|%X{ClassName}|%X{Unused}|%X{ProcessKey}|%X{TargetVirtualEntity}|%X{CustomField1}|%X{CustomField2}|%X{CustomField3}|%X{CustomField4}|
-                               %msg%n</pattern>
+                       <pattern>${metricPattern}</pattern>
                </encoder>
                <rollingPolicy
                                class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
                <file>${logDirectory}/security.log</file>
                <append>true</append>
                <encoder>
-                       <pattern>%X{BeginTimestamp}|%X{EndTimestamp}|%X{RequestId}|%X{ServiceInstanceId}|%.20thread|%X{VirtualServerName}|%X{ServiceName}|%X{PartnerName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDescription}|%X{InstanceUUID}|%.-5level|%X{AlertSeverity}|%X{ServerIPAddress}|%X{ElapsedTime}|%X{ServerFQDN}|%X{RemoteHost}|%X{ClassName}|%X{Unused}|%X{ProcessKey}|%X{CustomField1}|%X{CustomField2}|%X{CustomField3}|%X{CustomField4}|%msg%n
+                       <pattern>%X{EntryTimestamp}|%date{yyyy-MM-dd'T'HH:mm:ss.SSSXXX,UTC}|%X{RequestID}|%X{ServiceInstanceId}|%.20thread|%X{VirtualServerName}|%X{ServiceName}|%X{PartnerName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDescription}|%X{InstanceUUID}|%.-5level|%X{AlertSeverity}|%X{ServerIPAddress}|%X{ElapsedTime}|%X{ServerFQDN}|%X{RemoteHost}|%X{ClassName}|%X{Unused}|%X{ProcessKey}|%X{CustomField1}|%X{CustomField2}|%X{CustomField3}|%X{CustomField4}|%msg%n
                        </pattern>
                </encoder>
                <rollingPolicy
        <root level="DEBUG">
                <appender-ref ref="DEBUG" />
                <appender-ref ref="STDOUT" />
+               <appender-ref ref="AUDIT" />
+        <appender-ref ref="METRIC" />
+        <appender-ref ref="ERROR" />
        </root>
 </included>
index 27a06b2..7e823e1 100644 (file)
@@ -26,25 +26,23 @@ import static org.junit.Assert.assertNotNull;
 import static org.junit.Assert.assertNull;
 import static org.junit.Assert.assertTrue;
 
-import com.att.eelf.configuration.EELFLogger;
-import com.att.eelf.configuration.EELFManager;
-
 import java.time.ZoneOffset;
 import java.time.ZonedDateTime;
 import java.time.format.DateTimeFormatter;
 import java.util.Arrays;
 import java.util.Map;
-
 import javax.net.ssl.HttpsURLConnection;
 import javax.servlet.http.HttpServletRequest;
-
 import org.junit.Before;
 import org.junit.Test;
 import org.junit.runner.RunWith;
 import org.mockito.Mockito;
 import org.mockito.runners.MockitoJUnitRunner;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
 import org.slf4j.event.Level;
+import org.springframework.http.HttpStatus;
 import org.springframework.security.core.Authentication;
 import org.springframework.security.core.context.SecurityContext;
 import org.springframework.security.core.context.SecurityContextHolder;
@@ -56,7 +54,7 @@ import org.springframework.security.core.userdetails.UserDetails;
 @RunWith(MockitoJUnitRunner.class)
 public class LoggingUtilsTest {
 
-    private static final EELFLogger logger = EELFManager.getInstance().getLogger(LoggingUtilsTest.class);
+    protected static final Logger logger = LoggerFactory.getLogger(LoggingUtilsTest.class);
 
     private static final String SERVICE_NAME = "LogginUtilsTest: Test Entering method";
 
@@ -87,10 +85,10 @@ public class LoggingUtilsTest {
         util.entering(request, SERVICE_NAME);
 
         // then
-        String[] keys = { OnapLogConstants.Mdcs.PARTNER_NAME, OnapLogConstants.Mdcs.ENTRY_TIMESTAMP,
-                            OnapLogConstants.Mdcs.REQUEST_ID, OnapLogConstants.Mdcs.INVOCATION_ID,
-                            OnapLogConstants.Mdcs.CLIENT_IP_ADDRESS, OnapLogConstants.Mdcs.SERVER_FQDN,
-                            OnapLogConstants.Mdcs.INSTANCE_UUID, OnapLogConstants.Mdcs.SERVICE_NAME };
+        String[] keys = {OnapLogConstants.Mdcs.PARTNER_NAME, OnapLogConstants.Mdcs.ENTRY_TIMESTAMP,
+            OnapLogConstants.Mdcs.REQUEST_ID, OnapLogConstants.Mdcs.INVOCATION_ID,
+            OnapLogConstants.Mdcs.CLIENT_IP_ADDRESS, OnapLogConstants.Mdcs.SERVER_FQDN,
+            OnapLogConstants.Mdcs.INSTANCE_UUID, OnapLogConstants.Mdcs.SERVICE_NAME};
         Map<String, String> mdc = MDC.getMDCAdapter().getCopyOfContextMap();
 
         assertTrue(checkMapKeys(mdc, keys));
@@ -101,10 +99,11 @@ public class LoggingUtilsTest {
     public void testExistingLoggingUtils() {
         // given
         MDC.put(OnapLogConstants.Mdcs.ENTRY_TIMESTAMP,
-                ZonedDateTime.now(ZoneOffset.UTC).format(DateTimeFormatter.ISO_INSTANT));
+            ZonedDateTime.now(ZoneOffset.UTC).format(DateTimeFormatter.ISO_INSTANT));
 
         // when
-        util.exiting("200", SERVICE_NAME, Level.INFO, OnapLogConstants.ResponseStatus.COMPLETED);
+        util.exiting(HttpStatus.OK.value(), SERVICE_NAME, Level.INFO,
+            OnapLogConstants.ResponseStatus.COMPLETE);
 
         // then
         Map<String, String> mdc = MDC.getMDCAdapter().getCopyOfContextMap();
@@ -123,8 +122,9 @@ public class LoggingUtilsTest {
 
         // then
         assertNotNull(secureConnection);
-        String[] keys = { OnapLogConstants.Mdcs.TARGET_ENTITY, OnapLogConstants.Mdcs.TARGET_SERVICE_NAME,
-                            OnapLogConstants.Mdcs.INVOCATIONID_OUT, OnapLogConstants.Mdcs.INVOKE_TIMESTAMP };
+        String[] keys =
+            {OnapLogConstants.Mdcs.TARGET_ENTITY, OnapLogConstants.Mdcs.TARGET_SERVICE_NAME,
+                OnapLogConstants.Mdcs.INVOCATIONID_OUT, OnapLogConstants.Mdcs.INVOKE_TIMESTAMP};
         Map<String, String> mdc = MDC.getMDCAdapter().getCopyOfContextMap();
 
         assertTrue(checkMapKeys(mdc, keys));