/*- * ============LICENSE_START======================================================= * ONAP CLAMP * ================================================================================ * Copyright (C) 2017-2018 AT&T Intellectual Property. All rights * reserved. * ================================================================================ * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. * ============LICENSE_END============================================ * =================================================================== * */ package org.onap.clamp.clds.util; import java.net.HttpURLConnection; import java.net.InetAddress; import java.net.URLConnection; import java.net.UnknownHostException; import java.text.DateFormat; import java.text.SimpleDateFormat; import java.time.ZoneOffset; import java.time.ZonedDateTime; import java.time.format.DateTimeFormatter; 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.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; /** * This class handles the special info that appear in the log, like RequestID, * time context, ... */ public class LoggingUtils { 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 ENTERING, EXITING, etc. */ private static final String EMPTY_MESSAGE = ""; /** Logger delegate. */ private Logger mlogger; /** Automatic UUID, overrideable per adapter or per invocation. */ private static UUID sInstanceUUID = UUID.randomUUID(); /** * Constructor. */ public LoggingUtils(final Logger loggerP) { this.mlogger = checkNotNull(loggerP); } /** * Set request related logging variables in thread local data via MDC. * * @param service Service Name of API (ex. "PUT template") * @param partner Partner name (client or user invoking API) */ public static void setRequestContext(String service, String partner) { MDC.put("RequestId", UUID.randomUUID().toString()); MDC.put("ServiceName", service); MDC.put("PartnerName", partner); // Defaulting to HTTP/1.1 protocol MDC.put("Protocol", "HTTP/1.1"); try { MDC.put("ServerFQDN", InetAddress.getLocalHost().getCanonicalHostName()); MDC.put("ServerIPAddress", InetAddress.getLocalHost().getHostAddress()); } catch (UnknownHostException e) { logger.error("Failed to initiate setRequestContext", e); } } /** * Set time related logging variables in thread local data via MDC. * * @param beginTimeStamp Start time * @param endTimeStamp End time */ public static void setTimeContext(@NotNull Date beginTimeStamp, @NotNull Date endTimeStamp) { MDC.put("EntryTimestamp", generateTimestampStr(beginTimeStamp)); MDC.put("EndTimestamp", generateTimestampStr(endTimeStamp)); MDC.put("ElapsedTime", String.valueOf(endTimeStamp.getTime() - beginTimeStamp.getTime())); } /** * Set response related logging variables in thread local data via MDC. * * @param code Response code ("0" indicates success) * @param description Response description * @param className class name of invoking class */ public static void setResponseContext(String code, String description, String className) { MDC.put("ResponseCode", code); MDC.put("StatusCode", "0".equals(code) ? "COMPLETE" : "ERROR"); MDC.put("ResponseDescription", description != null ? description : ""); MDC.put("ClassName", className != null ? className : ""); } /** * Set target related logging variables in thread local data via MDC. * * @param targetEntity Target entity (an external/sub component, for ex. "sdc") * @param targetServiceName Target service name (name of API invoked on target) */ public static void setTargetContext(String targetEntity, String targetServiceName) { MDC.put("TargetEntity", targetEntity != null ? targetEntity : ""); MDC.put("TargetServiceName", targetServiceName != null ? targetServiceName : ""); } /** * Set error related logging variables in thread local data via MDC. * * @param code Error code * @param description Error description */ public static void setErrorContext(String code, String description) { MDC.put("ErrorCode", code); MDC.put("ErrorDescription", description != null ? description : ""); } private static String generateTimestampStr(Date timeStamp) { return DATE_FORMAT.format(timeStamp); } /** * Get a previously stored RequestID for the thread local data via MDC. If * one was not previously stored, generate one, store it, and return that * one. * * @return A string with the request ID */ public static String getRequestId() { String requestId = MDC.get(OnapLogConstants.Mdcs.REQUEST_ID); if (requestId == null || requestId.isEmpty()) { requestId = UUID.randomUUID().toString(); MDC.put(OnapLogConstants.Mdcs.REQUEST_ID, requestId); } return requestId; } private static DateFormat createDateFormat() { DateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ssX"); dateFormat.setTimeZone(TimeZone.getTimeZone("UTC")); return dateFormat; } /********************************************************************************************* * Method for ONAP Application Logging Specification v1.2 ********************************************************************************************/ /** * Report ENTERING marker. * * @param request non-null incoming request (wrapper) * @param serviceName service name */ public void entering(HttpServletRequest request, String serviceName) { // 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)); // 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())); } // 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.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()); } else { MDC.put(OnapLogConstants.Mdcs.SERVICE_NAME, serviceName); } // 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 EXITING marker. * * * @param code response code * @param descrption response description * @param severity response severity * @param status response status code */ 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)); 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. * * @param name The name of the property * @return The value of the property */ public String getProperties(String name) { return MDC.get(name); } /** * Report pending invocation with INVOKE marker, * setting standard ONAP logging headers automatically. * * @param con The HTTP url connection * @param targetEntity The target entity * @param targetServiceName The target service name * @return The HTTP url connection */ public HttpURLConnection invoke(final HttpURLConnection con, String targetEntity, String targetServiceName) { return this.invokeGeneric(con, targetEntity, targetServiceName); } /** * Report pending invocation with INVOKE marker, * setting standard ONAP logging headers automatically. * * @param targetEntity The target entity * @param targetServiceName The target service name */ public void invoke(String targetEntity, String targetServiceName) { final String invocationId = UUID.randomUUID().toString(); 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, "INVOKE"); this.mlogger.info(OnapLogConstants.Markers.INVOKE_SYNCHRONOUS + "{" + invocationId + "}"); } /** * Report pending invocation with INVOKE marker, * setting standard ONAP logging headers automatically. * * @param con The HTTPS url connection * @param targetEntity The target entity * @param targetServiceName The target service name * @return The HTTPS url connection */ public HttpsURLConnection invokeHttps(final HttpsURLConnection con, String targetEntity, String targetServiceName) { return this.invokeGeneric(con, targetEntity, targetServiceName); } /** * Report pending invocation with INVOKE-RETURN 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, "INVOKE-RETURN"); invokeReturnContext(); } /** * Dependency-free nullcheck. * * @param in to be checked * @param argument (and return) type * @return input arg */ private static T checkNotNull(final T in) { if (in == null) { throw new NullPointerException(); } return in; } /** * Dependency-free string default. * * @param in to be filtered * @return input string or null */ private static String defaultToEmpty(final Object in) { if (in == null) { return ""; } return in.toString(); } /** * Dependency-free string default. * * @param in to be filtered * @return input string or null */ private static String defaultToUuid(final String in) { if (in == null) { return UUID.randomUUID().toString(); } return in; } /** * Set target related logging variables in thread local data via MDC. * * @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 */ 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.RESPONSE_STATUS_CODE); } private 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; } }