Make assertions of log messages better 91/3891/1
authorelinuxhenrik <henrik.b.andersson@est.tech>
Thu, 28 May 2020 10:28:20 +0000 (12:28 +0200)
committerelinuxhenrik <henrik.b.andersson@est.tech>
Thu, 28 May 2020 10:28:33 +0000 (12:28 +0200)
Also added some awaits to improve staiblity of timing sensitive tests.

Change-Id: I92593c26e1d0068d26b5cfffa1afb61cdfd6bb1e
Issue-ID: NONRTRIC-116
Signed-off-by: elinuxhenrik <henrik.b.andersson@est.tech>
policy-agent/src/main/java/org/oransc/policyagent/dmaap/DmaapMessageHandler.java
policy-agent/src/test/java/org/oransc/policyagent/ApplicationTest.java
policy-agent/src/test/java/org/oransc/policyagent/aspect/LogAspectTest.java
policy-agent/src/test/java/org/oransc/policyagent/clients/SdncOscA1ClientTest.java
policy-agent/src/test/java/org/oransc/policyagent/dmaap/DmaapMessageConsumerTest.java
policy-agent/src/test/java/org/oransc/policyagent/dmaap/DmaapMessageHandlerTest.java
policy-agent/src/test/java/org/oransc/policyagent/tasks/EnvironmentProcessorTest.java
policy-agent/src/test/java/org/oransc/policyagent/tasks/RefreshConfigTaskTest.java
policy-agent/src/test/java/org/oransc/policyagent/tasks/RicSynchronizationTaskTest.java
policy-agent/src/test/java/org/oransc/policyagent/tasks/ServiceSupervisionTest.java

index 3d5da62..c50a46f 100644 (file)
@@ -73,8 +73,8 @@ public class DmaapMessageHandler {
                 .flatMap(
                     response -> sendDmaapResponse(response.getBody(), dmaapRequestMessage, response.getStatusCode()));
         } catch (Exception e) {
-            logger.warn("Received unparsable message from DMAAP: {}", msg);
-            return Mono.error(e); // Cannot make any response
+            String errorMsg = "Received unparsable message from DMAAP: \"" + msg + "\", reason: " + e.getMessage();
+            return Mono.error(new ServiceException(errorMsg)); // Cannot make any response
         }
     }
 
