From 9c40f569b817e0886d95ad8b1ac235d8644873da Mon Sep 17 00:00:00 2001 From: olegb Date: Mon, 19 Feb 2018 16:19:17 +0200 Subject: Changed logging context API Issue-ID: SDC-772 Change-Id: I9dce63f3a1bb7df067cf06a96158afa7d799319e Signed-off-by: olegb --- .../sdc/logging/GlobalLoggingContext.java | 185 +++++++++++++++++++++ .../sdc/logging/slf4j/BaseMDCCopyingWrapper.java | 52 ++++-- .../sdc/logging/slf4j/MDCCallableWrapper.java | 3 +- .../sdc/logging/slf4j/MDCRunnableWrapper.java | 3 +- .../sdc/logging/slf4j/SLF4JLoggerWrapper.java | 60 ++++--- .../logging/slf4j/SLF4JLoggingServiceProvider.java | 46 +++-- 6 files changed, 297 insertions(+), 52 deletions(-) create mode 100644 openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/GlobalLoggingContext.java (limited to 'openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main') diff --git a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/GlobalLoggingContext.java b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/GlobalLoggingContext.java new file mode 100644 index 0000000000..95dc52c85c --- /dev/null +++ b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/GlobalLoggingContext.java @@ -0,0 +1,185 @@ +/* + * Copyright © 2016-2017 European Support Limited + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.openecomp.sdc.logging; + +import java.io.IOException; +import java.io.InputStream; +import java.io.InputStreamReader; +import java.net.InetAddress; +import java.net.UnknownHostException; +import java.nio.charset.StandardCharsets; +import java.util.Properties; +import java.util.UUID; +import java.util.concurrent.atomic.AtomicLong; +import java.util.prefs.BackingStoreException; +import java.util.prefs.Preferences; + +/** + * Collect information the is required for logging, but should not concern the business code of an application. For + * example, host name and IP address. + * + * @author evitaliy + * @since 04 Mar 2018 + */ +@SuppressWarnings({"UseOfSystemOutOrSystemErr", "CallToPrintStackTrace", "squid:S106", "squid:S1148"}) +public class GlobalLoggingContext { + + private static final String APPLICATION_ID_KEY = "ApplicationId"; + + private static final String CONFIGURATION_RESOURCE = "META-INF/logging/logger.properties"; + + @SuppressWarnings("squid:S1075") + private static final String ID_PREFERENCES_PATH = "/logging/instance/uuid"; + + private static final String APP_DISTINGUISHER_KEY = "app.distinguisher"; + + // should be cashed to avoid low-level call, but with a timeout to account for IP or FQDN changes + private static final HostAddressCache HOST_ADDRESS = new HostAddressCache(); + + private static final String DISTINGUISHER; + + private static final String APPLICATION_ID; + + private static final String INSTANCE_ID; + + static { + APPLICATION_ID = System.getProperty(APPLICATION_ID_KEY); + DISTINGUISHER = readDistinguisher(); + INSTANCE_ID = readInstanceId(); + } + + private GlobalLoggingContext() { /* prevent instantiation */ } + + public static String getApplicationId() { + return APPLICATION_ID; + } + + /** + * A distinguisher to allow separation of logs created by applications running with the same configuration, but + * different class-loaders. For instance, when multiple web application are running in the same container and their + * logger configuration is passed at the JVM level. + * + * @return application distinguisher defined in a properties file + */ + public static String getDistinguisher() { + return DISTINGUISHER; + } + + /** + * A unique ID of the logging entity. Is useful to distinguish between different nodes of the same application. It + * is assumed, that the node can be re-started, in which case the unique ID must be retained. + * + * @return unique logging entity ID + */ + public static String getInstanceId() { + return INSTANCE_ID; + } + + /** + * Local host address as returned by Java runtime. A value of host address will be cached for the interval specified + * in {@link HostAddressCache#REFRESH_TIME} + * + * @return local host address, may be null if could not be read for some reason + */ + public static InetAddress getHostAddress() { + return HOST_ADDRESS.get(); + } + + private static String readInstanceId() { + + String appId = System.getProperty(APPLICATION_ID_KEY); + String key = ID_PREFERENCES_PATH + (appId == null ? "" : "/" + appId); + + try { + + // By default, this will be ~/.java/.userPrefs/prefs.xml + final Preferences preferences = Preferences.userRoot(); + String existingId = preferences.get(key, null); + if (existingId != null) { + return existingId; + } + + String newId = UUID.randomUUID().toString(); + preferences.put(key, newId); + preferences.flush(); + return newId; + + } catch (BackingStoreException e) { + e.printStackTrace(); + // don't fail if there's a problem to use the store for some unexpected reason + return UUID.randomUUID().toString(); + } + } + + private static String readDistinguisher() { + + try { + Properties properties = loadConfiguration(); + return properties.getProperty(APP_DISTINGUISHER_KEY, ""); + } catch (IOException e) { + e.printStackTrace(); // can't write to a log + return ""; + } + } + + private static Properties loadConfiguration() throws IOException { + + Properties properties = new Properties(); + + try (InputStream is = Thread.currentThread().getContextClassLoader() + .getResourceAsStream(CONFIGURATION_RESOURCE)) { + + if (is == null) { + return properties; + } + + try (InputStreamReader reader = new InputStreamReader(is, StandardCharsets.UTF_8)) { + properties.load(reader); + return properties; + } + } + } + + private static class HostAddressCache { + + private static final long REFRESH_TIME = 60000L; + + private final AtomicLong lastUpdated = new AtomicLong(0L); + private InetAddress hostAddress; + + public InetAddress get() { + + long current = System.currentTimeMillis(); + if (current - lastUpdated.get() > REFRESH_TIME) { + + synchronized (this) { + + try { + // set now to register the attempt even if failed + lastUpdated.set(current); + hostAddress = InetAddress.getLocalHost(); + } catch (UnknownHostException e) { + e.printStackTrace(); // can't really use logging + hostAddress = null; + } + } + } + + return hostAddress; + } + } +} diff --git a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/BaseMDCCopyingWrapper.java b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/BaseMDCCopyingWrapper.java index a963542906..d667ff769c 100644 --- a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/BaseMDCCopyingWrapper.java +++ b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/BaseMDCCopyingWrapper.java @@ -16,38 +16,58 @@ package org.openecomp.sdc.logging.slf4j; -import org.slf4j.MDC; - +import java.util.EnumMap; import java.util.Map; +import org.openecomp.sdc.logging.slf4j.SLF4JLoggingServiceProvider.ContextField; +import org.slf4j.MDC; /** - * @author EVITALIY - * @since 08 Jan 18 + * Because we don't know which information should be carried over from MDC, and which shouldn't, copy just the keys that + * the logging service uses. + * + * @author evitaliy + * @since 08 Jan 2018 */ abstract class BaseMDCCopyingWrapper { - private final Map context; + private final Map context; BaseMDCCopyingWrapper() { - this.context = MDC.getCopyOfContextMap(); + this.context = fromMdc(); } - final Map replace() { - Map old = MDC.getCopyOfContextMap(); - replaceMDC(this.context); + final Map replace() { + Map old = fromMdc(); + toMdc(this.context); return old; } - final void revert(Map old) { - replaceMDC(old); + final void revert(Map old) { + toMdc(old); + } + + private Map fromMdc() { + + Map copy = new EnumMap<>(ContextField.class); + for (ContextField k : ContextField.values()) { + String v = MDC.get(k.asKey()); + if (v != null) { + copy.put(k, v); + } + } + + return copy; } - private static void replaceMDC(Map context) { + private static void toMdc(Map context) { - if (context == null) { - MDC.clear(); - } else { - MDC.setContextMap(context); + for (ContextField k : ContextField.values()) { + String v = context.get(k); + if (v != null) { + MDC.put(k.asKey(), v); + } else { + MDC.remove(k.asKey()); + } } } } diff --git a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCCallableWrapper.java b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCCallableWrapper.java index 9cb67dee4c..07d0f935f7 100644 --- a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCCallableWrapper.java +++ b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCCallableWrapper.java @@ -18,6 +18,7 @@ package org.openecomp.sdc.logging.slf4j; import java.util.Map; import java.util.concurrent.Callable; +import org.openecomp.sdc.logging.slf4j.SLF4JLoggingServiceProvider.ContextField; /** * @author EVITALIY @@ -35,7 +36,7 @@ class MDCCallableWrapper extends BaseMDCCopyingWrapper implements Callable @Override public V call() throws Exception { - Map oldContext = replace(); + Map oldContext = replace(); try { return task.call(); diff --git a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCRunnableWrapper.java b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCRunnableWrapper.java index f1a6986fec..e1b8f1e5c5 100644 --- a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCRunnableWrapper.java +++ b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/MDCRunnableWrapper.java @@ -17,6 +17,7 @@ package org.openecomp.sdc.logging.slf4j; import java.util.Map; +import org.openecomp.sdc.logging.slf4j.SLF4JLoggingServiceProvider.ContextField; /** * @author EVITALIY @@ -34,7 +35,7 @@ class MDCRunnableWrapper extends BaseMDCCopyingWrapper implements Runnable { @Override public void run() { - Map oldContext = replace(); + Map oldContext = replace(); try { task.run(); diff --git a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggerWrapper.java b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggerWrapper.java index a8ada8777f..783dac4ed4 100644 --- a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggerWrapper.java +++ b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggerWrapper.java @@ -16,6 +16,14 @@ package org.openecomp.sdc.logging.slf4j; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.AuditField.BEGIN_TIMESTAMP; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.AuditField.CLIENT_IP_ADDRESS; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.AuditField.ELAPSED_TIME; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.AuditField.END_TIMESTAMP; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.AuditField.RESPONSE_CODE; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.AuditField.RESPONSE_DESCRIPTION; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggerWrapper.AuditField.STATUS_CODE; + import java.text.Format; import java.text.SimpleDateFormat; import org.openecomp.sdc.logging.api.AuditData; @@ -24,28 +32,36 @@ import org.slf4j.LoggerFactory; import org.slf4j.MDC; /** - * @author EVITALIY + * @author evitaliy * @since 08 Jan 18 */ class SLF4JLoggerWrapper implements Logger { //The specified format presents time in UTC formatted per ISO 8601, as required by ONAP logging guidelines - private static final String DATE_TIME_PATTERN = "yyyy-MM-dd'T'HH:mm:ss.SSSXXX"; + private static final String PREFIX = ""; - static final String BEGIN_TIMESTAMP = PREFIX + "BeginTimestamp"; - static final String END_TIMESTAMP = PREFIX + "EndTimestamp"; - static final String ELAPSED_TIME = PREFIX + "ElapsedTime"; - static final String STATUS_CODE = PREFIX + "StatusCode"; - static final String RESPONSE_CODE = PREFIX + "ResponseCode"; - static final String RESPONSE_DESCRIPTION = PREFIX + "ResponseDescription"; - static final String CLIENT_IP_ADDRESS = PREFIX + "ClientIpAddress"; + enum AuditField { + + BEGIN_TIMESTAMP(PREFIX + "BeginTimestamp"), + END_TIMESTAMP(PREFIX + "EndTimestamp"), + ELAPSED_TIME(PREFIX + "ElapsedTime"), + STATUS_CODE(PREFIX + "StatusCode"), + RESPONSE_CODE(PREFIX + "ResponseCode"), + RESPONSE_DESCRIPTION(PREFIX + "ResponseDescription"), + CLIENT_IP_ADDRESS(PREFIX + "ClientIpAddress"); + + private final String key; - private static final String[] ALL_MDC_FIELDS = { - BEGIN_TIMESTAMP, END_TIMESTAMP, ELAPSED_TIME, STATUS_CODE, - RESPONSE_CODE, RESPONSE_DESCRIPTION, CLIENT_IP_ADDRESS - }; + AuditField(String key) { + this.key = key; + } + + public String asKey() { + return key; + } + } private final org.slf4j.Logger logger; @@ -110,19 +126,19 @@ class SLF4JLoggerWrapper implements Logger { } putTimes(data); - putIfNotNull(RESPONSE_CODE, data.getResponseCode()); - putIfNotNull(RESPONSE_DESCRIPTION, data.getResponseDescription()); - putIfNotNull(CLIENT_IP_ADDRESS, data.getClientIpAddress()); + putIfNotNull(RESPONSE_CODE.key, data.getResponseCode()); + putIfNotNull(RESPONSE_DESCRIPTION.key, data.getResponseDescription()); + putIfNotNull(CLIENT_IP_ADDRESS.key, data.getClientIpAddress()); if (data.getStatusCode() != null) { - MDC.put(STATUS_CODE, data.getStatusCode().name()); + MDC.put(STATUS_CODE.key, data.getStatusCode().name()); } try { logger.info(Markers.AUDIT, ""); } finally { - for (String k : ALL_MDC_FIELDS) { - MDC.remove(k); + for (AuditField f : AuditField.values()) { + MDC.remove(f.key); } } } @@ -136,9 +152,9 @@ class SLF4JLoggerWrapper implements Logger { private void putTimes(AuditData data) { // SimpleDateFormat is not thread-safe and cannot be a constant Format dateTimeFormat = new SimpleDateFormat(DATE_TIME_PATTERN); - MDC.put(BEGIN_TIMESTAMP, dateTimeFormat.format(data.getStartTime())); - MDC.put(END_TIMESTAMP, dateTimeFormat.format(data.getEndTime())); - MDC.put(ELAPSED_TIME, String.valueOf(data.getEndTime() - data.getStartTime())); + MDC.put(BEGIN_TIMESTAMP.key, dateTimeFormat.format(data.getStartTime())); + MDC.put(END_TIMESTAMP.key, dateTimeFormat.format(data.getEndTime())); + MDC.put(ELAPSED_TIME.key, String.valueOf(data.getEndTime() - data.getStartTime())); } @Override diff --git a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggingServiceProvider.java b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggingServiceProvider.java index fbda93cf61..6f69aae1b6 100644 --- a/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggingServiceProvider.java +++ b/openecomp-be/lib/openecomp-sdc-logging-lib/openecomp-sdc-logging-core/src/main/java/org/openecomp/sdc/logging/slf4j/SLF4JLoggingServiceProvider.java @@ -16,6 +16,10 @@ package org.openecomp.sdc.logging.slf4j; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggingServiceProvider.ContextField.PARTNER_NAME; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggingServiceProvider.ContextField.REQUEST_ID; +import static org.openecomp.sdc.logging.slf4j.SLF4JLoggingServiceProvider.ContextField.SERVICE_NAME; + import java.util.Objects; import java.util.concurrent.Callable; import org.openecomp.sdc.logging.api.Logger; @@ -24,11 +28,26 @@ import org.slf4j.MDC; /** * @author evitaliy - * @since 13/09/2016. + * @since 13 Sep 2016 */ public class SLF4JLoggingServiceProvider implements LoggingServiceProvider { - private static final String KEY_CANNOT_BE_NULL = "Key cannot be null"; + enum ContextField { + + REQUEST_ID("RequestId"), + SERVICE_NAME("ServiceName"), + PARTNER_NAME("PartnerName"); + + private final String key; + + ContextField(String key) { + this.key = key; + } + + String asKey() { + return key; + } + } @Override public Logger getLogger(String className) { @@ -43,26 +62,29 @@ public class SLF4JLoggingServiceProvider implements LoggingServiceProvider { } @Override - public void put(String key, String value) { - Objects.requireNonNull(key, KEY_CANNOT_BE_NULL); - MDC.put(key, value); + public void putRequestId(String requestId) { + put(REQUEST_ID.key, requestId); } @Override - public String get(String key) { - Objects.requireNonNull(key, KEY_CANNOT_BE_NULL); - return MDC.get(key); + public void putServiceName(String serviceName) { + put(SERVICE_NAME.key, serviceName); } @Override - public void remove(String key) { - Objects.requireNonNull(key, KEY_CANNOT_BE_NULL); - MDC.remove(key); + public void putPartnerName(String partnerName) { + put(PARTNER_NAME.key, partnerName); } @Override public void clear() { - MDC.clear(); + for (ContextField s : ContextField.values()) { + MDC.remove(s.key); + } + } + + private void put(String key, String value) { + MDC.put(key, Objects.requireNonNull(value, key)); } @Override -- cgit 1.2.3-korg