Merge "Change MDC datetime formatter to Zulu time"

5 files changed, 98 insertions, 23 deletions

diff --git a/reference/logging-slf4j/README.md b/reference/logging-slf4j/README.md
index 2796a21..bbad3b3 100644
--- a/reference/logging-slf4j/README.md
+++ b/reference/logging-slf4j/README.md
@@ -25,26 +25,13 @@ The adapter provides:
 Note that:
 * The adapter implementation uses static inner classes in order to fit in a single source file. This was an objective. 
 
-## WAR
-
-Building produces a simple (spring-boot](https://projects.spring.io/spring-boot/) example WAR, which can be launched from this directory with:
-
-```bash
-$ java -war target/*war
-```
-
-The example WAR in ```logging-slf4j-demo``` publishes four web services:
-1. ```services/alpha```
-2. ```services/beta```
-3. ```services/gamma```
-4. ```services/delta```
+The purpose of the WAR is to demonstrate minimalist ONAP-compliant logging for web components, but a secondary purpose is to demonstrate that the call graph can be generated for a (mostly) representative set of interacting REST services.
 
-... each of which can invoke the others.
+## Configuration
 
-The purpose of the WAR is to demonstrate minimalist ONAP-compliant logging for web components, but a secondary purpose is to demonstrate that the call graph can be generated for a (mostly) representative set of interacting REST services.
+Note that the bundled SLF4J configuration *isn't* meant to be normative. Close enough as makes no difference for
+the purposes of tests, but be aware that it might not always be up-to-date.
 
 ## Tests
 
-Tests for:
-1. Code in the (potentially) reusable ``common`` package.
-2. Validating that emitted logs can be used to generate an unambiguous call graph.
+TestNG tests for contract + output of SLF4J reference impl.
diff --git a/reference/logging-slf4j/src/main/java/org/onap/logging/ref/slf4j/ONAPLogAdapter.java b/reference/logging-slf4j/src/main/java/org/onap/logging/ref/slf4j/ONAPLogAdapter.java
index 50693cb..d26cd13 100644
--- a/reference/logging-slf4j/src/main/java/org/onap/logging/ref/slf4j/ONAPLogAdapter.java
+++ b/reference/logging-slf4j/src/main/java/org/onap/logging/ref/slf4j/ONAPLogAdapter.java
@@ -21,7 +21,9 @@
 
 package org.onap.logging.ref.slf4j;
 
-import java.time.LocalDateTime;
+import java.time.ZoneOffset;
+import java.time.ZonedDateTime;
+import java.time.format.DateTimeFormatter;
 import java.util.UUID;
 
 import javax.servlet.http.HttpServletRequest;
@@ -315,7 +317,9 @@ public class ONAPLogAdapter {
         // depending on where you need them to appear, OR extend the
         // ServiceDescriptor to add them.
 
-        MDC.put(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP, LocalDateTime.now().toString());
+        MDC.put(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP,
+                ZonedDateTime.now(ZoneOffset.UTC)
+                        .format(DateTimeFormatter.ISO_INSTANT));
         MDC.put(ONAPLogConstants.MDCs.REQUEST_ID, requestID);
         MDC.put(ONAPLogConstants.MDCs.INVOCATION_ID, invocationID);
         MDC.put(ONAPLogConstants.MDCs.PARTNER_NAME, partnerName);
diff --git a/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterOutputTest.java b/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterOutputTest.java
index bab74bb..d8c2419 100644
--- a/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterOutputTest.java
+++ b/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterOutputTest.java
@@ -28,6 +28,41 @@ import java.nio.file.Files;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.UUID;
+import static org.hamcrest.MatcherAssert.assertThat;
+import static org.hamcrest.core.Is.is;
+import static org.hamcrest.core.IsEqual.equalTo;
+import static org.hamcrest.core.IsNot.not;
+import static org.hamcrest.core.IsSame.sameInstance;
+import static org.hamcrest.core.StringContains.containsString;
+import static org.hamcrest.core.StringEndsWith.endsWith;
+import static org.hamcrest.core.Every.everyItem;
+import static org.hamcrest.core.IsInstanceOf.instanceOf;
+import static org.hamcrest.core.IsNull.notNullValue;
+import static org.hamcrest.core.IsNull.nullValue;
+import static org.hamcrest.core.StringStartsWith.startsWith;
+import static org.hamcrest.beans.HasProperty.hasProperty;
+import static org.hamcrest.number.IsCloseTo.closeTo;
+import static org.hamcrest.number.OrderingComparison.greaterThan;
+import static org.hamcrest.number.OrderingComparison.greaterThanOrEqualTo;
+import static org.hamcrest.number.OrderingComparison.lessThan;
+import static org.hamcrest.number.OrderingComparison.lessThanOrEqualTo;
+import static org.hamcrest.collection.IsArray.array;
+import static org.hamcrest.collection.IsArrayContaining.hasItemInArray;
+import static org.hamcrest.collection.IsArrayContainingInAnyOrder.arrayContainingInAnyOrder;
+import static org.hamcrest.collection.IsIn.isIn;
+import static org.hamcrest.collection.IsIn.isOneOf;
+import static org.hamcrest.collection.IsMapContaining.hasKey;
+import static org.hamcrest.collection.IsMapContaining.hasEntry;
+import static org.hamcrest.collection.IsMapContaining.hasValue;
+import static org.hamcrest.text.IsEqualIgnoringWhiteSpace.equalToIgnoringWhiteSpace;
+import static org.hamcrest.text.IsEqualIgnoringCase.equalToIgnoringCase;
+import static org.hamcrest.text.IsEmptyString.isEmptyOrNullString;
+import static org.hamcrest.text.IsEmptyString.isEmptyString;
+import static org.hamcrest.text.StringContainsInOrder.stringContainsInOrder;
+import static org.hamcrest.xml.HasXPath.hasXPath;
+
+import org.testng.Assert;
+import org.testng.annotations.Test;
 
 import javax.xml.bind.DatatypeConverter;
 
@@ -61,7 +96,7 @@ public class ONAPLogAdapterOutputTest {
     @BeforeSuite
     public static void setUp() throws Exception {
         sDir = Files.createTempDirectory(ONAPLogAdapterOutputTest.class.getName()).toFile();
-        System.getProperties().setProperty("SLF4J_OUTPUT_DIRECTORY", sDir.getAbsolutePath());
+        System.getProperties().setProperty("TESTNG_SLF4J_OUTPUT_DIRECTORY", sDir.getAbsolutePath());
         LoggerFactory.getLogger(ONAPLogAdapterOutputTest.class).info("Starting.");
     }
 
@@ -121,7 +156,9 @@ public class ONAPLogAdapterOutputTest {
         assertThat(lines.get(0), containsString("ENTRY"));
         final String [] line0 = lines.get(0).split("\t", -1);
         assertThat(line0.length, is(9));
-        DatatypeConverter.parseDateTime(line0[0]);
+        final long sanity = DatatypeConverter.parseDateTime(line0[0]).getTimeInMillis();
+        assertThat(Math.abs(System.currentTimeMillis() - sanity), lessThan(5000L));
+        assertThat(line0[0], endsWith("Z"));
         assertThat(line0[1].trim().length(), greaterThan(1));
         assertThat(line0[2], is("INFO"));
         assertThat(line0[3], is(this.getClass().getName()));
@@ -136,6 +173,7 @@ public class ONAPLogAdapterOutputTest {
         final String [] line1 = lines.get(1).split("\t", -1);
         assertThat(line1.length, is(9));
         DatatypeConverter.parseDateTime(line1[0]);
+        assertThat(line1[0], endsWith("Z"));
         assertThat(line1[1].trim().length(), greaterThan(1));
         assertThat(line1[2], is("WARN"));
         assertThat(line1[3], is(this.getClass().getName()));
@@ -150,6 +188,7 @@ public class ONAPLogAdapterOutputTest {
         final String [] line2 = lines.get(2).split("\t", -1);
         assertThat(line2.length, is(9));
         DatatypeConverter.parseDateTime(line2[0]);
+        assertThat(line2[0], endsWith("Z"));
         assertThat(line2[1].trim().length(), greaterThan(1));
         assertThat(line2[2], is("ERROR"));
         assertThat(line2[3], is(this.getClass().getName()));
diff --git a/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterTest.java b/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterTest.java
index ad22603..b14df9f 100644
--- a/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterTest.java
+++ b/reference/logging-slf4j/src/test/java/org/onap/logging/ref/slf4j/ONAPLogAdapterTest.java
@@ -25,6 +25,8 @@ import java.util.HashMap;
 import java.util.Map;
 import java.util.UUID;
 
+import javax.xml.bind.DatatypeConverter;
+
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
@@ -33,6 +35,41 @@ import org.springframework.mock.web.MockHttpServletRequest;
 import org.testng.Assert;
 import org.testng.annotations.AfterMethod;
 import org.testng.annotations.Test;
+import static org.hamcrest.MatcherAssert.assertThat;
+import static org.hamcrest.core.Is.is;
+import static org.hamcrest.core.IsEqual.equalTo;
+import static org.hamcrest.core.IsNot.not;
+import static org.hamcrest.core.IsSame.sameInstance;
+import static org.hamcrest.core.StringContains.containsString;
+import static org.hamcrest.core.StringEndsWith.endsWith;
+import static org.hamcrest.core.Every.everyItem;
+import static org.hamcrest.core.IsInstanceOf.instanceOf;
+import static org.hamcrest.core.IsNull.notNullValue;
+import static org.hamcrest.core.IsNull.nullValue;
+import static org.hamcrest.core.StringStartsWith.startsWith;
+import static org.hamcrest.beans.HasProperty.hasProperty;
+import static org.hamcrest.number.IsCloseTo.closeTo;
+import static org.hamcrest.number.OrderingComparison.greaterThan;
+import static org.hamcrest.number.OrderingComparison.greaterThanOrEqualTo;
+import static org.hamcrest.number.OrderingComparison.lessThan;
+import static org.hamcrest.number.OrderingComparison.lessThanOrEqualTo;
+import static org.hamcrest.collection.IsArray.array;
+import static org.hamcrest.collection.IsArrayContaining.hasItemInArray;
+import static org.hamcrest.collection.IsArrayContainingInAnyOrder.arrayContainingInAnyOrder;
+import static org.hamcrest.collection.IsIn.isIn;
+import static org.hamcrest.collection.IsIn.isOneOf;
+import static org.hamcrest.collection.IsMapContaining.hasKey;
+import static org.hamcrest.collection.IsMapContaining.hasEntry;
+import static org.hamcrest.collection.IsMapContaining.hasValue;
+import static org.hamcrest.text.IsEqualIgnoringWhiteSpace.equalToIgnoringWhiteSpace;
+import static org.hamcrest.text.IsEqualIgnoringCase.equalToIgnoringCase;
+import static org.hamcrest.text.IsEmptyString.isEmptyOrNullString;
+import static org.hamcrest.text.IsEmptyString.isEmptyString;
+import static org.hamcrest.text.StringContainsInOrder.stringContainsInOrder;
+import static org.hamcrest.xml.HasXPath.hasXPath;
+
+import org.testng.Assert;
+import org.testng.annotations.Test;
 
 import static org.hamcrest.MatcherAssert.assertThat;
 import static org.hamcrest.core.Is.is;
@@ -116,6 +153,14 @@ public class ONAPLogAdapterTest {
             assertThat(mdcs.get("ServiceName"), is("uri123"));
             assertThat(mdcs.get("ServerFQDN"), is("local123"));
             assertThat(mdcs.get("ClientIPAddress"), is("remote123"));
+
+            // Timestamp format and value:
+
+            final String invokeTimestampString = mdcs.get("InvokeTimestamp");
+            assertThat(invokeTimestampString, notNullValue());
+            assertThat(invokeTimestampString, endsWith("Z"));
+            final long invokeTimestamp = DatatypeConverter.parseDateTime(invokeTimestampString).getTimeInMillis();
+            assertThat(Math.abs(System.currentTimeMillis() - invokeTimestamp), lessThan(5000L));
         }
         finally {
             MDC.clear();
diff --git a/reference/logging-slf4j/src/test/resources/logback.xml b/reference/logging-slf4j/src/test/resources/logback.xml
index 554d712..ba86e54 100644
--- a/reference/logging-slf4j/src/test/resources/logback.xml
+++ b/reference/logging-slf4j/src/test/resources/logback.xml
@@ -17,7 +17,7 @@
     </appender>
 
     <appender name="FILE" class="ch.qos.logback.core.FileAppender">
-        <file>${SLF4J_OUTPUT_DIRECTORY}/output.log</file>
+        <file>${TESTNG_SLF4J_OUTPUT_DIRECTORY}/output.log</file>
         <encoder>
             <pattern>${pattern}</pattern>
         </encoder>