vid-app-common/src/main/java/org/onap/vid/utils/Logging.java

   1 /*-
   2  * ============LICENSE_START=======================================================
   3  * VID
   4  * ================================================================================
   5  * Copyright (C) 2017 - 2019 AT&T Intellectual Property. All rights reserved.
   6  * ================================================================================
   7  * Licensed under the Apache License, Version 2.0 (the "License");
   8  * you may not use this file except in compliance with the License.
   9  * You may obtain a copy of the License at
  10  *
  11  *      http://www.apache.org/licenses/LICENSE-2.0
  12  *
  13  * Unless required by applicable law or agreed to in writing, software
  14  * distributed under the License is distributed on an "AS IS" BASIS,
  15  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  16  * See the License for the specific language governing permissions and
  17  * limitations under the License.
  18  * ============LICENSE_END=========================================================
  19  */
  20
  21 package org.onap.vid.utils;
  22
  23 import static java.util.Collections.emptyMap;
  24 import static org.apache.commons.lang3.ObjectUtils.defaultIfNull;
  25 import static org.apache.commons.lang3.exception.ExceptionUtils.getRootCause;
  26 import static org.apache.commons.lang3.exception.ExceptionUtils.getThrowableList;
  27 import static org.onap.vid.utils.Streams.not;
  28
  29 import com.att.eelf.configuration.EELFLogger;
  30 import com.fasterxml.jackson.core.JsonProcessingException;
  31 import com.fasterxml.jackson.databind.ObjectMapper;
  32 import com.fasterxml.jackson.databind.SerializationFeature;
  33 import com.google.common.collect.ImmutableList;
  34 import io.joshworks.restclient.http.HttpResponse;
  35 import java.nio.charset.StandardCharsets;
  36 import java.util.Arrays;
  37 import java.util.Map;
  38 import java.util.Objects;
  39 import java.util.Optional;
  40 import java.util.UUID;
  41 import java.util.concurrent.Callable;
  42 import java.util.function.Function;
  43 import javax.servlet.http.HttpServletRequest;
  44 import javax.ws.rs.core.Response;
  45 import org.apache.commons.io.IOUtils;
  46 import org.apache.commons.lang3.StringUtils;
  47 import org.onap.portalsdk.core.logging.logic.EELFLoggerDelegate;
  48 import org.onap.portalsdk.core.util.SystemProperties;
  49 import org.onap.vid.exceptions.GenericUncheckedException;
  50 import org.onap.vid.utils.Unchecked.UncheckedThrowingSupplier;
  51 import org.slf4j.MDC;
  52 import org.springframework.http.HttpMethod;
  53 import org.springframework.stereotype.Service;
  54 import org.springframework.web.context.request.RequestContextHolder;
  55 import org.springframework.web.context.request.ServletRequestAttributes;
  56
  57 @Service
  58 public class Logging {
  59
  60     public static final String HTTP_REQUESTS_OUTGOING = "http.requests.outgoing.";
  61
  62     public static final String REQUEST_ID_HEADER_KEY = SystemProperties.ECOMP_REQUEST_ID;
  63     public static final String ONAP_REQUEST_ID_HEADER_KEY = "X-ONAP-RequestID";
  64
  65
  66     private static ObjectMapper objectMapper = new ObjectMapper();
  67
  68     public static String getMethodName() {
  69         return getMethodName(0);
  70     }
  71
  72     public static String getMethodCallerName() {
  73         return getMethodName(1);
  74     }
  75
  76     private static String getMethodName(int depth) {
  77         final StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace();
  78         String thisClassName = stackTrace[1].getClassName();
  79         final Optional<String> caller =
  80                 Arrays.stream(stackTrace)
  81                         .skip(1)
  82                         .filter(not(frame -> frame.getClassName().equals(thisClassName)))
  83                         .skip(depth)
  84                         .map(StackTraceElement::getMethodName)
  85                         .findFirst();
  86         return caller.orElse("<unknonwn method name>");
  87     }
  88
  89     public static EELFLogger getRequestsLogger(String serverName) {
  90         return EELFLoggerDelegate.getLogger(HTTP_REQUESTS_OUTGOING +serverName);
  91     }
  92
  93     public void logRequest(final EELFLogger logger, final HttpMethod method, final String url, final Object body) {
  94         if (!logger.isDebugEnabled()) {
  95             return;
  96         }
  97
  98         if (body == null) {
  99             logRequest(logger, method, url);
 100             return;
 101         }
 102
 103         try {
 104             String bodyAsJson = objectMapper.writeValueAsString(body);
 105             logger.debug("Sending  {} {} Body: {}", method.name(), url, bodyAsJson);
 106         } catch (JsonProcessingException e) {
 107             logRequest(logger, method, url);
 108             logger.debug("Failed to parse object in logRequest. {}", body);
 109         }
 110     }
 111
 112     public void logRequest(final EELFLogger logger, final HttpMethod method, final String url) {
 113         logger.debug("Sending  {} {}", method.name(), url);
 114     }
 115
 116     public <T> void logResponse(final EELFLogger logger, final HttpMethod method, final String url, final Response response, final Class<T> entityClass) {
 117         if (!logger.isDebugEnabled()) {
 118             return;
 119         }
 120         if (response == null) {
 121             logger.debug("Received {} {} response: null", method.name(), url);
 122             return;
 123         }
 124         try {
 125             response.bufferEntity();
 126             logger.debug("Received {} {} Status: {} . Body: {}", method.name(), url, response.getStatus(), new Substring(response.readEntity(entityClass)));
 127         }
 128         catch (Exception e) {
 129             logger.debug("Received {} {} Status: {} . Failed to read response as {}", method.name(), url, response.getStatus(), entityClass.getName());
 130         }
 131     }
 132
 133     public <T> void logResponse(final EELFLogger logger, final HttpMethod method, final String url, final HttpResponse<T> response) {
 134         try {
 135             logger.debug("Received {} {} Status: {} . Body: {}", method.name(),
 136                 url, response.getStatus(), new Substring(IOUtils.toString(response.getRawBody(), StandardCharsets.UTF_8)));
 137             response.getRawBody().reset();
 138         }
 139         catch (Exception e) {
 140             logger.debug("Received {} {} Status: {} . Failed to read response", method.name(), url, response.getStatus());
 141         }
 142     }
 143
 144     public void logResponse(final EELFLogger logger, final HttpMethod method, final String url, final Response response) {
 145         logResponse(logger, method, url, response, String.class);
 146     }
 147
 148     public static HttpServletRequest getHttpServletRequest(){
 149         return ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
 150     }
 151
 152     public static String extractOrGenerateRequestId() {
 153         try {
 154             return getHttpServletRequest().getHeader(REQUEST_ID_HEADER_KEY);
 155         }
 156         catch (IllegalStateException e) {
 157             //in async jobs we don't have any HttpServletRequest
 158             return UUID.randomUUID().toString();
 159         }
 160     }
 161
 162     public static void debugRequestDetails(Object requestDetails, final EELFLogger logger) {
 163         if (logger.isDebugEnabled()) {
 164             String requestDetailsAsString;
 165             try {
 166                 requestDetailsAsString = new ObjectMapper().enable(SerializationFeature.INDENT_OUTPUT).writeValueAsString(requestDetails);
 167             } catch (JsonProcessingException e) {
 168                 requestDetailsAsString = "error: cannot stringify RequestDetails";
 169             }
 170             logger.debug("requestDetailsAsString: {}", requestDetailsAsString);
 171         }
 172     }
 173
 174     public static String exceptionToDescription(Throwable exceptionToDescribe) {
 175         // Ignore top-most GenericUnchecked or Runtime exceptions that has no added message
 176         final Throwable top = getThrowableList(exceptionToDescribe).stream()
 177                 .filter(not(e -> ImmutableList.of(GenericUncheckedException.class, RuntimeException.class).contains(e.getClass())
 178                         && StringUtils.equals(e.getMessage(), e.getCause() == null ? null : e.getCause().toString())))
 179                 .findFirst().orElse(exceptionToDescribe);
 180
 181         final Throwable root = defaultIfNull(getRootCause(top), top);
 182
 183         String rootToString = root.toString();
 184
 185         // nullPointer description will include some context
 186         if (root.getClass().equals(NullPointerException.class) && root.getStackTrace().length > 0) {
 187             rootToString = String.format("NullPointerException at %s:%d",
 188                     root.getStackTrace()[0].getFileName(),
 189                     root.getStackTrace()[0].getLineNumber());
 190         }
 191
 192         // if input is a single exception, without cause: top.toString
 193         // else: return top.toString + root.toString
 194         //       but not if root is already described in top.toString
 195         if (top.equals(root)) {
 196             return rootToString;
 197         } else {
 198             final String topToString = top.toString();
 199             if (topToString.contains(root.getClass().getName()) && topToString.contains(root.getLocalizedMessage())) {
 200                 return topToString;
 201             } else {
 202                 return topToString + ": " + rootToString;
 203             }
 204         }
 205     }
 206
 207     /**
 208      * This class defers the toString() and truncation to the point in time where logger needs it.
 209      * This will save some bytes in memory if logger will decide to discard the logging (mostly because logging level
 210      * is filtering the message out).
 211      */
 212     static class Substring {
 213         private final Object obj;
 214         private final int maxLen = 1_000_000;
 215
 216         public Substring(Object obj) {
 217             this.obj = obj;
 218         }
 219
 220         @Override
 221         public String toString() {
 222             // null safe truncation
 223             return StringUtils.left(Objects.toString(obj), maxLen);
 224         }
 225     }
 226
 227     /**
 228      * in order to be able to write the correct data while creating the node on a new thread save a copy of the current
 229      * thread's context map, with keys and values of type String.
 230      */
 231     public <T> Callable<T> withMDC(Map<String, String> copyOfParentMDC, Callable<T> callable) {
 232         return () -> withMDCInternal(copyOfParentMDC, callable::call);
 233     }
 234
 235     /**
 236      * in order to be able to write the correct data while creating the node on a new thread save a copy of the current
 237      * thread's context map, with keys and values of type String.
 238      */
 239     public <T, U> Function<T, U> withMDC(Map<String, String> copyOfParentMDC, Function<T, U> function) {
 240         return t -> withMDCInternal(copyOfParentMDC, () -> function.apply(t));
 241     }
 242
 243     <T> T withMDCInternal(Map<String, String> copyOfParentMDC, UncheckedThrowingSupplier<T> supplier) {
 244         try {
 245             MDC.setContextMap(defaultIfNull(copyOfParentMDC, emptyMap()));
 246             return supplier.get();
 247         } finally {
 248             MDC.clear();
 249         }
 250     }
 251
 252 }