summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorSmokowski, Kevin (ks6305) <kevin.smokowski@att.com>2020-04-24 18:53:31 +0000
committerKevin Smokowski <kevin.smokowski@att.com>2020-04-27 14:59:20 +0000
commit180d84761326fae9c222211d09b4f7496a40f974 (patch)
tree70aa102670db9a5ca200f30fe2e8c1eddde7acc3
parent23e4b15ad336693da3d2536ecdd96dff037059d7 (diff)
metric logger change
fix elapsed time in metric logger Issue-ID: CCSDK-2337 Signed-off-by: Smokowski, Kevin (ks6305) <kevin.smokowski@att.com> Change-Id: I81c27bbead8614e2927aa9eddef3621559eb7cc0
-rwxr-xr-xsli/common/pom.xml11
-rwxr-xr-xsli/common/src/main/java/org/onap/ccsdk/sli/core/sli/MetricLogger.java33
-rwxr-xr-xsli/common/src/test/java/org/onap/ccsdk/sli/core/sli/TestMetricLogger.java23
3 files changed, 52 insertions, 15 deletions
diff --git a/sli/common/pom.xml b/sli/common/pom.xml
index 5fb0b5ff0..16efd0e56 100755
--- a/sli/common/pom.xml
+++ b/sli/common/pom.xml
@@ -60,6 +60,17 @@
<groupId>org.onap.logging-analytics</groupId>
<artifactId>logging-slf4j</artifactId>
</dependency>
+ <!-- log4j dependencies are needed to test MDC in junit tests -->
+ <dependency>
+ <groupId>org.apache.logging.log4j</groupId>
+ <artifactId>log4j-slf4j-impl</artifactId>
+ <scope>test</scope>
+ </dependency>
+ <dependency>
+ <groupId>org.apache.logging.log4j</groupId>
+ <artifactId>log4j-core</artifactId>
+ <scope>test</scope>
+ </dependency>
<dependency>
<groupId>com.google.code.gson</groupId>
<artifactId>gson</artifactId>
diff --git a/sli/common/src/main/java/org/onap/ccsdk/sli/core/sli/MetricLogger.java b/sli/common/src/main/java/org/onap/ccsdk/sli/core/sli/MetricLogger.java
index 518316d56..0966c0bfe 100755
--- a/sli/common/src/main/java/org/onap/ccsdk/sli/core/sli/MetricLogger.java
+++ b/sli/common/src/main/java/org/onap/ccsdk/sli/core/sli/MetricLogger.java
@@ -26,6 +26,10 @@ package org.onap.ccsdk.sli.core.sli;
import java.text.DateFormat;
import java.text.SimpleDateFormat;
+import java.time.ZoneOffset;
+import java.time.ZonedDateTime;
+import java.time.format.DateTimeFormatter;
+import java.time.temporal.ChronoUnit;
import java.util.Date;
import java.util.TimeZone;
import org.onap.logging.ref.slf4j.ONAPLogConstants;
@@ -55,6 +59,7 @@ public class MetricLogger {
}
+ @Deprecated
public static String asIso8601(Date date) {
TimeZone tz = TimeZone.getTimeZone("UTC");
DateFormat df = new SimpleDateFormat("yyy-MM-dd'T'HH:mm:ss.SS'+00:00'");
@@ -62,6 +67,7 @@ public class MetricLogger {
return df.format(date);
}
+ @Deprecated
public static String asIso8601(long tsInMillis) {
return MetricLogger.asIso8601(new Date(tsInMillis));
}
@@ -74,9 +80,10 @@ public class MetricLogger {
public void logRequest(String svcInstanceId, String targetEntity, String targetServiceName, String targetElement,
String msg) {
- long start = System.currentTimeMillis();
- MDC.put(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP, MetricLogger.asIso8601(start));
-
+ String timeNow = ZonedDateTime.now(ZoneOffset.UTC).format(DateTimeFormatter.ISO_INSTANT);
+ MDC.put(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP, timeNow);
+ MDC.put(ONAPLogConstants.MDCs.ENTRY_TIMESTAMP, timeNow);
+
if (svcInstanceId != null) {
MDC.put(ONAPLogConstants.MDCs.SERVICE_INSTANCE_ID, svcInstanceId);
}
@@ -97,9 +104,9 @@ public class MetricLogger {
METRIC.info(INVOKE, "Invoke");
}
- public void logResponse(String statusCode, String responseCode, String responseDescription) {
- long start = System.currentTimeMillis();
- MDC.put(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP, MetricLogger.asIso8601(start));
+ public void logResponse(String statusCode, String responseCode, String responseDescription) {
+ String timeNow = ZonedDateTime.now(ZoneOffset.UTC).format(DateTimeFormatter.ISO_INSTANT);
+ MDC.put(ONAPLogConstants.MDCs.INVOKE_TIMESTAMP, timeNow);
if (statusCode != null) {
MDC.put(ONAPLogConstants.MDCs.RESPONSE_STATUS_CODE, statusCode);
@@ -110,9 +117,17 @@ public class MetricLogger {
if (responseDescription != null) {
MDC.put(ONAPLogConstants.MDCs.RESPONSE_DESCRIPTION, formatString(responseDescription));
}
- long end = System.currentTimeMillis();
- MDC.put(ONAPLogConstants.MDCs.LOG_TIMESTAMP, MetricLogger.asIso8601(end));
- MDC.put(ONAPLogConstants.MDCs.ELAPSED_TIME, Long.toString(end - start));
+ ZonedDateTime endTime = ZonedDateTime.now(ZoneOffset.UTC);
+ MDC.put(ONAPLogConstants.MDCs.LOG_TIMESTAMP, endTime.format(DateTimeFormatter.ISO_INSTANT));
+ try {
+ DateTimeFormatter timeFormatter = DateTimeFormatter.ISO_ZONED_DATE_TIME;
+ ZonedDateTime entryTimestamp =
+ ZonedDateTime.parse(MDC.get(ONAPLogConstants.MDCs.ENTRY_TIMESTAMP), timeFormatter);
+ String elapedTime = Long.toString(ChronoUnit.MILLIS.between(entryTimestamp, endTime));
+ MDC.put(ONAPLogConstants.MDCs.ELAPSED_TIME,elapedTime);
+ } catch (Exception e) {
+ //pass
+ }
METRIC.info(INVOKE_RETURN, formatString(lastMsg));
resetContext();
}
diff --git a/sli/common/src/test/java/org/onap/ccsdk/sli/core/sli/TestMetricLogger.java b/sli/common/src/test/java/org/onap/ccsdk/sli/core/sli/TestMetricLogger.java
index 4b371cf8f..b5090eaa2 100755
--- a/sli/common/src/test/java/org/onap/ccsdk/sli/core/sli/TestMetricLogger.java
+++ b/sli/common/src/test/java/org/onap/ccsdk/sli/core/sli/TestMetricLogger.java
@@ -2,8 +2,12 @@ package org.onap.ccsdk.sli.core.sli;
import static org.junit.Assert.*;
import java.util.Date;
+import java.util.UUID;
+
import org.junit.Before;
import org.junit.Test;
+import org.onap.logging.ref.slf4j.ONAPLogConstants;
+import org.slf4j.MDC;
public class TestMetricLogger {
@@ -11,17 +15,24 @@ public class TestMetricLogger {
@Before
public void setUp() throws Exception {
-
logger = new MetricLogger();
- logger.resetContext();
- logger.logRequest("svcInstance1", "svcName", "svcPartner", "targetEntity", "targetServiceName", "targetVirtualEntity", "hello-world");
- logger.logResponse("200", "200", "SUCCESS");
-
+ MetricLogger.resetContext();
}
@Test
public final void testGetRequestID() {
- logger.getRequestID();
+ UUID uuid = UUID.randomUUID();
+ MDC.put(ONAPLogConstants.MDCs.REQUEST_ID, uuid.toString());
+ assertEquals(uuid.toString(),logger.getRequestID());
+ }
+
+ @Test
+ public final void elapsedTime() {
+ logger.logRequest("svcInstance1", "svcName", "svcPartner", "targetEntity", "targetServiceName", "targetVirtualEntity", "hello-world");
+ logger.logResponse("200", "200", "SUCCESS");
+ Long elapsedTime = Long.valueOf(MDC.get(ONAPLogConstants.MDCs.ELAPSED_TIME));
+ assertNotNull(elapsedTime);
+ assertTrue(elapsedTime > 1);
}
@Test