src/main/java/org/onap/clamp/clds/util/LoggingUtils.java

   1 /*-
   2  * ============LICENSE_START=======================================================
   3  * ONAP CLAMP
   4  * ================================================================================
   5  * Copyright (C) 2017-2018 AT&T Intellectual Property. All rights
   6  *                             reserved.
   7  * ================================================================================
   8  * Licensed under the Apache License, Version 2.0 (the "License");
   9  * you may not use this file except in compliance with the License.
  10  * You may obtain a copy of the License at
  11  *
  12  * http://www.apache.org/licenses/LICENSE-2.0
  13  *
  14  * Unless required by applicable law or agreed to in writing, software
  15  * distributed under the License is distributed on an "AS IS" BASIS,
  16  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  17  * See the License for the specific language governing permissions and
  18  * limitations under the License.
  19  * ============LICENSE_END============================================
  20  * ===================================================================
  21  *
  22  */
  23
  24 package org.onap.clamp.clds.util;
  25
  26 import java.net.HttpURLConnection;
  27 import java.net.InetAddress;
  28 import java.net.URLConnection;
  29 import java.net.UnknownHostException;
  30 import java.text.DateFormat;
  31 import java.text.SimpleDateFormat;
  32 import java.time.ZoneOffset;
  33 import java.time.ZonedDateTime;
  34 import java.time.format.DateTimeFormatter;
  35 import java.time.temporal.ChronoUnit;
  36 import java.util.Date;
  37 import java.util.TimeZone;
  38 import java.util.UUID;
  39 import javax.net.ssl.HttpsURLConnection;
  40 import javax.servlet.http.HttpServletRequest;
  41 import javax.validation.constraints.NotNull;
  42 import org.onap.clamp.authorization.AuthorizationController;
  43 import org.slf4j.Logger;
  44 import org.slf4j.LoggerFactory;
  45 import org.slf4j.MDC;
  46 import org.slf4j.event.Level;
  47 import org.springframework.security.core.context.SecurityContextHolder;
  48
  49 /**
  50  * This class handles the special info that appear in the log, like RequestID,
  51  * time context, ...
  52  */
  53 public class LoggingUtils {
  54
  55     protected static final Logger logger = LoggerFactory.getLogger(LoggingUtils.class);
  56
  57     private static final DateFormat DATE_FORMAT = createDateFormat();
  58
  59     private static final String DATE_FORMATTER_ISO = "yyyy-MM-dd'T'HH:mm:ss.SSSXXX";
  60
  61     /** String constant for messages <tt>ENTERING</tt>, <tt>EXITING</tt>, etc. */
  62     private static final String EMPTY_MESSAGE = "";
  63
  64     /** Logger delegate. */
  65     private Logger mlogger;
  66
  67     /** Automatic UUID, overrideable per adapter or per invocation. */
  68     private static UUID sInstanceUUID = UUID.randomUUID();
  69
  70     /**
  71      * Constructor.
  72      */
  73     public LoggingUtils(final Logger loggerP) {
  74         this.mlogger = checkNotNull(loggerP);
  75     }
  76
  77     /**
  78      * Set request related logging variables in thread local data via MDC.
  79      *
  80      * @param service Service Name of API (ex. "PUT template")
  81      * @param partner Partner name (client or user invoking API)
  82      */
  83     public static void setRequestContext(String service, String partner) {
  84         MDC.put("RequestId", UUID.randomUUID().toString());
  85         MDC.put("ServiceName", service);
  86         MDC.put("PartnerName", partner);
  87         // Defaulting to HTTP/1.1 protocol
  88         MDC.put("Protocol", "HTTP/1.1");
  89         try {
  90             MDC.put("ServerFQDN", InetAddress.getLocalHost().getCanonicalHostName());
  91             MDC.put("ServerIPAddress", InetAddress.getLocalHost().getHostAddress());
  92         } catch (UnknownHostException e) {
  93             logger.error("Failed to initiate setRequestContext", e);
  94         }
  95     }
  96
  97     /**
  98      * Set time related logging variables in thread local data via MDC.
  99      *
 100      * @param beginTimeStamp Start time
 101      * @param endTimeStamp End time
 102      */
 103     public static void setTimeContext(@NotNull Date beginTimeStamp, @NotNull Date endTimeStamp) {
 104         MDC.put("EntryTimestamp", generateTimestampStr(beginTimeStamp));
 105         MDC.put("EndTimestamp", generateTimestampStr(endTimeStamp));
 106         MDC.put("ElapsedTime", String.valueOf(endTimeStamp.getTime() - beginTimeStamp.getTime()));
 107     }
 108
 109     /**
 110      * Set response related logging variables in thread local data via MDC.
 111      *
 112      * @param code Response code ("0" indicates success)
 113      * @param description Response description
 114      * @param className class name of invoking class
 115      */
 116     public static void setResponseContext(String code, String description, String className) {
 117         MDC.put("ResponseCode", code);
 118         MDC.put("StatusCode", "0".equals(code) ? "COMPLETE" : "ERROR");
 119         MDC.put("ResponseDescription", description != null ? description : "");
 120         MDC.put("ClassName", className != null ? className : "");
 121     }
 122
 123     /**
 124      * Set target related logging variables in thread local data via MDC.
 125      *
 126      * @param targetEntity Target entity (an external/sub component, for ex. "sdc")
 127      * @param targetServiceName Target service name (name of API invoked on target)
 128      */
 129     public static void setTargetContext(String targetEntity, String targetServiceName) {
 130         MDC.put("TargetEntity", targetEntity != null ? targetEntity : "");
 131         MDC.put("TargetServiceName", targetServiceName != null ? targetServiceName : "");
 132     }
 133
 134     /**
 135      * Set error related logging variables in thread local data via MDC.
 136      *
 137      * @param code Error code
 138      * @param description Error description
 139      */
 140     public static void setErrorContext(String code, String description) {
 141         MDC.put("ErrorCode", code);
 142         MDC.put("ErrorDescription", description != null ? description : "");
 143     }
 144
 145     private static String generateTimestampStr(Date timeStamp) {
 146         return DATE_FORMAT.format(timeStamp);
 147     }
 148
 149     /**
 150      * Get a previously stored RequestID for the thread local data via MDC. If
 151      * one was not previously stored, generate one, store it, and return that
 152      * one.
 153      *
 154      * @return A string with the request ID
 155      */
 156     public static String getRequestId() {
 157         String requestId = MDC.get(OnapLogConstants.Mdcs.REQUEST_ID);
 158         if (requestId == null || requestId.isEmpty()) {
 159             requestId = UUID.randomUUID().toString();
 160             MDC.put(OnapLogConstants.Mdcs.REQUEST_ID, requestId);
 161         }
 162         return requestId;
 163     }
 164
 165     private static DateFormat createDateFormat() {
 166         DateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ssX");
 167         dateFormat.setTimeZone(TimeZone.getTimeZone("UTC"));
 168         return dateFormat;
 169     }
 170
 171     /*********************************************************************************************
 172      * Method for ONAP Application Logging Specification v1.2
 173      ********************************************************************************************/
 174
 175     /**
 176      * Report <tt>ENTERING</tt> marker.
 177      *
 178      * @param request non-null incoming request (wrapper)
 179      * @param serviceName service name
 180      */
 181     public void entering(HttpServletRequest request, String serviceName) {
 182         // MDC.clear();
 183         checkNotNull(request);
 184         // Extract MDC values from standard HTTP headers.
 185         final String requestId =
 186             defaultToUuid(request.getHeader(OnapLogConstants.Headers.REQUEST_ID));
 187         final String invocationId =
 188             defaultToUuid(request.getHeader(OnapLogConstants.Headers.INVOCATION_ID));
 189         final String partnerName =
 190             defaultToEmpty(request.getHeader(OnapLogConstants.Headers.PARTNER_NAME));
 191
 192         // Default the partner name to the user name used to login to clamp
 193         if (partnerName.equalsIgnoreCase(EMPTY_MESSAGE)) {
 194             MDC.put(OnapLogConstants.Mdcs.PARTNER_NAME,
 195                 AuthorizationController.getPrincipalName(SecurityContextHolder.getContext()));
 196         }
 197
 198         // Set standard MDCs. Override this entire method if you want to set
 199         // others, OR set them BEFORE or AFTER the invocation of #entering,
 200         // depending on where you need them to appear, OR extend the
 201         // ServiceDescriptor to add them.
 202         MDC.put(OnapLogConstants.Mdcs.ENTRY_TIMESTAMP, ZonedDateTime.now(ZoneOffset.UTC)
 203             .format(DateTimeFormatter.ofPattern(DATE_FORMATTER_ISO)));
 204         MDC.put(OnapLogConstants.Mdcs.REQUEST_ID, requestId);
 205         MDC.put(OnapLogConstants.Mdcs.INVOCATION_ID, invocationId);
 206         MDC.put(OnapLogConstants.Mdcs.CLIENT_IP_ADDRESS, defaultToEmpty(request.getRemoteAddr()));
 207         MDC.put(OnapLogConstants.Mdcs.SERVER_FQDN, defaultToEmpty(request.getServerName()));
 208         MDC.put(OnapLogConstants.Mdcs.INSTANCE_UUID, defaultToEmpty(sInstanceUUID));
 209
 210         // Default the service name to the requestURI, in the event that
 211         // no value has been provided.
 212         if (serviceName == null || serviceName.equalsIgnoreCase(EMPTY_MESSAGE)) {
 213             MDC.put(OnapLogConstants.Mdcs.SERVICE_NAME, request.getRequestURI());
 214         } else {
 215             MDC.put(OnapLogConstants.Mdcs.SERVICE_NAME, serviceName);
 216         }
 217
 218         // Set the Response Status code to in progress
 219         MDC.put(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE,
 220             OnapLogConstants.ResponseStatus.INPROGRESS.toString());
 221         setElapsedTime();
 222
 223         this.mlogger.info(OnapLogConstants.Markers.ENTRY, "Entering");
 224     }
 225
 226     /**
 227      * Report <tt>EXITING</tt> marker.
 228      *
 229      *
 230      * @param code response code
 231      * @param descrption response description
 232      * @param severity response severity
 233      * @param status response status code
 234      */
 235     public void exiting(int code, String descrption, Level severity,
 236         OnapLogConstants.ResponseStatus status) {
 237         try {
 238
 239             MDC.put(OnapLogConstants.Mdcs.RESPONSE_CODE, defaultToEmpty(code));
 240             MDC.put(OnapLogConstants.Mdcs.RESPONSE_DESCRIPTION, defaultToEmpty(descrption));
 241             MDC.put(OnapLogConstants.Mdcs.RESPONSE_SEVERITY, defaultToEmpty(severity));
 242             MDC.put(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE, defaultToEmpty(status));
 243
 244             setElapsedTime();
 245             this.mlogger.info(OnapLogConstants.Markers.EXIT, "Exiting");
 246         } finally {
 247             MDC.clear();
 248         }
 249     }
 250
 251     private void setElapsedTime() {
 252         ZonedDateTime startTime =
 253             ZonedDateTime.parse(MDC.get(OnapLogConstants.Mdcs.ENTRY_TIMESTAMP),
 254                 DateTimeFormatter.ISO_DATE_TIME.withZone(ZoneOffset.UTC));
 255         ZonedDateTime endTime = ZonedDateTime.now(ZoneOffset.UTC);
 256         long duration = ChronoUnit.MILLIS.between(startTime, endTime);
 257         MDC.put(OnapLogConstants.Mdcs.ELAPSED_TIME, String.valueOf(duration));
 258     }
 259
 260     /**
 261      * Get the property value.
 262      *
 263      * @param name The name of the property
 264      * @return The value of the property
 265      */
 266     public String getProperties(String name) {
 267         return MDC.get(name);
 268     }
 269
 270     /**
 271      * Report pending invocation with <tt>INVOKE</tt> marker,
 272      * setting standard ONAP logging headers automatically.
 273      *
 274      * @param con The HTTP url connection
 275      * @param targetEntity The target entity
 276      * @param targetServiceName The target service name
 277      * @return The HTTP url connection
 278      */
 279     public HttpURLConnection invoke(final HttpURLConnection con, String targetEntity,
 280         String targetServiceName) {
 281         return this.invokeGeneric(con, targetEntity, targetServiceName);
 282     }
 283
 284     /**
 285      * Report pending invocation with <tt>INVOKE</tt> marker,
 286      * setting standard ONAP logging headers automatically.
 287      *
 288      * @param targetEntity The target entity
 289      * @param targetServiceName The target service name
 290      */
 291     public void invoke(String targetEntity, String targetServiceName) {
 292         final String invocationId = UUID.randomUUID().toString();
 293
 294         invokeContext(targetEntity, targetServiceName, invocationId);
 295
 296         // Log INVOKE*, with the invocationID as the message body.
 297         // (We didn't really want this kind of behavior in the standard,
 298         // but is it worse than new, single-message MDC?)
 299         this.mlogger.info(OnapLogConstants.Markers.INVOKE, "INVOKE");
 300         this.mlogger.info(OnapLogConstants.Markers.INVOKE_SYNCHRONOUS + "{" + invocationId + "}");
 301     }
 302
 303     /**
 304      * Report pending invocation with <tt>INVOKE</tt> marker,
 305      * setting standard ONAP logging headers automatically.
 306      *
 307      * @param con The HTTPS url connection
 308      * @param targetEntity The target entity
 309      * @param targetServiceName The target service name
 310      * @return The HTTPS url connection
 311      */
 312     public HttpsURLConnection invokeHttps(final HttpsURLConnection con, String targetEntity,
 313         String targetServiceName) {
 314         return this.invokeGeneric(con, targetEntity, targetServiceName);
 315     }
 316
 317     /**
 318      * Report pending invocation with <tt>INVOKE-RETURN</tt> marker.
 319      */
 320     public void invokeReturn() {
 321         MDC.put(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE,
 322             OnapLogConstants.ResponseStatus.COMPLETE.toString());
 323         // Add the Invoke-return marker and clear the needed MDC
 324         this.mlogger.info(OnapLogConstants.Markers.INVOKE_RETURN, "INVOKE-RETURN");
 325         invokeReturnContext();
 326     }
 327
 328     /**
 329      * Dependency-free nullcheck.
 330      *
 331      * @param in to be checked
 332      * @param <T> argument (and return) type
 333      * @return input arg
 334      */
 335     private static <T> T checkNotNull(final T in) {
 336         if (in == null) {
 337             throw new NullPointerException();
 338         }
 339         return in;
 340     }
 341
 342     /**
 343      * Dependency-free string default.
 344      *
 345      * @param in to be filtered
 346      * @return input string or null
 347      */
 348     private static String defaultToEmpty(final Object in) {
 349         if (in == null) {
 350             return "";
 351         }
 352         return in.toString();
 353     }
 354
 355     /**
 356      * Dependency-free string default.
 357      *
 358      * @param in to be filtered
 359      * @return input string or null
 360      */
 361     private static String defaultToUuid(final String in) {
 362         if (in == null) {
 363             return UUID.randomUUID().toString();
 364         }
 365         return in;
 366     }
 367
 368     /**
 369      * Set target related logging variables in thread local data via MDC.
 370      *
 371      * @param targetEntity Target entity (an external/sub component, for ex. "sdc")
 372      * @param targetServiceName Target service name (name of API invoked on target)
 373      * @param invocationId The invocation ID
 374      */
 375     private void invokeContext(String targetEntity, String targetServiceName, String invocationId) {
 376         MDC.put(OnapLogConstants.Mdcs.TARGET_ENTITY, defaultToEmpty(targetEntity));
 377         MDC.put(OnapLogConstants.Mdcs.TARGET_SERVICE_NAME, defaultToEmpty(targetServiceName));
 378         MDC.put(OnapLogConstants.Mdcs.INVOCATIONID_OUT, invocationId);
 379         MDC.put(OnapLogConstants.Mdcs.INVOKE_TIMESTAMP, ZonedDateTime.now(ZoneOffset.UTC)
 380             .format(DateTimeFormatter.ofPattern(DATE_FORMATTER_ISO)));
 381     }
 382
 383     /**
 384      * Clear target related logging variables in thread local data via MDC.
 385      */
 386     private void invokeReturnContext() {
 387         MDC.remove(OnapLogConstants.Mdcs.TARGET_ENTITY);
 388         MDC.remove(OnapLogConstants.Mdcs.TARGET_SERVICE_NAME);
 389         MDC.remove(OnapLogConstants.Mdcs.INVOCATIONID_OUT);
 390         MDC.remove(OnapLogConstants.Mdcs.INVOKE_TIMESTAMP);
 391         MDC.remove(OnapLogConstants.Mdcs.RESPONSE_STATUS_CODE);
 392     }
 393
 394     private <T extends URLConnection> T invokeGeneric(final T con, String targetEntity,
 395         String targetServiceName) {
 396         final String invocationId = UUID.randomUUID().toString();
 397
 398         // Set standard HTTP headers on (southbound request) builder.
 399         con.setRequestProperty(OnapLogConstants.Headers.REQUEST_ID,
 400             defaultToEmpty(MDC.get(OnapLogConstants.Mdcs.REQUEST_ID)));
 401         con.setRequestProperty(OnapLogConstants.Headers.INVOCATION_ID, invocationId);
 402         con.setRequestProperty(OnapLogConstants.Headers.PARTNER_NAME,
 403             defaultToEmpty(MDC.get(OnapLogConstants.Mdcs.PARTNER_NAME)));
 404
 405         invokeContext(targetEntity, targetServiceName, invocationId);
 406
 407         // Log INVOKE*, with the invocationID as the message body.
 408         // (We didn't really want this kind of behavior in the standard,
 409         // but is it worse than new, single-message MDC?)
 410         this.mlogger.info(OnapLogConstants.Markers.INVOKE, "");
 411         this.mlogger.info(OnapLogConstants.Markers.INVOKE_SYNCHRONOUS + "{" + invocationId + "}");
 412         return con;
 413     }
 414 }