index cffd1c4..a8cab60 100644 (file)
@@ -332,7 +332,7 @@ class ApplicationTest {
 
         url = "/policies";
         String rsp = restClient().get(url).block();
-        assertThat(rsp.contains(policyInstanceId)).isTrue();
+        assertThat(rsp.contains(policyInstanceId)).as("Response contains policy instance ID.").isTrue();
 
         url = "/policy?id=" + policyInstanceId;
         rsp = restClient().get(url).block();
@@ -400,10 +400,10 @@ class ApplicationTest {
 
         String rsp = restClient().get("/policies").block();
         List<PolicyInfo> info = parseList(rsp, PolicyInfo.class);
-        assertThat(info).size().isEqualTo(1);
+        assertThat(info.size()).isEqualTo(1);
         PolicyInfo policyInfo = info.get(0);
-        assertThat(policyInfo.id.equals("id1")).isTrue();
-        assertThat(policyInfo.type.equals("")).isTrue();
+        assertThat(policyInfo.id).isEqualTo("id1");
+        assertThat(policyInfo.type).isEqualTo("");
     }
 
     @Test
@@ -581,8 +581,9 @@ class ApplicationTest {
     @Test
     void testPutAndGetService() throws Exception {
         // PUT
-        putService("name", 0, HttpStatus.CREATED);
-        putService("name", 0, HttpStatus.OK);
+        String serviceName = "name";
+        putService(serviceName, 0, HttpStatus.CREATED);
+        putService(serviceName, 0, HttpStatus.OK);
 
         // GET one service
         String url = "/services?name=name";
@@ -591,12 +592,12 @@ class ApplicationTest {
         assertThat(info.size()).isEqualTo(1);
         ServiceStatus status = info.iterator().next();
         assertThat(status.keepAliveIntervalSeconds).isEqualTo(0);
-        assertThat(status.serviceName).isEqualTo("name");
+        assertThat(status.serviceName).isEqualTo(serviceName);
 
         // GET (all)
         url = "/services";
         rsp = restClient().get(url).block();
-        assertThat(rsp.contains("name")).isTrue();
+        assertThat(rsp.contains(serviceName)).as("Response contains service name").isTrue();
         logger.info(rsp);
 
         // Keep alive
@@ -610,17 +611,17 @@ class ApplicationTest {
         restClient().delete(url).block();
         assertThat(services.size()).isEqualTo(0);
 
-        // Keep alive, no registerred service
+        // Keep alive, no registered service
         testErrorCode(restClient().put("/services/keepalive?name=name", ""), HttpStatus.NOT_FOUND);
 
         // PUT servive with bad payload
         testErrorCode(restClient().put("/service", "crap"), HttpStatus.BAD_REQUEST);
         testErrorCode(restClient().put("/service", "{}"), HttpStatus.BAD_REQUEST);
-        testErrorCode(restClient().put("/service", createServiceJson("name", -123)), HttpStatus.BAD_REQUEST);
-        testErrorCode(restClient().put("/service", createServiceJson("name", 0, "missing.portandprotocol.com")),
+        testErrorCode(restClient().put("/service", createServiceJson(serviceName, -123)), HttpStatus.BAD_REQUEST);
+        testErrorCode(restClient().put("/service", createServiceJson(serviceName, 0, "missing.portandprotocol.com")),
             HttpStatus.BAD_REQUEST);
 
-        // GET non existing servive
+        // GET non existing service
         testErrorCode(restClient().get("/services?name=XXX"), HttpStatus.NOT_FOUND);
     }
 
@@ -648,7 +649,7 @@ class ApplicationTest {
 
         String url = "/policy_status?id=id";
         String rsp = restClient().get(url).block();
-        assertThat(rsp.equals("OK")).isTrue();
+        assertThat(rsp).isEqualTo("OK");
 
         // GET non existing policy status
         url = "/policy_status?id=XXX";
@@ -657,7 +658,7 @@ class ApplicationTest {
 
     private Policy addPolicy(String id, String typeName, String service, String ric) throws ServiceException {
         addRic(ric);
-        Policy p = ImmutablePolicy.builder() //
+        Policy policy = ImmutablePolicy.builder() //
             .id(id) //
             .json(jsonString()) //
             .ownerServiceName(service) //
@@ -666,8 +667,8 @@ class ApplicationTest {
             .lastModified("lastModified") //
             .isTransient(false) //
             .build();
-        policies.put(p);
-        return p;
+        policies.put(policy);
+        return policy;
     }
 
     private Policy addPolicy(String id, String typeName, String service) throws ServiceException {
@@ -716,11 +717,11 @@ class ApplicationTest {
         addPolicyType("type2", "ric");
 
         for (int i = 0; i < 10; ++i) {
-            Thread t =
+            Thread thread =
                 new Thread(new ConcurrencyTestRunnable(baseUrl(), supervision, a1ClientFactory, rics, policyTypes),
                     "TestThread_" + i);
-            t.start();
-            threads.add(t);
+            thread.start();
+            threads.add(thread);
         }
         for (Thread t : threads) {
             t.join();
@@ -755,11 +756,11 @@ class ApplicationTest {
             .verify();
     }
 
-    private boolean checkWebClientError(Throwable t, HttpStatus expStatus, String responseContains) {
-        assertTrue(t instanceof WebClientResponseException);
-        WebClientResponseException e = (WebClientResponseException) t;
-        assertThat(e.getStatusCode()).isEqualTo(expStatus);
-        assertThat(e.getResponseBodyAsString()).contains(responseContains);
+    private boolean checkWebClientError(Throwable throwable, HttpStatus expStatus, String responseContains) {
+        assertTrue(throwable instanceof WebClientResponseException);
+        WebClientResponseException responseException = (WebClientResponseException) throwable;
+        assertThat(responseException.getStatusCode()).isEqualTo(expStatus);
+        assertThat(responseException.getResponseBodyAsString()).contains(responseContains);
         return true;
     }
 
@@ -809,8 +810,8 @@ class ApplicationTest {
         List<T> result = new ArrayList<>();
         JsonArray jsonArr = JsonParser.parseString(jsonString).getAsJsonArray();
         for (JsonElement jsonElement : jsonArr) {
-            T o = gson.fromJson(jsonElement.toString(), clazz);
-            result.add(o);
+            T json = gson.fromJson(jsonElement.toString(), clazz);
+            result.add(json);
         }
         return result;
     }
index 7930e5c..6b53aa1 100644 (file)
@@ -47,7 +47,7 @@ class LogAspectTest {
         // 'proceed(Object[])' is never called
         verify(proceedingJoinPoint, never()).proceed(null);
 
-        assertThat(logAppender.list.toString().contains("Execution time of")).isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage()).startsWith("Execution time of");
     }
 
     @Test
@@ -60,7 +60,7 @@ class LogAspectTest {
 
         sampleAspect.entryLog(proceedingJoinPoint);
 
-        assertThat(logAppender.list.toString().contains("Entering method: " + signature)).isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage()).isEqualTo("Entering method: " + signature);
     }
 
     @Test
@@ -73,6 +73,6 @@ class LogAspectTest {
 
         sampleAspect.exitLog(proceedingJoinPoint);
 
-        assertThat(logAppender.list.toString().contains("Exiting method: " + signature)).isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage()).isEqualTo("Exiting method: " + signature);
     }
 }
index d63974e..8a2f044 100644 (file)
@@ -121,8 +121,8 @@ class SdncOscA1ClientTest {
 
         List<String> policyTypeIds = clientUnderTest.getPolicyTypeIdentities().block();
 
-        assertEquals(1, policyTypeIds.size(), "");
-        assertEquals(POLICY_TYPE_1_ID, policyTypeIds.get(0), "");
+        assertEquals(1, policyTypeIds.size());
+        assertEquals(POLICY_TYPE_1_ID, policyTypeIds.get(0));
 
         String expUrl = RIC_1_URL + "/a1-p/policytypes";
         ImmutableAdapterRequest expectedParams = ImmutableAdapterRequest.builder() //
@@ -137,7 +137,7 @@ class SdncOscA1ClientTest {
     void getTypeSchema_STD() {
         String policyType = clientUnderTest.getPolicyTypeSchema("").block();
 
-        assertEquals("{}", policyType, "");
+        assertEquals("{}", policyType);
     }
 
     @Test
@@ -164,9 +164,9 @@ class SdncOscA1ClientTest {
         String inputString = "[1, \"1\" ]";
 
         List<String> result = SdncJsonHelper.parseJsonArrayOfString(inputString).collectList().block();
-        assertEquals(2, result.size(), "");
-        assertEquals("1", result.get(0), "");
-        assertEquals("1", result.get(1), "");
+        assertEquals(2, result.size());
+        assertEquals("1", result.get(0));
+        assertEquals("1", result.get(1));
     }
 
     @Test
@@ -177,7 +177,7 @@ class SdncOscA1ClientTest {
 
         List<String> returned = clientUnderTest.getPolicyIdentities().block();
 
-        assertEquals(2, returned.size(), "");
+        assertEquals(2, returned.size());
 
         ImmutableAdapterRequest expectedParams = ImmutableAdapterRequest.builder() //
             .nearRtRicUrl(policiesUrl()) //
@@ -200,7 +200,7 @@ class SdncOscA1ClientTest {
 
         List<String> returned = clientUnderTest.getPolicyIdentities().block();
 
-        assertEquals(2, returned.size(), "");
+        assertEquals(2, returned.size());
 
         ImmutableAdapterRequest expectedParams = ImmutableAdapterRequest.builder() //
             .nearRtRicUrl(RIC_1_URL + "/a1-p/policytypes/type1/policies") //
@@ -218,7 +218,7 @@ class SdncOscA1ClientTest {
             .putPolicy(A1ClientHelper.createPolicy(RIC_1_URL, POLICY_1_ID, POLICY_JSON_VALID, POLICY_TYPE_1_ID))
             .block();
 
-        assertEquals("OK", returned, "");
+        assertEquals("OK", returned);
         final String expUrl = policiesUrl() + "/" + POLICY_1_ID;
         AdapterRequest expectedInputParams = ImmutableAdapterRequest.builder() //
             .nearRtRicUrl(expUrl) //
@@ -267,7 +267,7 @@ class SdncOscA1ClientTest {
             .deletePolicy(A1ClientHelper.createPolicy(RIC_1_URL, POLICY_1_ID, POLICY_JSON_VALID, POLICY_TYPE_1_ID))
             .block();
 
-        assertEquals("OK", returned, "");
+        assertEquals("OK", returned);
         final String expUrl = policiesUrl() + "/" + POLICY_1_ID;
         AdapterRequest expectedInputParams = ImmutableAdapterRequest.builder() //
             .nearRtRicUrl(expUrl) //
index 5c11830..6e78656 100644 (file)
@@ -145,9 +145,8 @@ class DmaapMessageConsumerTest {
 
         messageConsumerUnderTest.start().join();
 
-        assertThat(logAppender.list.toString()
-            .contains("Cannot fetch because of Error respons " + responseCode + " " + responseMessage + " from DMaaP."))
-                .isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage()).isEqualTo(
+            "Cannot fetch because of Error respons " + responseCode + " " + responseMessage + " from DMaaP.");
 
         verify(messageConsumerUnderTest).sleep(DmaapMessageConsumer.TIME_BETWEEN_DMAAP_RETRIES);
     }
index f1ae7fb..3cbe28b 100644 (file)
@@ -20,6 +20,7 @@
 
 package org.oransc.policyagent.dmaap;
 
+import static ch.qos.logback.classic.Level.WARN;
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.junit.Assert.assertFalse;
 import static org.junit.Assert.assertNotNull;
@@ -32,7 +33,6 @@ import static org.mockito.Mockito.spy;
 import static org.mockito.Mockito.verify;
 import static org.mockito.Mockito.verifyNoMoreInteractions;
 
-import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.core.read.ListAppender;
 
@@ -129,12 +129,15 @@ class DmaapMessageHandlerTest {
 
     @Test
     void unparseableMessage_thenWarning() {
-        final ListAppender<ILoggingEvent> logAppender = LoggingUtils.getLogListAppender(DmaapMessageHandler.class);
+        final ListAppender<ILoggingEvent> logAppender =
+            LoggingUtils.getLogListAppender(DmaapMessageHandler.class, WARN);
 
-        testedObject.handleDmaapMsg("bad message");
+        String msg = "bad message";
+        testedObject.handleDmaapMsg(msg);
 
-        assertThat(logAppender.list.get(0).getLevel()).isEqualTo(Level.WARN);
-        assertThat(logAppender.list.toString().contains("handleDmaapMsg failure ")).isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage()).startsWith(
+            "handleDmaapMsg failure org.oransc.policyagent.exceptions.ServiceException: Received unparsable "
+                + "message from DMAAP: \"" + msg + "\", reason: ");
     }
 
     @Test
@@ -237,7 +240,9 @@ class DmaapMessageHandlerTest {
         ArgumentCaptor<String> captor = ArgumentCaptor.forClass(String.class);
         verify(dmaapClient).send(captor.capture());
         String actualMessage = captor.getValue();
-        assertThat(actualMessage.contains(HttpStatus.BAD_REQUEST.toString())).isTrue();
+        assertThat(actualMessage.contains(HttpStatus.BAD_REQUEST.toString()))
+            .as("Message \"%s\" sent to DMaaP contains %s", actualMessage, HttpStatus.BAD_REQUEST) //
+            .isTrue();
 
         verify(dmaapClient).sendBatchWithResponse();
         verifyNoMoreInteractions(dmaapClient);
@@ -255,7 +260,9 @@ class DmaapMessageHandlerTest {
         verify(dmaapClient).send(captor.capture());
         String actualMessage = captor.getValue();
         assertThat(actualMessage
-            .contains(HttpStatus.BAD_REQUEST + "\",\"message\":\"Not implemented operation: " + badOperation)).isTrue();
+            .contains(HttpStatus.BAD_REQUEST + "\",\"message\":\"Not implemented operation: " + badOperation)) //
+                .as("Message \"%s\" sent to DMaaP contains %s", actualMessage, HttpStatus.BAD_REQUEST) //
+                .isTrue();
 
         verify(dmaapClient).sendBatchWithResponse();
         verifyNoMoreInteractions(dmaapClient);
@@ -266,11 +273,12 @@ class DmaapMessageHandlerTest {
         String message = dmaapInputMessage(Operation.PUT).toString();
         message = message.replace(",\"payload\":{\"name\":\"name\",\"schema\":\"schema\"}", "");
 
-        final ListAppender<ILoggingEvent> logAppender = LoggingUtils.getLogListAppender(DmaapMessageHandler.class);
+        final ListAppender<ILoggingEvent> logAppender =
+            LoggingUtils.getLogListAppender(DmaapMessageHandler.class, WARN);
 
         testedObject.handleDmaapMsg(message);
 
-        assertThat(logAppender.list.get(0).getLevel()).isEqualTo(Level.WARN);
-        assertThat(logAppender.list.toString().contains("Expected payload in message from DMAAP: ")).isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage())
+            .startsWith("Expected payload in message from DMAAP: ");
     }
 }
index 5d8c74c..efabba3 100644 (file)
@@ -20,9 +20,9 @@
 
 package org.oransc.policyagent.tasks;
 
+import static ch.qos.logback.classic.Level.WARN;
 import static org.assertj.core.api.Assertions.assertThat;
 
-import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.core.read.ListAppender;
 
@@ -90,14 +90,14 @@ class EnvironmentProcessorTest {
             .appName(HOSTNAME_VALUE) //
             .build();
 
-        final ListAppender<ILoggingEvent> logAppender = LoggingUtils.getLogListAppender(EnvironmentProcessor.class);
+        final ListAppender<ILoggingEvent> logAppender =
+            LoggingUtils.getLogListAppender(EnvironmentProcessor.class, WARN);
 
         StepVerifier.create(EnvironmentProcessor.readEnvironmentVariables(systemEnvironment))
             .expectNext(expectedEnvProperties).expectComplete();
 
-        assertThat(logAppender.list.get(0).getLevel()).isEqualTo(Level.WARN);
-        assertThat(logAppender.list.toString()
-            .contains("$CONSUL_PORT variable will be set to default port " + defaultConsulPort)).isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage())
+            .isEqualTo("$CONSUL_PORT variable will be set to default port " + defaultConsulPort);
     }
 
     @Test
index c7b913b..2b1d2a7 100644 (file)
@@ -23,6 +23,7 @@ package org.oransc.policyagent.tasks;
 import static ch.qos.logback.classic.Level.ERROR;
 import static ch.qos.logback.classic.Level.WARN;
 import static org.assertj.core.api.Assertions.assertThat;
+import static org.awaitility.Awaitility.await;
 import static org.mockito.ArgumentMatchers.any;
 import static org.mockito.Mockito.doNothing;
 import static org.mockito.Mockito.doReturn;
@@ -138,21 +139,22 @@ class RefreshConfigTaskTest {
 
         refreshTaskUnderTest.start();
 
-        assertThat(logAppender.list.toString().contains("Configuration refresh terminated")).isTrue();
+        assertThat(logAppender.list.get(0).getFormattedMessage()).isEqualTo("Configuration refresh terminated");
     }
 
     @Test
     void startWithStubbedRefreshReturnError_thenErrorAndTerminationLogged() {
         refreshTaskUnderTest = this.createTestObject(CONFIG_FILE_DOES_NOT_EXIST, null, null, false);
-        doReturn(Flux.error(new Exception("Error"))).when(refreshTaskUnderTest).createRefreshTask();
+        String errorMessage = "Error";
+        doReturn(Flux.error(new Exception(errorMessage))).when(refreshTaskUnderTest).createRefreshTask();
 
         final ListAppender<ILoggingEvent> logAppender = LoggingUtils.getLogListAppender(RefreshConfigTask.class, ERROR);
 
         refreshTaskUnderTest.start();
 
         ILoggingEvent event = logAppender.list.get(0);
-        assertThat(event.getLevel()).isEqualTo(ERROR);
-        assertThat(event.toString().contains("Configuration refresh terminated due to exception")).isTrue();
+        assertThat(event.getFormattedMessage())
+            .isEqualTo("Configuration refresh terminated due to exception java.lang.Exception: " + errorMessage);
     }
 
     @Test
@@ -163,7 +165,7 @@ class RefreshConfigTaskTest {
         refreshTaskUnderTest.start();
         refreshTaskUnderTest.stop();
 
-        assertThat(refreshTaskUnderTest.getRefreshTask().isDisposed()).isTrue();
+        assertThat(refreshTaskUnderTest.getRefreshTask().isDisposed()).as("Refresh task is disposed").isTrue();
     }
 
     @Test
@@ -215,7 +217,9 @@ class RefreshConfigTaskTest {
         verify(refreshTaskUnderTest).loadConfigurationFromFile();
         assertThat(appConfig.getRicConfigs().size()).isEqualTo(0);
 
-        assertThat(logAppender.list.toString().contains("Local configuration file not loaded: fileName, ")).isTrue();
+        await().until(() -> logAppender.list.size() > 0);
+        assertThat(logAppender.list.get(0).getFormattedMessage())
+            .startsWith("Local configuration file not loaded: fileName, ");
     }
 
     @Test
@@ -238,9 +242,9 @@ class RefreshConfigTaskTest {
             .thenCancel() //
             .verify();
 
-        assertThat(
-            logAppender.list.toString().contains("Could not refresh application configuration. java.io.IOException"))
-                .isTrue();
+        await().until(() -> logAppender.list.size() > 0);
+        assertThat(logAppender.list.get(0).getFormattedMessage())
+            .isEqualTo("Could not refresh application configuration. java.io.IOException");
     }
 
     @Test
@@ -316,8 +320,9 @@ class RefreshConfigTaskTest {
             .thenCancel() //
             .verify();
 
-        assertThat(logAppender.list.toString()
-            .contains("Could not parse configuration org.oransc.policyagent.exceptions.ServiceException: ")).isTrue();
+        await().until(() -> logAppender.list.size() > 0);
+        assertThat(logAppender.list.get(0).getFormattedMessage())
+            .startsWith("Could not parse configuration org.oransc.policyagent.exceptions.ServiceException: ");
     }
 
     private RicConfig getRicConfig(String name) {
index 224803d..8674d0a 100644 (file)
@@ -308,7 +308,8 @@ class RicSynchronizationTaskTest {
 
         ILoggingEvent loggingEvent = logAppender.list.get(0);
         assertThat(loggingEvent.getLevel()).isEqualTo(WARN);
-        verifyCorrectLogMessage(0, logAppender, "Service notification failed for service: " + SERVICE_1_NAME);
+        verifyCorrectLogMessage(0, logAppender,
+            "Service notification failed for service: " + SERVICE_1_NAME + ". Cause: " + originalErrorMessage);
     }
 
     private void setUpCreationOfA1Client() {
@@ -333,6 +334,6 @@ class RicSynchronizationTaskTest {
     private void verifyCorrectLogMessage(int messageIndex, ListAppender<ILoggingEvent> logAppender,
         String expectedMessage) {
         ILoggingEvent loggingEvent = logAppender.list.get(messageIndex);
-        assertThat(loggingEvent.toString().contains(expectedMessage)).isTrue();
+        assertThat(loggingEvent.getFormattedMessage()).isEqualTo(expectedMessage);
     }
 }
index 495b2a5..f1f4931 100644 (file)
@@ -136,7 +136,7 @@ class ServiceSupervisionTest {
         assertThat(loggingEvent.getLevel()).isEqualTo(WARN);
         String expectedLogMessage =
             "Could not delete policy: " + POLICY_ID + " from ric: " + RIC_NAME + ". Cause: " + originalErrorMessage;
-        assertThat(loggingEvent.toString().contains(expectedLogMessage)).isTrue();
+        assertThat(loggingEvent.getFormattedMessage()).isEqualTo(expectedLogMessage);
     }
 
     @Test