From 42021b0ffd2662e50fd2f3985beb4e837c2421bc Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Wed, 24 Nov 2021 15:06:10 -0800 Subject: [PATCH 1/8] Allow global context and fill few API gaps --- .../checkstyle/checkstyle-suppressions.xml | 2 +- .../azure/core/util/logging/ClientLogger.java | 85 +++++++- .../util/logging/LoggingEventBuilder.java | 180 ++++++++++++---- .../ClientLoggerJavaDocCodeSnippets.java | 26 +++ .../core/util/logging/ClientLoggerTests.java | 197 +++++++++++++++++- 5 files changed, 439 insertions(+), 51 deletions(-) diff --git a/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml b/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml index 1bd220ae71f70..eb85c6b797aeb 100755 --- a/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml +++ b/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml @@ -243,7 +243,7 @@ the main ServiceBusClientBuilder. --> - + diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java index 0a414345f7061..7aa328bc66377 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java @@ -10,6 +10,8 @@ import org.slf4j.LoggerFactory; import org.slf4j.helpers.NOPLogger; +import java.util.Collections; +import java.util.Map; import java.util.Objects; import java.util.function.Supplier; @@ -37,10 +39,13 @@ *
  • {@link ClientLogger#verbose(String, Object...) Verbose}
    • * * + *

    The logger is capable of producing json-formatted messages enriched with key value pairs. + * Context can be provided in the constructor and populated on every message or added per each log record.

    * @see Configuration */ public class ClientLogger { private final Logger logger; + private final String globalContextSerialized; /** * Retrieves a logger for the passed class using the {@link LoggerFactory}. @@ -55,11 +60,43 @@ public ClientLogger(Class clazz) { * Retrieves a logger for the passed class name using the {@link LoggerFactory}. * * @param className Class name creating the logger. - * @throws RuntimeException it is an error. + * @throws RuntimeException in case of invalid arguments. */ public ClientLogger(String className) { + this(className, Collections.emptyMap()); + } + + /** + * Retrieves a logger for the passed class using the {@link LoggerFactory}. + * + * @param clazz Class creating the logger. + * @param context Context to be populated on every log record written with this logger. + */ + public ClientLogger(Class clazz, Map context) { + this(clazz.getName(), context); + } + + /** + * Retrieves a logger for the passed class name using the {@link LoggerFactory} with + * context that will be populated on all log records produced with this logger. + * + * + * 
    +     * ClientLogger loggerWithContext = new ClientLogger(ClientLoggerJavaDocCodeSnippets.class,
+     *     Map.of("connectionId", "95a47cf"));
+     * loggerWithContext.info("A formattable message. Hello, {}", name);
+     *
    + * + * + * @param className Class name creating the logger. + * @param context Context to be populated on every log record written with this logger. + * @throws RuntimeException in case of invalid arguments. + */ + public ClientLogger(String className, Map context) { + Objects.requireNonNull(context, "'context' cannot be null."); Logger initLogger = LoggerFactory.getLogger(className); logger = initLogger instanceof NOPLogger ? new DefaultLogger(className) : initLogger; + globalContextSerialized = LoggingEventBuilder.writeJsonFragment(context); } /** @@ -126,7 +163,11 @@ public void log(LogLevel logLevel, Supplier message, Throwable throwable */ public void verbose(String message) { if (logger.isDebugEnabled()) { - logger.debug(removeNewLinesFromLogMessage(message)); + if (globalContextSerialized.isEmpty()) { + logger.debug(removeNewLinesFromLogMessage(message)); + } else { + atVerbose().log(message); + } } } @@ -170,7 +211,11 @@ public void verbose(String format, Object... args) { */ public void info(String message) { if (logger.isInfoEnabled()) { - logger.info(removeNewLinesFromLogMessage(message)); + if (globalContextSerialized.isEmpty()) { + logger.info(removeNewLinesFromLogMessage(message)); + } else { + atInfo().log(message); + } } } @@ -215,7 +260,11 @@ public void info(String format, Object... args) { */ public void warning(String message) { if (logger.isWarnEnabled()) { - logger.warn(removeNewLinesFromLogMessage(message)); + if (globalContextSerialized.isEmpty()) { + logger.warn(removeNewLinesFromLogMessage(message)); + } else { + atWarning().log(message); + } } } @@ -264,7 +313,12 @@ public void warning(String format, Object... args) { */ public void error(String message) { if (logger.isErrorEnabled()) { - logger.error(removeNewLinesFromLogMessage(message)); + if (globalContextSerialized.isEmpty()) { + logger.error(removeNewLinesFromLogMessage(message)); + } else { + atError().log(message); + } + } } @@ -398,6 +452,13 @@ public T logThrowableAsError(T throwable) { * @param args Arguments for the message, if an exception is being logged last argument is the throwable. */ private void performLogging(LogLevel logLevel, boolean isExceptionLogging, String format, Object... args) { + + if (!globalContextSerialized.isEmpty()) { + LoggingEventBuilder.create(logger, logLevel, globalContextSerialized, true) + .log(format, args); + return; + } + // If the logging level is less granular than verbose remove the potential throwable from the args. String throwableMessage = ""; if (doesArgsHaveThrowable(args)) { @@ -454,6 +515,12 @@ private void performLogging(LogLevel logLevel, boolean isExceptionLogging, Strin * @param args Arguments for the message, if an exception is being logged last argument is the throwable. */ private void performDeferredLogging(LogLevel logLevel, Supplier messageSupplier, Throwable throwable) { + if (!globalContextSerialized.isEmpty()) { + LoggingEventBuilder.create(logger, logLevel, globalContextSerialized, canLogAtLevel(logLevel)) + .log(messageSupplier.get(), throwable); + return; + } + String message = removeNewLinesFromLogMessage(messageSupplier.get()); String throwableMessage = (throwable != null) ? throwable.getMessage() : ""; @@ -548,7 +615,7 @@ public boolean canLogAtLevel(LogLevel logLevel) { * @return instance of {@link LoggingEventBuilder} or no-op if error logging is disabled. */ public LoggingEventBuilder atError() { - return LoggingEventBuilder.create(logger, LogLevel.ERROR, canLogAtLevel(LogLevel.ERROR)); + return LoggingEventBuilder.create(logger, LogLevel.ERROR, globalContextSerialized, canLogAtLevel(LogLevel.ERROR)); } /** @@ -570,7 +637,7 @@ public LoggingEventBuilder atError() { * @return instance of {@link LoggingEventBuilder} or no-op if warn logging is disabled. */ public LoggingEventBuilder atWarning() { - return LoggingEventBuilder.create(logger, LogLevel.WARNING, canLogAtLevel(LogLevel.WARNING)); + return LoggingEventBuilder.create(logger, LogLevel.WARNING, globalContextSerialized, canLogAtLevel(LogLevel.WARNING)); } /** @@ -592,7 +659,7 @@ public LoggingEventBuilder atWarning() { * @return instance of {@link LoggingEventBuilder} or no-op if info logging is disabled. */ public LoggingEventBuilder atInfo() { - return LoggingEventBuilder.create(logger, LogLevel.INFORMATIONAL, canLogAtLevel(LogLevel.INFORMATIONAL)); + return LoggingEventBuilder.create(logger, LogLevel.INFORMATIONAL, globalContextSerialized, canLogAtLevel(LogLevel.INFORMATIONAL)); } /** @@ -613,6 +680,6 @@ public LoggingEventBuilder atInfo() { * @return instance of {@link LoggingEventBuilder} or no-op if verbose logging is disabled. */ public LoggingEventBuilder atVerbose() { - return LoggingEventBuilder.create(logger, LogLevel.VERBOSE, canLogAtLevel(LogLevel.VERBOSE)); + return LoggingEventBuilder.create(logger, LogLevel.VERBOSE, globalContextSerialized, canLogAtLevel(LogLevel.VERBOSE)); } } diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java index 9e07d1f3a99ee..305ae66c09b94 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java @@ -4,13 +4,16 @@ package com.azure.core.util.logging; import com.azure.core.annotation.Fluent; +import com.azure.core.util.CoreUtils; import com.fasterxml.jackson.core.io.JsonStringEncoder; import org.slf4j.Logger; import org.slf4j.helpers.FormattingTuple; import org.slf4j.helpers.MessageFormatter; import java.util.ArrayList; +import java.util.Collections; import java.util.List; +import java.util.Map; import java.util.Objects; import java.util.function.Supplier; @@ -38,12 +41,13 @@ @Fluent public final class LoggingEventBuilder { private static final JsonStringEncoder JSON_STRING_ENCODER = JsonStringEncoder.getInstance(); - private static final LoggingEventBuilder NOOP = new LoggingEventBuilder(null, null, false); + private static final LoggingEventBuilder NOOP = new LoggingEventBuilder(null, null, null, false); private static final String AZURE_SDK_LOG_MESSAGE_KEY = "az.sdk.message"; private final Logger logger; private final LogLevel level; private List context; + private final String globalContextCached; // use flag instead for no-op instance instead of inheritance private final boolean isEnabled; @@ -52,19 +56,20 @@ public final class LoggingEventBuilder { * Creates {@code LoggingEventBuilder} for provided level and {@link ClientLogger}. * If level is disabled, returns no-op instance. */ - static LoggingEventBuilder create(Logger logger, LogLevel level, boolean canLogAtLevel) { + static LoggingEventBuilder create(Logger logger, LogLevel level, String globalContextSerialized, boolean canLogAtLevel) { if (canLogAtLevel) { - return new LoggingEventBuilder(logger, level, true); + return new LoggingEventBuilder(logger, level, globalContextSerialized, true); } return NOOP; } - private LoggingEventBuilder(Logger logger, LogLevel level, boolean isEnabled) { + private LoggingEventBuilder(Logger logger, LogLevel level, String globalContextSerialized, boolean isEnabled) { this.logger = logger; this.level = level; this.isEnabled = isEnabled; - this.context = null; + this.context = Collections.emptyList(); + this.globalContextCached = globalContextSerialized == null ? "" : globalContextSerialized; } /** @@ -94,6 +99,36 @@ public LoggingEventBuilder addKeyValue(String key, String value) { return this; } + /** + * Adds key with Object value to the context of current log being created. + * If logging is enabled at given level, and object is not null, uses {@code value.toString()} to + * serialize object. + * + *

    Code samples

    + * + *

    Adding string value to logging event context.

    + * + * + * 
    +     * logger.atVerbose()
+     *     // equivalent to addKeyValue("key", () -> new LoggableObject("string representation").toString()
+     *     .addKeyValue("key", new LoggableObject("string representation"))
+     *     .log("Param 1: {}, Param 2: {}, Param 3: {}", "param1", "param2", "param3");
+     *
    + * + * + * @param key String key. + * @param value Object value. + * @return The updated {@code LoggingEventBuilder} object. + */ + public LoggingEventBuilder addKeyValue(String key, Object value) { + if (this.isEnabled) { + addKeyValueInternal(key, value == null ? null : value.toString()); + } + + return this; + } + /** * Adds key with boolean value to the context of current log being created. * @@ -143,7 +178,7 @@ public LoggingEventBuilder addKeyValue(String key, long value) { */ public LoggingEventBuilder addKeyValue(String key, Supplier valueSupplier) { if (this.isEnabled) { - if (this.context == null) { + if (this.context.isEmpty()) { this.context = new ArrayList<>(); } @@ -175,6 +210,19 @@ public void log(Supplier messageSupplier) { } } + /** + * Logs message annotated with context. + * + * @param messageSupplier string message supplier. + * @param throwable {@link Throwable} for the message. + */ + public void log(Supplier messageSupplier, Throwable throwable) { + if (this.isEnabled) { + String message = messageSupplier != null ? messageSupplier.get() : null; + performLogging(level, message, throwable); + } + } + /** * Logs a format-able message that uses {@code {}} as the placeholder at {@code warning} log level. * @@ -205,14 +253,30 @@ public Throwable log(Throwable throwable) { return throwable; } + /** + * Logs the {@link RuntimeException} and returns it to be thrown. + * This API covers the cases where a checked exception type needs to be thrown and logged. + * + * @param runtimeException RuntimeException to be logged and returned. + * @return The passed {@link RuntimeException}. + * @throws NullPointerException If {@code runtimeException} is {@code null}. + */ + public RuntimeException log(RuntimeException runtimeException) { + Objects.requireNonNull(runtimeException, "'runtimeException' cannot be null."); + + if (this.isEnabled) { + performLogging(level, null, runtimeException); + } + + return runtimeException; + } + private String getMessageWithContext(String message, Throwable throwable) { if (message == null) { message = ""; } - int contextSize = context == null ? 0 : context.size(); - - StringBuilder sb = new StringBuilder(20 + contextSize * 20 + message.length()); + StringBuilder sb = new StringBuilder(20 + context.size() * 20 + message.length() + globalContextCached.length()); sb.append("{\"") // message must be first for log parsing tooling to work, key also works as a // marker for Azure SDK logs so we'll write it even if there is no message @@ -227,11 +291,13 @@ private String getMessageWithContext(String message, Throwable throwable) { sb.append("\""); } - if (context != null) { - for (int i = 0; i < context.size(); i++) { - context.get(i) - .writeKeyAndValue(sb.append(",")); - } + if (!globalContextCached.isEmpty()) { + sb.append(",").append(globalContextCached); + } + + for (int i = 0; i < context.size(); i++) { + context.get(i) + .write(sb.append(",")); } sb.append("}"); @@ -239,7 +305,7 @@ private String getMessageWithContext(String message, Throwable throwable) { } private void addKeyValueInternal(String key, Object value) { - if (this.context == null) { + if (this.context.isEmpty()) { this.context = new ArrayList<>(); } @@ -294,6 +360,62 @@ void performLogging(LogLevel logLevel, String format, Object... args) { } } + /** + * Serializes passed map to string containing valid JSON fragment: + * e.g. "k1":"v1","k2":"v2", properly escaped and without trailing comma. + * + * Does not support custom or complex object serialization, uses {@code toString()} on them. + * + * @param context to serialize. + */ + static String writeJsonFragment(Map context) { + if (CoreUtils.isNullOrEmpty(context)) { + return ""; + } + + StringBuilder formatter = new StringBuilder(context.size() * 20); + for (Map.Entry pair : context.entrySet()) { + Object value = pair.getValue(); + + if (value == null + || value instanceof String + || value instanceof Boolean + || value instanceof Integer + || value instanceof Long + || value instanceof Byte) { + writeKeyAndValue(pair.getKey(), value, formatter); + } else { + writeKeyAndValue(pair.getKey(), value.toString(), formatter); + } + + formatter.append(","); + } + + // remove trailing comma just in case + return formatter.deleteCharAt(formatter.length() - 1) + .toString(); + } + + private static StringBuilder writeKeyAndValue(String key, Object value, StringBuilder formatter) { + formatter.append("\""); + JSON_STRING_ENCODER.quoteAsString(key, formatter); + formatter.append("\":"); + + if (value == null) { + return formatter.append("null"); + } + + // LoggingEventBuilder only populates primitives and Strings + if (!(value instanceof String)) { + JSON_STRING_ENCODER.quoteAsString(value.toString(), formatter); + return formatter; + } + + formatter.append("\""); + JSON_STRING_ENCODER.quoteAsString(value.toString(), formatter); + return formatter.append("\""); + } + /** * Key value pair with basic serialization capabilities. */ @@ -317,32 +439,12 @@ private static final class ContextKeyValuePair { /** * Writes "key":"value" json string to provided StringBuilder. */ - public StringBuilder writeKeyAndValue(StringBuilder formatter) { - formatter.append("\""); - JSON_STRING_ENCODER.quoteAsString(key, formatter); - formatter.append("\":"); - - String valueStr = null; - if (value != null) { - // LoggingEventBuilder only supports primitives and strings - if (!(value instanceof String)) { - JSON_STRING_ENCODER.quoteAsString(value.toString(), formatter); - return formatter; - } - - valueStr = (String) value; - } else if (valueSupplier != null) { - valueStr = valueSupplier.get(); - } - - if (valueStr == null) { - return formatter.append("null"); + public StringBuilder write(StringBuilder formatter) { + if (valueSupplier == null) { + return writeKeyAndValue(key, value, formatter); } - formatter.append("\""); - JSON_STRING_ENCODER.quoteAsString(valueStr, formatter); - - return formatter.append("\""); + return writeKeyAndValue(key, valueSupplier.get(), formatter); } } } diff --git a/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java b/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java index bc26b1ef2fb6f..578d4c06a2ce1 100644 --- a/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java +++ b/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java @@ -5,6 +5,7 @@ import java.io.File; import java.io.IOException; +import java.util.Map; /** * Code snippets for {@link ClientLogger} javadocs @@ -74,6 +75,12 @@ public void loggingSnippets() { } // END: com.azure.core.util.logging.clientlogger.error#string-object + // BEGIN: com.azure.core.util.logging.clientlogger#globalcontext + ClientLogger loggerWithContext = new ClientLogger(ClientLoggerJavaDocCodeSnippets.class, + Map.of("connectionId", "95a47cf")); + loggerWithContext.info("A formattable message. Hello, {}", name); + // END: com.azure.core.util.logging.clientlogger#globalcontext + // BEGIN: com.azure.core.util.logging.clientlogger.atInfo logger.atInfo() .addKeyValue("key", "value") @@ -109,6 +116,13 @@ public void loggingSnippets() { .addKeyValue("key3", () -> getName()) .log("A formattable message. Hello, {}", name); // END: com.azure.core.util.logging.loggingeventbuilder + + // BEGIN: com.azure.core.util.logging.clientlogger.atverbose.addKeyValue#object + logger.atVerbose() + // equivalent to addKeyValue("key", () -> new LoggableObject("string representation").toString() + .addKeyValue("key", new LoggableObject("string representation")) + .log("Param 1: {}, Param 2: {}, Param 3: {}", "param1", "param2", "param3"); + // END: com.azure.core.util.logging.clientlogger.atverbose.addKeyValue#object } /** @@ -138,4 +152,16 @@ private String getName() { private void upload(File resource) throws IOException { throw new IOException(); } + + class LoggableObject { + private final String str; + LoggableObject(String str) { + this.str = str; + } + + @Override + public String toString() { + return str; + } + } } diff --git a/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java b/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java index 377ef44267c77..7958ddb9cc5a7 100644 --- a/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java +++ b/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java @@ -27,6 +27,9 @@ import java.io.UncheckedIOException; import java.io.UnsupportedEncodingException; import java.nio.charset.StandardCharsets; +import java.util.Collections; +import java.util.LinkedHashMap; +import java.util.Map; import java.util.function.Consumer; import java.util.function.Supplier; import java.util.stream.Stream; @@ -353,6 +356,84 @@ public void logWithContext(LogLevel logLevelToConfigure) { LogLevel.WARNING); } + /** + * Tests that logging with context of string message writes + * log message and global context in correct format and depending on the level. + */ + @ParameterizedTest + @MethodSource("provideLogLevels") + public void logWithGlobalContext(LogLevel logLevelToConfigure) { + setupLogLevel(logLevelToConfigure.getLogLevel()); + + // preserve order + Map globalContext = new LinkedHashMap<>(); + globalContext.put("connectionId", "foo"); + globalContext.put("linkName", 1); + globalContext.put("anotherKey", new LoggableObject("hello world")); + + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); + logger.warning("Param 1: {}, Param 2: {}, Param 3: {}", "test1", "test2", "test3"); + + assertMessage( + "{\"az.sdk.message\":\"Param 1: test1, Param 2: test2, Param 3: test3\",\"connectionId\":\"foo\",\"linkName\":1,\"anotherKey\":\"hello world\"}", + byteArraySteamToString(logCaptureStream), + logLevelToConfigure, + LogLevel.WARNING); + } + + /** + * Tests empty global context + */ + @Test + public void logWithEmptyGlobalContext() { + setupLogLevel(LogLevel.INFORMATIONAL.getLogLevel()); + + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, Collections.emptyMap()); + logger.warning("Param 1: {}, Param 2: {}, Param 3: {}", "test1", "test2", "test3"); + + assertMessage( + "Param 1: test1, Param 2: test2, Param 3: test3", + byteArraySteamToString(logCaptureStream), + LogLevel.INFORMATIONAL, + LogLevel.WARNING); + } + + /** + * Tests null global context + */ + @Test + public void logWithNullGlobalContext() { + assertThrows(NullPointerException.class, () -> new ClientLogger(ClientLoggerTests.class, null)); + } + + /** + * Tests that logging with context of string message writes + * log message and local and globacl context in correct format and depending on the level. + */ + @ParameterizedTest + @MethodSource("provideLogLevels") + public void logWithGlobalAndLocalContext(LogLevel logLevelToConfigure) { + setupLogLevel(logLevelToConfigure.getLogLevel()); + + // preserve order + Map globalContext = new LinkedHashMap<>(); + globalContext.put("connectionId", "foo"); + globalContext.put("linkName", 1); + globalContext.put("anotherKey", new LoggableObject("hello world")); + + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); + logger.atInfo() + .addKeyValue("local", true) + .addKeyValue("connectionId", "conflict") + .log("Param 1: {}, Param 2: {}, Param 3: {}", "test1", "test2", "test3"); + + assertMessage( + "{\"az.sdk.message\":\"Param 1: test1, Param 2: test2, Param 3: test3\",\"connectionId\":\"foo\",\"linkName\":1,\"anotherKey\":\"hello world\",\"local\":true,\"connectionId\":\"conflict\"}", + byteArraySteamToString(logCaptureStream), + logLevelToConfigure, + LogLevel.INFORMATIONAL); + } + /** * Tests that contextual logging without context of string message writes * log message and context in correct format and depending on the level. @@ -417,7 +498,7 @@ public void logWithContextNullMessage() { } /** - * Tests that newline is escaped in message, keys and values. + * Tests that newline is escaped in message, keys and values. */ @Test public void logWithContextNewLineIsEscaped() { @@ -438,6 +519,29 @@ public void logWithContextNewLineIsEscaped() { LogLevel.INFORMATIONAL); } + /** + * Tests that global context is escaped + */ + @Test + public void logWithGlobalContextIsEscaped() { + setupLogLevel(LogLevel.VERBOSE.getLogLevel()); + + // preserve order + Map globalContext = new LinkedHashMap<>(); + globalContext.put("link\tName", 1); + globalContext.put("another\rKey\n", new LoggableObject("hello \"world\"\r\n")); + + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); + + logger.verbose("\"message\""); + + assertMessage( + "{\"az.sdk.message\":\"\\\"message\\\"\",\"link\\tName\":1,\"another\\rKey\\n\":\"hello \\\"world\\\"\\r\\n\"}", + byteArraySteamToString(logCaptureStream), + LogLevel.VERBOSE, + LogLevel.INFORMATIONAL); + } + /** * Tests that logging with context with null message supplier does not throw. */ @@ -481,6 +585,25 @@ public void logWithContextValueSupplier() { LogLevel.WARNING); } + /** + * Tests supplied context value. + */ + @Test + public void logWithContextObject() { + setupLogLevel(LogLevel.INFORMATIONAL.getLogLevel()); + ClientLogger logger = new ClientLogger(ClientLoggerTests.class); + + logger.atWarning() + .addKeyValue("linkName", new LoggableObject("some complex object")) + .log("test"); + + assertMessage( + "{\"az.sdk.message\":\"test\",\"linkName\":\"some complex object\"}", + byteArraySteamToString(logCaptureStream), + LogLevel.INFORMATIONAL, + LogLevel.WARNING); + } + /** * Tests message with args and context. */ @@ -531,6 +654,35 @@ public void logWithContextWithThrowableInArgs(LogLevel logLevelToConfigure) { LogLevel.WARNING); } + /** + * Tests logging with context and supplied message when args have throwable (stack trace is only logged at debug) + */ + @ParameterizedTest + @MethodSource("provideLogLevels") + public void logWithContextMessageSupplierAndThrowableInArgs(LogLevel logLevelToConfigure) { + setupLogLevel(logLevelToConfigure.getLogLevel()); + ClientLogger logger = new ClientLogger(ClientLoggerTests.class); + + String exceptionMessage = "An exception message"; + IOException ioException = createIOException(exceptionMessage); + + logger.atWarning() + .addKeyValue("connectionId", "foo") + .addKeyValue("linkName", "bar") + .log(() -> String.format("hello %s", "world"), ioException); + + String message = "{\"az.sdk.message\":\"hello world\",\"exception\":\"" + exceptionMessage + "\",\"connectionId\":\"foo\",\"linkName\":\"bar\"}"; + if (logLevelToConfigure.equals(LogLevel.VERBOSE)) { + message += System.lineSeparator() + ioException.toString() + System.lineSeparator() + "\tat " + ioException.getStackTrace()[0].toString(); + } + + assertMessage( + message, + byteArraySteamToString(logCaptureStream), + logLevelToConfigure, + LogLevel.WARNING); + } + /** * Tests json escape in keys, values, message and exception message */ @@ -568,7 +720,7 @@ public void logWithContextWithThrowableInArgsAndEscaping(LogLevel logLevelToConf */ @ParameterizedTest @MethodSource("provideLogLevels") - public void logWithContextWithThrowableInCause(LogLevel logLevelToConfigure) { + public void logWithContextRuntimeException(LogLevel logLevelToConfigure) { setupLogLevel(logLevelToConfigure.getLogLevel()); ClientLogger logger = new ClientLogger(ClientLoggerTests.class); @@ -592,6 +744,35 @@ public void logWithContextWithThrowableInCause(LogLevel logLevelToConfigure) { LogLevel.WARNING); } + /** + * Tests logging with context when cause is set + */ + @ParameterizedTest + @MethodSource("provideLogLevels") + public void logWithContextThrowable(LogLevel logLevelToConfigure) { + setupLogLevel(logLevelToConfigure.getLogLevel()); + ClientLogger logger = new ClientLogger(ClientLoggerTests.class); + + String exceptionMessage = "An exception message"; + IOException ioException = createIOException(exceptionMessage); + + assertSame(ioException, logger.atWarning() + .addKeyValue("connectionId", "foo") + .addKeyValue("linkName", "bar") + .log(ioException)); + + String message = "{\"az.sdk.message\":\"\",\"exception\":\"" + exceptionMessage + "\",\"connectionId\":\"foo\",\"linkName\":\"bar\"}"; + if (logLevelToConfigure.equals(LogLevel.VERBOSE)) { + message += System.lineSeparator() + ioException.toString() + System.lineSeparator() + "\tat " + ioException.getStackTrace()[0].toString(); + } + + assertMessage( + message, + byteArraySteamToString(logCaptureStream), + logLevelToConfigure, + LogLevel.WARNING); + } + @Test public void testIsSupplierLoggingWithException() { Supplier supplier = () -> String.format("Param 1: %s, Param 2: %s, Param 3: %s", "test1", "test2", "test3"); @@ -992,4 +1173,16 @@ private static Stream validLogLevelSupplier() { Arguments.of(null, LogLevel.NOT_SET) ); } + + class LoggableObject { + private final String str; + LoggableObject(String str) { + this.str = str; + } + + @Override + public String toString() { + return str; + } + } } From d2629ff61e47d748961cad63b7aac6dea0ddb612 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Wed, 24 Nov 2021 17:41:46 -0800 Subject: [PATCH 2/8] up --- .../src/main/resources/checkstyle/checkstyle-suppressions.xml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml b/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml index eb85c6b797aeb..1bd220ae71f70 100755 --- a/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml +++ b/eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml @@ -243,7 +243,7 @@ the main ServiceBusClientBuilder. --> - + From 4c64a3030e62e8e9efadfd6ce610219e46113ba4 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 29 Nov 2021 10:23:16 -0800 Subject: [PATCH 3/8] clean up and review comments --- sdk/core/azure-core/CHANGELOG.md | 2 + .../azure/core/util/logging/ClientLogger.java | 41 ++++++++++-------- .../util/logging/LoggingEventBuilder.java | 43 ++++++++----------- 3 files changed, 44 insertions(+), 42 deletions(-) diff --git a/sdk/core/azure-core/CHANGELOG.md b/sdk/core/azure-core/CHANGELOG.md index 87450c252b286..3f8beffbffebf 100644 --- a/sdk/core/azure-core/CHANGELOG.md +++ b/sdk/core/azure-core/CHANGELOG.md @@ -4,6 +4,8 @@ ### Features Added +- Added `ClientLogger` APIs (`atError`, `atWarning`, `atInfo`, `atVerbose`) that allow adding key-value pairs to log entries and `ClientLogger` constructor overloads that take context to apply to every log entry written with this logger instance. Logger writes entries that have context as JSON similar to `{"az.sdk.message":"on delivery","connectionId":"foo"}` + ### Breaking Changes ### Bugs Fixed diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java index 7aa328bc66377..bab80f98895fa 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java @@ -46,6 +46,7 @@ public class ClientLogger { private final Logger logger; private final String globalContextSerialized; + private final boolean hasGlobalContext; /** * Retrieves a logger for the passed class using the {@link LoggerFactory}. @@ -71,6 +72,7 @@ public ClientLogger(String className) { * * @param clazz Class creating the logger. * @param context Context to be populated on every log record written with this logger. + * Objects are serialized with {@code toString()} method. */ public ClientLogger(Class clazz, Map context) { this(clazz.getName(), context); @@ -90,6 +92,7 @@ public ClientLogger(Class clazz, Map context) { * * @param className Class name creating the logger. * @param context Context to be populated on every log record written with this logger. + * Objects are serialized with {@code toString()} method. * @throws RuntimeException in case of invalid arguments. */ public ClientLogger(String className, Map context) { @@ -97,6 +100,7 @@ public ClientLogger(String className, Map context) { Logger initLogger = LoggerFactory.getLogger(className); logger = initLogger instanceof NOPLogger ? new DefaultLogger(className) : initLogger; globalContextSerialized = LoggingEventBuilder.writeJsonFragment(context); + hasGlobalContext = !CoreUtils.isNullOrEmpty(globalContextSerialized); } /** @@ -163,10 +167,10 @@ public void log(LogLevel logLevel, Supplier message, Throwable throwable */ public void verbose(String message) { if (logger.isDebugEnabled()) { - if (globalContextSerialized.isEmpty()) { - logger.debug(removeNewLinesFromLogMessage(message)); - } else { + if (hasGlobalContext) { atVerbose().log(message); + } else { + logger.debug(removeNewLinesFromLogMessage(message)); } } } @@ -211,10 +215,10 @@ public void verbose(String format, Object... args) { */ public void info(String message) { if (logger.isInfoEnabled()) { - if (globalContextSerialized.isEmpty()) { - logger.info(removeNewLinesFromLogMessage(message)); - } else { + if (hasGlobalContext) { atInfo().log(message); + } else { + logger.info(removeNewLinesFromLogMessage(message)); } } } @@ -260,10 +264,10 @@ public void info(String format, Object... args) { */ public void warning(String message) { if (logger.isWarnEnabled()) { - if (globalContextSerialized.isEmpty()) { - logger.warn(removeNewLinesFromLogMessage(message)); - } else { + if (hasGlobalContext) { atWarning().log(message); + } else { + logger.warn(removeNewLinesFromLogMessage(message)); } } } @@ -313,12 +317,11 @@ public void warning(String format, Object... args) { */ public void error(String message) { if (logger.isErrorEnabled()) { - if (globalContextSerialized.isEmpty()) { - logger.error(removeNewLinesFromLogMessage(message)); - } else { + if (hasGlobalContext) { atError().log(message); + } else { + logger.error(removeNewLinesFromLogMessage(message)); } - } } @@ -452,8 +455,7 @@ public T logThrowableAsError(T throwable) { * @param args Arguments for the message, if an exception is being logged last argument is the throwable. */ private void performLogging(LogLevel logLevel, boolean isExceptionLogging, String format, Object... args) { - - if (!globalContextSerialized.isEmpty()) { + if (hasGlobalContext) { LoggingEventBuilder.create(logger, logLevel, globalContextSerialized, true) .log(format, args); return; @@ -509,15 +511,18 @@ private void performLogging(LogLevel logLevel, boolean isExceptionLogging, Strin } /* - * Performs deferred logging. + * Performs deferred logging. Call only if logging at this level is enable,. * * @param logLevel sets the logging level * @param args Arguments for the message, if an exception is being logged last argument is the throwable. */ private void performDeferredLogging(LogLevel logLevel, Supplier messageSupplier, Throwable throwable) { - if (!globalContextSerialized.isEmpty()) { + + if (hasGlobalContext) { + // LoggingEventBuilder writes log messages as json and performs all necessary escaping, i.e. no + // sanitization needed LoggingEventBuilder.create(logger, logLevel, globalContextSerialized, canLogAtLevel(logLevel)) - .log(messageSupplier.get(), throwable); + .log(messageSupplier, throwable); return; } diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java index 305ae66c09b94..fbfc0821e9dc8 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java @@ -48,8 +48,9 @@ public final class LoggingEventBuilder { private final LogLevel level; private List context; private final String globalContextCached; + private final boolean hasGlobalContext; - // use flag instead for no-op instance instead of inheritance + // flag for no-op instance instead of inheritance private final boolean isEnabled; /** @@ -70,6 +71,7 @@ private LoggingEventBuilder(Logger logger, LogLevel level, String globalContextS this.isEnabled = isEnabled; this.context = Collections.emptyList(); this.globalContextCached = globalContextSerialized == null ? "" : globalContextSerialized; + this.hasGlobalContext = !this.globalContextCached.isEmpty(); } /** @@ -287,11 +289,14 @@ private String getMessageWithContext(String message, Throwable throwable) { if (throwable != null) { sb.append(",\"exception\":\""); - JSON_STRING_ENCODER.quoteAsString(throwable.getMessage(), sb); + + String exceptionMessage = throwable.getMessage() == null ? "" : throwable.getMessage(); + + JSON_STRING_ENCODER.quoteAsString(exceptionMessage, sb); sb.append("\""); } - if (!globalContextCached.isEmpty()) { + if (hasGlobalContext) { sb.append(",").append(globalContextCached); } @@ -318,7 +323,7 @@ private void addKeyValueInternal(String key, Object value) { * @param format format-able message. * @param args Arguments for the message, if an exception is being logged last argument is the throwable. */ - void performLogging(LogLevel logLevel, String format, Object... args) { + private void performLogging(LogLevel logLevel, String format, Object... args) { Throwable throwable = null; if (doesArgsHaveThrowable(args)) { @@ -367,6 +372,8 @@ void performLogging(LogLevel logLevel, String format, Object... args) { * Does not support custom or complex object serialization, uses {@code toString()} on them. * * @param context to serialize. + * + * @returns Serialized JSON fragment or empty string. */ static String writeJsonFragment(Map context) { if (CoreUtils.isNullOrEmpty(context)) { @@ -375,20 +382,7 @@ static String writeJsonFragment(Map context) { StringBuilder formatter = new StringBuilder(context.size() * 20); for (Map.Entry pair : context.entrySet()) { - Object value = pair.getValue(); - - if (value == null - || value instanceof String - || value instanceof Boolean - || value instanceof Integer - || value instanceof Long - || value instanceof Byte) { - writeKeyAndValue(pair.getKey(), value, formatter); - } else { - writeKeyAndValue(pair.getKey(), value.toString(), formatter); - } - - formatter.append(","); + writeKeyAndValue(pair.getKey(), pair.getValue(), formatter).append(","); } // remove trailing comma just in case @@ -406,9 +400,12 @@ private static StringBuilder writeKeyAndValue(String key, Object value, StringBu } // LoggingEventBuilder only populates primitives and Strings - if (!(value instanceof String)) { - JSON_STRING_ENCODER.quoteAsString(value.toString(), formatter); - return formatter; + if (value instanceof Boolean + || value instanceof Integer + || value instanceof Long + || value instanceof Byte) { + JSON_STRING_ENCODER.quoteAsString(value.toString(), formatter); + return formatter; } formatter.append("\""); @@ -416,9 +413,7 @@ private static StringBuilder writeKeyAndValue(String key, Object value, StringBu return formatter.append("\""); } - /** - * Key value pair with basic serialization capabilities. - */ + private static final class ContextKeyValuePair { private final String key; private final Object value; From da358bc10813acc13ac794c39e35063ea6f29033 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 29 Nov 2021 10:34:35 -0800 Subject: [PATCH 4/8] spot bugs --- .../util/logging/LoggingEventBuilder.java | 50 +++++++++++++------ 1 file changed, 35 insertions(+), 15 deletions(-) diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java index fbfc0821e9dc8..bb28f4823f8d5 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/LoggingEventBuilder.java @@ -288,12 +288,16 @@ private String getMessageWithContext(String message, Throwable throwable) { sb.append("\""); if (throwable != null) { - sb.append(",\"exception\":\""); - - String exceptionMessage = throwable.getMessage() == null ? "" : throwable.getMessage(); - - JSON_STRING_ENCODER.quoteAsString(exceptionMessage, sb); - sb.append("\""); + sb.append(",\"exception\":"); + + String exceptionMessage = throwable.getMessage(); + if (exceptionMessage != null) { + sb.append("\""); + JSON_STRING_ENCODER.quoteAsString(exceptionMessage, sb); + sb.append("\""); + } else { + sb.append("null"); + } } if (hasGlobalContext) { @@ -369,11 +373,11 @@ private void performLogging(LogLevel logLevel, String format, Object... args) { * Serializes passed map to string containing valid JSON fragment: * e.g. "k1":"v1","k2":"v2", properly escaped and without trailing comma. * - * Does not support custom or complex object serialization, uses {@code toString()} on them. + * For complex object serialization, it calls {@code toString()} guarded with null check. * * @param context to serialize. * - * @returns Serialized JSON fragment or empty string. + * @returns Serialized JSON fragment or an empty string. */ static String writeJsonFragment(Map context) { if (CoreUtils.isNullOrEmpty(context)) { @@ -399,13 +403,9 @@ private static StringBuilder writeKeyAndValue(String key, Object value, StringBu return formatter.append("null"); } - // LoggingEventBuilder only populates primitives and Strings - if (value instanceof Boolean - || value instanceof Integer - || value instanceof Long - || value instanceof Byte) { - JSON_STRING_ENCODER.quoteAsString(value.toString(), formatter); - return formatter; + if (isPrimitive(value)) { + JSON_STRING_ENCODER.quoteAsString(value.toString(), formatter); + return formatter; } formatter.append("\""); @@ -413,6 +413,26 @@ private static StringBuilder writeKeyAndValue(String key, Object value, StringBu return formatter.append("\""); } + /** + * Returns true if the value is an instance of a primitive type and false otherwise. + */ + private static boolean isPrimitive(Object value) { + // most of the time values are strings + if (value instanceof String) { + return false; + } + + if (value instanceof Boolean + || value instanceof Integer + || value instanceof Long + || value instanceof Byte + || value instanceof Double + || value instanceof Float) { + return true; + } + + return false; + } private static final class ContextKeyValuePair { private final String key; From 8c2bac4f665ec810919823966b2d608d3355c8bd Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 29 Nov 2021 11:11:12 -0800 Subject: [PATCH 5/8] review --- .../com/azure/core/util/logging/ClientLogger.java | 5 ++--- .../azure/core/util/logging/ClientLoggerTests.java | 11 ++++++++++- 2 files changed, 12 insertions(+), 4 deletions(-) diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java index bab80f98895fa..35c69dc5a16e6 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java @@ -61,7 +61,7 @@ public ClientLogger(Class clazz) { * Retrieves a logger for the passed class name using the {@link LoggerFactory}. * * @param className Class name creating the logger. - * @throws RuntimeException in case of invalid arguments. + * @throws RuntimeException when logging configuration is invalid depending on SDL4J implementation. */ public ClientLogger(String className) { this(className, Collections.emptyMap()); @@ -93,10 +93,9 @@ public ClientLogger(Class clazz, Map context) { * @param className Class name creating the logger. * @param context Context to be populated on every log record written with this logger. * Objects are serialized with {@code toString()} method. - * @throws RuntimeException in case of invalid arguments. + * @throws RuntimeException when logging configuration is invalid depending on SDL4J implementation. */ public ClientLogger(String className, Map context) { - Objects.requireNonNull(context, "'context' cannot be null."); Logger initLogger = LoggerFactory.getLogger(className); logger = initLogger instanceof NOPLogger ? new DefaultLogger(className) : initLogger; globalContextSerialized = LoggingEventBuilder.writeJsonFragment(context); diff --git a/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java b/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java index 7958ddb9cc5a7..0c9b847a71db2 100644 --- a/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java +++ b/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java @@ -403,7 +403,16 @@ public void logWithEmptyGlobalContext() { */ @Test public void logWithNullGlobalContext() { - assertThrows(NullPointerException.class, () -> new ClientLogger(ClientLoggerTests.class, null)); + setupLogLevel(LogLevel.INFORMATIONAL.getLogLevel()); + + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, null); + logger.info("Param 1: {}, Param 2: {}, Param 3: {}", "test1", "test2", "test3"); + + assertMessage( + "Param 1: test1, Param 2: test2, Param 3: test3", + byteArraySteamToString(logCaptureStream), + LogLevel.INFORMATIONAL, + LogLevel.INFORMATIONAL); } /** From 96f555d8cc1ec6b323f59b04b30226fdcd291c4f Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 29 Nov 2021 11:15:52 -0800 Subject: [PATCH 6/8] snippets --- .../java/com/azure/core/util/logging/ClientLogger.java | 10 +++++----- .../util/logging/ClientLoggerJavaDocCodeSnippets.java | 7 +++++-- 2 files changed, 10 insertions(+), 7 deletions(-) diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java index 35c69dc5a16e6..8b059adecfb77 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java @@ -61,7 +61,7 @@ public ClientLogger(Class clazz) { * Retrieves a logger for the passed class name using the {@link LoggerFactory}. * * @param className Class name creating the logger. - * @throws RuntimeException when logging configuration is invalid depending on SDL4J implementation. + * @throws RuntimeException when logging configuration is invalid depending on SLF4J implementation. */ public ClientLogger(String className) { this(className, Collections.emptyMap()); @@ -93,7 +93,7 @@ public ClientLogger(Class clazz, Map context) { * @param className Class name creating the logger. * @param context Context to be populated on every log record written with this logger. * Objects are serialized with {@code toString()} method. - * @throws RuntimeException when logging configuration is invalid depending on SDL4J implementation. + * @throws RuntimeException when logging configuration is invalid depending on SLF4J implementation. */ public ClientLogger(String className, Map context) { Logger initLogger = LoggerFactory.getLogger(className); @@ -448,7 +448,7 @@ public T logThrowableAsError(T throwable) { } /* - * Performs the logging. + * Performs the logging. Call only if logging at this level is enabled. * * @param format format-able message. * @param args Arguments for the message, if an exception is being logged last argument is the throwable. @@ -510,7 +510,7 @@ private void performLogging(LogLevel logLevel, boolean isExceptionLogging, Strin } /* - * Performs deferred logging. Call only if logging at this level is enable,. + * Performs deferred logging. Call only if logging at this level is enabled. * * @param logLevel sets the logging level * @param args Arguments for the message, if an exception is being logged last argument is the throwable. @@ -520,7 +520,7 @@ private void performDeferredLogging(LogLevel logLevel, Supplier messageS if (hasGlobalContext) { // LoggingEventBuilder writes log messages as json and performs all necessary escaping, i.e. no // sanitization needed - LoggingEventBuilder.create(logger, logLevel, globalContextSerialized, canLogAtLevel(logLevel)) + LoggingEventBuilder.create(logger, logLevel, globalContextSerialized, true) .log(messageSupplier, throwable); return; } diff --git a/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java b/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java index 578d4c06a2ce1..fb9c8d7985e1d 100644 --- a/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java +++ b/sdk/core/azure-core/src/samples/java/com/azure/core/util/logging/ClientLoggerJavaDocCodeSnippets.java @@ -5,6 +5,7 @@ import java.io.File; import java.io.IOException; +import java.util.HashMap; import java.util.Map; /** @@ -76,8 +77,10 @@ public void loggingSnippets() { // END: com.azure.core.util.logging.clientlogger.error#string-object // BEGIN: com.azure.core.util.logging.clientlogger#globalcontext - ClientLogger loggerWithContext = new ClientLogger(ClientLoggerJavaDocCodeSnippets.class, - Map.of("connectionId", "95a47cf")); + Map context = new HashMap<>(); + context.put("connectionId", "95a47cf"); + + ClientLogger loggerWithContext = new ClientLogger(ClientLoggerJavaDocCodeSnippets.class, context); loggerWithContext.info("A formattable message. Hello, {}", name); // END: com.azure.core.util.logging.clientlogger#globalcontext From 1a6b30e13c210885fc25f9c2522503ef2af59a53 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 29 Nov 2021 12:04:54 -0800 Subject: [PATCH 7/8] a few more tests --- .../core/util/logging/ClientLoggerTests.java | 123 +++++++++++++++--- 1 file changed, 104 insertions(+), 19 deletions(-) diff --git a/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java b/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java index 0c9b847a71db2..0783728a198f1 100644 --- a/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java +++ b/sdk/core/azure-core/src/test/java/com/azure/core/util/logging/ClientLoggerTests.java @@ -51,6 +51,7 @@ public class ClientLoggerTests { private String originalLogLevel; private PrintStream originalSystemOut; private ByteArrayOutputStream logCaptureStream; + private Map globalContext; @BeforeEach public void setupLoggingConfiguration() { @@ -61,6 +62,12 @@ public void setupLoggingConfiguration() { originalSystemOut = System.out; logCaptureStream = new ByteArrayOutputStream(); System.setOut(new PrintStream(logCaptureStream)); + + // preserve order + globalContext = new LinkedHashMap<>(); + globalContext.put("connectionId", "foo"); + globalContext.put("linkName", 1); + globalContext.put("anotherKey", new LoggableObject("hello world")); } @AfterEach @@ -365,12 +372,6 @@ public void logWithContext(LogLevel logLevelToConfigure) { public void logWithGlobalContext(LogLevel logLevelToConfigure) { setupLogLevel(logLevelToConfigure.getLogLevel()); - // preserve order - Map globalContext = new LinkedHashMap<>(); - globalContext.put("connectionId", "foo"); - globalContext.put("linkName", 1); - globalContext.put("anotherKey", new LoggableObject("hello world")); - ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); logger.warning("Param 1: {}, Param 2: {}, Param 3: {}", "test1", "test2", "test3"); @@ -381,6 +382,78 @@ public void logWithGlobalContext(LogLevel logLevelToConfigure) { LogLevel.WARNING); } + /** + * Tests that logging with context of string message writes + * log message and global context in correct format at info level + */ + @Test + public void logInfoWithGlobalContext() { + setupLogLevel(LogLevel.VERBOSE.getLogLevel()); + + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); + logger.info("message"); + + assertMessage( + "{\"az.sdk.message\":\"message\",\"connectionId\":\"foo\",\"linkName\":1,\"anotherKey\":\"hello world\"}", + byteArraySteamToString(logCaptureStream), + LogLevel.VERBOSE, + LogLevel.VERBOSE); + } + + /** + * Tests that logging with context of string message writes + * log message and global context in correct format at verbose level + */ + @Test + public void logVerboseWithGlobalContext() { + setupLogLevel(LogLevel.VERBOSE.getLogLevel()); + + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); + logger.verbose("message"); + + assertMessage( + "{\"az.sdk.message\":\"message\",\"connectionId\":\"foo\",\"linkName\":1,\"anotherKey\":\"hello world\"}", + byteArraySteamToString(logCaptureStream), + LogLevel.VERBOSE, + LogLevel.INFORMATIONAL); + } + + /** + * Tests that logging with context of string message writes + * log message and global context in correct format at warning level + */ + @Test + public void logWarningWithGlobalContext() { + setupLogLevel(LogLevel.VERBOSE.getLogLevel()); + + new ClientLogger(ClientLoggerTests.class, globalContext) + .warning("message"); + + assertMessage( + "{\"az.sdk.message\":\"message\",\"connectionId\":\"foo\",\"linkName\":1,\"anotherKey\":\"hello world\"}", + byteArraySteamToString(logCaptureStream), + LogLevel.VERBOSE, + LogLevel.WARNING); + } + + /** + * Tests that logging with context of string message writes + * log message and global context in correct format at error level + */ + @Test + public void logErrorWithGlobalContext() { + setupLogLevel(LogLevel.VERBOSE.getLogLevel()); + + new ClientLogger(ClientLoggerTests.class, globalContext) + .error("message"); + + assertMessage( + "{\"az.sdk.message\":\"message\",\"connectionId\":\"foo\",\"linkName\":1,\"anotherKey\":\"hello world\"}", + byteArraySteamToString(logCaptureStream), + LogLevel.VERBOSE, + LogLevel.ERROR); + } + /** * Tests empty global context */ @@ -424,12 +497,6 @@ public void logWithNullGlobalContext() { public void logWithGlobalAndLocalContext(LogLevel logLevelToConfigure) { setupLogLevel(logLevelToConfigure.getLogLevel()); - // preserve order - Map globalContext = new LinkedHashMap<>(); - globalContext.put("connectionId", "foo"); - globalContext.put("linkName", 1); - globalContext.put("anotherKey", new LoggableObject("hello world")); - ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); logger.atInfo() .addKeyValue("local", true) @@ -453,9 +520,7 @@ public void contextualLogWithoutContext(LogLevel logLevelToConfigure) { setupLogLevel(logLevelToConfigure.getLogLevel()); ClientLogger logger = new ClientLogger(ClientLoggerTests.class); - String message = String.format("Param 1: %s, Param 2: %s, Param 3: %s", "test1", "test2", "test3"); - - logger.atWarning().log(message); + logger.atWarning().log(String.format("Param 1: %s, Param 2: %s, Param 3: %s", "test1", "test2", "test3")); assertMessage( "{\"az.sdk.message\":\"Param 1: test1, Param 2: test2, Param 3: test3\"}", @@ -463,6 +528,26 @@ public void contextualLogWithoutContext(LogLevel logLevelToConfigure) { logLevelToConfigure, LogLevel.WARNING); } + + + /** + * Tests message supplier with local and global context. + */ + @ParameterizedTest + @MethodSource("provideLogLevels") + public void logWithGlobalContextMessageSupplier(LogLevel logLevelToConfigure) { + setupLogLevel(logLevelToConfigure.getLogLevel()); + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); + + logger.log(LogLevel.INFORMATIONAL, () -> String.format("Param 1: %s, Param 2: %s, Param 3: %s", "test1", "test2", "test3")); + + assertMessage( + "{\"az.sdk.message\":\"Param 1: test1, Param 2: test2, Param 3: test3\",\"connectionId\":\"foo\",\"linkName\":1,\"anotherKey\":\"hello world\"}", + byteArraySteamToString(logCaptureStream), + logLevelToConfigure, + LogLevel.INFORMATIONAL); + } + /** * Tests message supplier with context. */ @@ -536,11 +621,11 @@ public void logWithGlobalContextIsEscaped() { setupLogLevel(LogLevel.VERBOSE.getLogLevel()); // preserve order - Map globalContext = new LinkedHashMap<>(); - globalContext.put("link\tName", 1); - globalContext.put("another\rKey\n", new LoggableObject("hello \"world\"\r\n")); + Map globalCtx = new LinkedHashMap<>(); + globalCtx.put("link\tName", 1); + globalCtx.put("another\rKey\n", new LoggableObject("hello \"world\"\r\n")); - ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalContext); + ClientLogger logger = new ClientLogger(ClientLoggerTests.class, globalCtx); logger.verbose("\"message\""); From 85414e5918b7164aff2f3558aa3aa51f07fc3c20 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 29 Nov 2021 12:26:03 -0800 Subject: [PATCH 8/8] a few more tests --- .../main/java/com/azure/core/util/logging/ClientLogger.java | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java index 8b059adecfb77..3d39b40821ca5 100644 --- a/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java +++ b/sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java @@ -84,8 +84,10 @@ public ClientLogger(Class clazz, Map context) { * * * 
    -     * ClientLogger loggerWithContext = new ClientLogger(ClientLoggerJavaDocCodeSnippets.class,
-     *     Map.of("connectionId", "95a47cf"));
+     * Map<String, Object> context = new HashMap<>();
+     * context.put("connectionId", "95a47cf");
+     *
+     * ClientLogger loggerWithContext = new ClientLogger(ClientLoggerJavaDocCodeSnippets.class, context);
      * loggerWithContext.info("A formattable message. Hello, {}", name);
      *
    *