vid-automation/src/test/java/org/onap/vid/more/LoggerFormatTest.java

   1 package org.onap.vid.more;
   2
   3 import static java.util.Collections.reverse;
   4 import static java.util.stream.Collectors.toList;
   5 import static org.hamcrest.CoreMatchers.containsString;
   6 import static org.hamcrest.CoreMatchers.is;
   7 import static org.hamcrest.MatcherAssert.assertThat;
   8 import static org.hamcrest.Matchers.allOf;
   9 import static org.hamcrest.Matchers.contains;
  10 import static org.hamcrest.Matchers.containsInAnyOrder;
  11 import static org.hamcrest.Matchers.containsInRelativeOrder;
  12 import static org.hamcrest.Matchers.either;
  13 import static org.hamcrest.Matchers.emptyOrNullString;
  14 import static org.hamcrest.Matchers.greaterThan;
  15 import static org.hamcrest.Matchers.greaterThanOrEqualTo;
  16 import static org.hamcrest.Matchers.hasSize;
  17 import static org.hamcrest.Matchers.matchesPattern;
  18 import static org.onap.vid.api.TestUtils.assertAndRetryIfNeeded;
  19 import static vid.automation.test.services.SimulatorApi.retrieveRecordedRequests;
  20
  21 import com.fasterxml.jackson.databind.JsonNode;
  22 import java.lang.reflect.Method;
  23 import java.net.URI;
  24 import java.util.ArrayList;
  25 import java.util.Arrays;
  26 import java.util.HashMap;
  27 import java.util.HashSet;
  28 import java.util.LinkedList;
  29 import java.util.List;
  30 import java.util.Map;
  31 import java.util.Random;
  32 import org.apache.commons.lang3.StringUtils;
  33 import org.apache.commons.lang3.exception.ExceptionUtils;
  34 import org.apache.logging.log4j.LogManager;
  35 import org.apache.logging.log4j.Logger;
  36 import org.jetbrains.annotations.NotNull;
  37 import org.onap.simulator.presetGenerator.presets.aai.PresetAAIGetSubscribersGet;
  38 import org.onap.vid.api.BaseApiTest;
  39 import org.springframework.web.client.RestClientException;
  40 import org.springframework.web.client.RestTemplate;
  41 import org.testng.annotations.BeforeClass;
  42 import org.testng.annotations.DataProvider;
  43 import org.testng.annotations.Test;
  44 import vid.automation.test.services.SimulatorApi;
  45 import vid.automation.test.services.SimulatorApi.RecordedRequests;
  46
  47 public class LoggerFormatTest extends BaseApiTest {
  48
  49     private final static String logChecker = System.getProperty("EELF_LOG_CHECKER", "http://my-logchecker:8888/validate");
  50     private final Logger logger = LogManager.getLogger(LoggerFormatTest.class);
  51     private final int PRIORITY_LAST = 999;
  52
  53     public enum LogName {
  54         audit2019, error, metrics2019, debug
  55     }
  56
  57     @BeforeClass
  58     public void login() {
  59         super.login();
  60     }
  61
  62     @BeforeClass
  63     public void setAaiSubscribers() {
  64         SimulatorApi.registerExpectationFromPreset(new PresetAAIGetSubscribersGet(), SimulatorApi.RegistrationStrategy.CLEAR_THEN_SET);
  65     }
  66
  67     @DataProvider
  68     public static Object[][] logsAndFormats(Method test) {
  69         return new Object[][]{
  70                 {LogName.debug, "debug", 0.95 },
  71                 {LogName.metrics2019, "metric-ELS-2019.11", 0.95},
  72                 {LogName.audit2019, "audit-ELS-2019.11", 0.95},
  73                 {LogName.error, "error", 0.75 }
  74         };
  75     }
  76
  77
  78     @Test(dataProvider = "logsAndFormats", priority = PRIORITY_LAST)
  79     public void validateLogsAndFormat(LogName logName, String logCheckerFormat, Double expectedRank){
  80         String logLines = validateLogsFormat(logName, logCheckerFormat, expectedRank);
  81
  82         if (logName == LogName.audit2019)
  83         {
  84             moreValidationsForAuditFormat(logLines);
  85         }
  86     }
  87
  88     //more validations for log format that logcheck doesn't verify
  89     private void moreValidationsForAuditFormat (String logLines){
  90         splitLogLines(logLines).forEach(line -> {
  91             String[] records = line.split("\\|");
  92             assertThat("server name shall be empty", records[5], emptyOrNullString());
  93
  94             //authenticated request shall logs with userId.
  95             final String serviceName = records[6];
  96             if (StringUtils.containsAny(serviceName, "aai", "mso")) {
  97                 assertThat("Partner name shall be userId", records[7], matchesPattern("^[A-Za-z0-9]{4,15}$"));
  98             }
  99
 100             assertThat("Severity shall be empty", records[13], emptyOrNullString());
 101             assertThat("marker", records[21], either(is("ENTRY")).or(is("EXIT")));
 102         });
 103     }
 104
 105     private String validateLogsFormat (LogName logName, String logType){
 106         return validateLogsFormat(logName, logType, 0.95);
 107     }
 108
 109     private String validateLogsFormat (LogName logName, String logType,double score){
 110
 111         String logLines = getLogLines(logName);
 112         logger.info("logLines are: " + logLines);
 113         JsonNode response = getCheckerResults(logType, logLines);
 114         logger.info("Response is:" + response.toString());
 115
 116         int total_records = response.path("summary").path("total_records").asInt();
 117         int valid_records = response.path("summary").path("valid_records").asInt();
 118
 119         assertThat(total_records, greaterThan(30)); //make sure we have at least 30 total records
 120         assertThat((double) valid_records / total_records, is(greaterThanOrEqualTo(score)));
 121
 122         return logLines;
 123     }
 124
 125     private String getLogLines (LogName logname){
 126         return getLogLines(logname, 5000, 30, restTemplate, uri);
 127     }
 128
 129     public static String getLogLines (LogName logname,int maxRows, int minRows, RestTemplate restTemplate, URI uri){
 130         String logLines = restTemplate.getForObject(uri + "/logger/" + logname.name() + "?limit={maxRows}", String.class, maxRows);
 131         assertThat("expecting at least " + minRows + " rows in " + logname.name(),
 132                 StringUtils.countMatches(logLines, '\n') + 1,
 133                 is(greaterThanOrEqualTo(minRows)));
 134         return logLines;
 135     }
 136
 137     /**
 138      * @return Chronological-ordered list of recent log-lines
 139      */
 140     public static List<String> getLogLinesAsList (LogName logname,int maxRows, int minRows, RestTemplate restTemplate, URI uri){
 141         String logLines = LoggerFormatTest.getLogLines(logname, maxRows, minRows, restTemplate, uri);
 142         List<String> lines = splitLogLines(logLines);
 143
 144         // Reverse
 145         reverse(lines);
 146
 147         return lines;
 148     }
 149
 150     @NotNull
 151     private static List<String> splitLogLines (String logLines){
 152         return new ArrayList<>(Arrays.asList(logLines.split("(\\r?\\n)")));
 153     }
 154
 155
 156     /**
 157      * @return Chronological-ordered list of recent log-lines of a given requestId
 158      */
 159     public static List<String> getRequestLogLines (String requestId, LogName logname, RestTemplate restTemplate, URI uri){
 160
 161         List<String> lines = getLogLinesAsList(logname, 30, 1, restTemplate, uri);
 162
 163         //Filter
 164         lines.removeIf(line -> !StringUtils.containsIgnoreCase(line, requestId));
 165
 166         return lines;
 167     }
 168
 169     public static void verifyExistenceOfIncomingReqsInAuditLogs (RestTemplate restTemplate, URI uri, String requestId, String path){
 170         assertAndRetryIfNeeded(5, () -> {
 171             List<String> logLines = getRequestLogLines(requestId, LogName.audit2019, restTemplate, uri);
 172             String requestIdPrefix = "RequestID=";
 173             assertThat("\nENTRY & EXIT logs are expected to include RequestId: " + requestId
 174                     + " \nAnd request path: "
 175                     + path +
 176                     "\nin exactly two rows - inside the audit log matching lines:\n"
 177                     + String.join("\n", logLines) + "\n",
 178                 logLines,
 179                 contains(
 180                     allOf(
 181                         containsString(requestIdPrefix + requestId),
 182                         containsString("ENTRY"),
 183                         containsString(path)),
 184                     allOf(
 185                         containsString(requestIdPrefix + requestId),
 186                         containsString("EXIT"),
 187                         containsString(path))
 188                 ));
 189         });
 190     }
 191
 192     public static void assertHeadersAndMetricLogs (RestTemplate restTemplate, URI uri, String requestId, String path, int requestsSize){
 193         List<RecordedRequests> requests = retrieveRecordedRequests();
 194         List<RecordedRequests> underTestRequests =
 195                 requests.stream().filter(x -> x.path.contains(path)).collect(toList());
 196
 197         assertThat(underTestRequests, hasSize(requestsSize));
 198
 199         underTestRequests.forEach(request -> {
 200             assertThat("X-ONAP-RequestID", request.headers.get("X-ONAP-RequestID"), contains(requestId));
 201             assertThat("X-ECOMP-RequestID", request.headers.get("X-ECOMP-RequestID"), contains(requestId));
 202             assertThat("X-ONAP-PartnerName", request.headers.get("X-ONAP-PartnerName"), contains("VID.VID"));
 203         });
 204
 205         List<String> allInvocationIds = new LinkedList<>();
 206
 207         underTestRequests.forEach(request -> {
 208
 209             List<String> invocationIds = request.headers.get("X-InvocationID");
 210             assertThat(invocationIds, hasSize(1));
 211
 212             String invocationId = invocationIds.get(0);
 213             allInvocationIds.add(invocationId);
 214
 215             assertAndRetryIfNeeded(5, () -> assertIdsInMetricsLog(
 216                 getRequestLogLines(requestId, LogName.metrics2019, restTemplate, uri), requestId, invocationId)
 217             );
 218         });
 219
 220         //make sure no InvocationId is repeated twice
 221         assertThat("expect all InvocationIds to be unique",
 222                 allInvocationIds, containsInAnyOrder(new HashSet<>(allInvocationIds).toArray()));
 223     }
 224
 225     public static void assertIdsInMetricsLog (List < String > logLines, String requestId, String invocationId){
 226         assertThat("request id and invocation id must be found in exactly two rows in: \n" + String.join("\n", logLines),
 227                 logLines,
 228                 containsInRelativeOrder(
 229                         allOf(
 230                                 containsString("RequestID=" + requestId),
 231                                 containsString("InvocationID=" + invocationId),
 232                                 containsString("Invoke")),
 233                         allOf(
 234                                 containsString("RequestID=" + requestId),
 235                                 containsString("InvocationID=" + invocationId),
 236                                 containsString("InvokeReturn"))
 237                 ));
 238     }
 239
 240     private JsonNode getCheckerResults (String logtype, String logLines){
 241
 242         final int MAX_RETRIES = 3;
 243
 244         Map<String, String> params = new HashMap<>();
 245         params.put("format", "raw");
 246         params.put("type", logtype);
 247         params.put("component", "vid");
 248         params.put("data", logLines);
 249
 250         for (int i=0; i< MAX_RETRIES; i++) {
 251             try {
 252                 return restTemplate.postForObject(logChecker, params, JsonNode.class);
 253             } catch (RestClientException exception) { //retry for cases that logchecker is not available immediately
 254                 logger.error("Failed to call to logChecker try: " + i, exception);
 255                 if (i<(MAX_RETRIES-1)) { //no need to sleep on last retry
 256                     try {
 257                         Thread.sleep((new Random().nextInt(2000) + 1000)); //random sleep between 1-3 seconds
 258                     } catch (InterruptedException e) {
 259                         ExceptionUtils.rethrow(e);
 260                     }
 261                 }
 262             }
 263         }
 264         throw new AssertionError("failed to call to logChecker after max retries: "+MAX_RETRIES);
 265     }
 266 }