diff options
author | Ashwin Sharma <ashwin.shyam.sharma@att.com> | 2020-07-27 07:55:07 +0000 |
---|---|---|
committer | Ashwin Sharma <ashwin.shyam.sharma@att.com> | 2020-07-27 16:54:29 +0000 |
commit | cac17e887b4df189fc9123097e1442d0b6c421b8 (patch) | |
tree | 92201ffb77a6eff6c2fb507edacbc1421ed066a9 /src | |
parent | 083e5a2aefd76bb1fc25bcb5528b7288b059c1c2 (diff) |
Fix audit, metric and error logs as per logging specification
Issue-ID: CLAMP-900
Signed-off-by: Ashwin Sharma <ashwin.shyam.sharma@att.com>
Change-Id: Ia911e16ecd4a5a03f44c45d32ebc874ff8882895
Diffstat (limited to 'src')
7 files changed, 290 insertions, 124 deletions
diff --git a/src/main/java/org/onap/clamp/authorization/AuthorizationController.java b/src/main/java/org/onap/clamp/authorization/AuthorizationController.java index e4a03fd38..f4da09a2e 100644 --- a/src/main/java/org/onap/clamp/authorization/AuthorizationController.java +++ b/src/main/java/org/onap/clamp/authorization/AuthorizationController.java @@ -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; diff --git a/src/main/java/org/onap/clamp/clds/service/CldsHealthcheckService.java b/src/main/java/org/onap/clamp/clds/service/CldsHealthcheckService.java index 6203cdf86..3fceace55 100644 --- a/src/main/java/org/onap/clamp/clds/service/CldsHealthcheckService.java +++ b/src/main/java/org/onap/clamp/clds/service/CldsHealthcheckService.java @@ -22,15 +22,13 @@ 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 +} diff --git a/src/main/java/org/onap/clamp/clds/util/LoggingUtils.java b/src/main/java/org/onap/clamp/clds/util/LoggingUtils.java index a471b411b..0ac1a14fc 100644 --- a/src/main/java/org/onap/clamp/clds/util/LoggingUtils.java +++ b/src/main/java/org/onap/clamp/clds/util/LoggingUtils.java @@ -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; } } diff --git a/src/main/java/org/onap/clamp/clds/util/OnapLogConstants.java b/src/main/java/org/onap/clamp/clds/util/OnapLogConstants.java index 3c896b907..8952e5df1 100644 --- a/src/main/java/org/onap/clamp/clds/util/OnapLogConstants.java +++ b/src/main/java/org/onap/clamp/clds/util/OnapLogConstants.java @@ -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; + } + } + } diff --git a/src/main/java/org/onap/clamp/flow/log/FlowLogOperation.java b/src/main/java/org/onap/clamp/flow/log/FlowLogOperation.java index 868e424e8..e31406b2c 100644 --- a/src/main/java/org/onap/clamp/flow/log/FlowLogOperation.java +++ b/src/main/java/org/onap/clamp/flow/log/FlowLogOperation.java @@ -23,14 +23,12 @@ 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); } diff --git a/src/main/resources/logback-default.xml b/src/main/resources/logback-default.xml index a91f9576b..e263a13fc 100644 --- a/src/main/resources/logback-default.xml +++ b/src/main/resources/logback-default.xml @@ -31,6 +31,19 @@ <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 @@ -48,13 +61,15 @@ <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"> @@ -89,11 +104,18 @@ <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"> @@ -114,11 +136,18 @@ <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"> @@ -144,7 +173,7 @@ <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 @@ -293,5 +322,8 @@ <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> diff --git a/src/test/java/org/onap/clamp/clds/util/LoggingUtilsTest.java b/src/test/java/org/onap/clamp/clds/util/LoggingUtilsTest.java index 27a06b213..7e823e163 100644 --- a/src/test/java/org/onap/clamp/clds/util/LoggingUtilsTest.java +++ b/src/test/java/org/onap/clamp/clds/util/LoggingUtilsTest.java @@ -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)); |