Skip to content

Commit

Permalink
Structured logging with ClientLogger (#25247)
Browse files Browse the repository at this point in the history
* Structured logging implementation
  • Loading branch information
lmolkova authored Nov 25, 2021
1 parent 91990c9 commit 56e6410
Show file tree
Hide file tree
Showing 8 changed files with 853 additions and 25 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -242,7 +242,8 @@ the main ServiceBusClientBuilder. -->
<!-- Logger class suppression -->
<suppress checks="com.azure.tools.checkstyle.checks.GoodLoggingCheck" files="ClientLogger.java"/>
<suppress checks="com.azure.tools.checkstyle.checks.GoodLoggingCheck" files="DefaultLogger.java"/>

<suppress checks="com.azure.tools.checkstyle.checks.GoodLoggingCheck" files="LoggingEventBuilder.java"/>

<!-- Requires static access to logger to report errors while loading i18n messages (from within a static initializer )-->
<suppress checks="com.azure.tools.checkstyle.checks.GoodLoggingCheck" files="Messages.java"/>

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2404,6 +2404,10 @@
<Class name="com.azure.core.util.logging.ClientLogger"/>
<Bug pattern="CRLF_INJECTION_LOGS"/>
</Match>
<Match>
<Class name="com.azure.core.util.logging.LoggingEventBuilder"/>
<Bug pattern="CRLF_INJECTION_LOGS"/>
</Match>

<!-- The predictable randomness doesn't expose any crucial detail in this case. -->
<Match>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,13 +5,15 @@

import com.azure.core.util.CoreUtils;

import java.util.Arrays;

/**
* Contains utility methods for logging.
*/
public final class LoggingUtils {
private static final char CR = '\r';
private static final char LF = '\n';

private LoggingUtils() {
}

Expand Down Expand Up @@ -48,4 +50,29 @@ public static String removeNewLinesFromLogMessage(String logMessage) {
sb.append(logMessage, prevStart, logMessage.length());
return sb.toString();
}

/*
* Determines if the arguments contains a throwable that would be logged, SLF4J logs a throwable if it is the last
* element in the argument list.
*
* @param args The arguments passed to format the log message.
* @return True if the last element is a throwable, false otherwise.
*/
public static boolean doesArgsHaveThrowable(Object... args) {
if (args.length == 0) {
return false;
}

return args[args.length - 1] instanceof Throwable;
}

/*
* Removes the last element from the arguments as it is a throwable.
*
* @param args The arguments passed to format the log message.
* @return The arguments with the last element removed.
*/
public static Object[] removeThrowable(Object... args) {
return Arrays.copyOf(args, args.length - 1);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -10,12 +10,14 @@
import org.slf4j.LoggerFactory;
import org.slf4j.helpers.NOPLogger;

import java.util.Arrays;
import java.util.Objects;
import java.util.function.Supplier;

import static com.azure.core.implementation.logging.LoggingUtils.removeNewLinesFromLogMessage;

import static com.azure.core.implementation.logging.LoggingUtils.doesArgsHaveThrowable;
import static com.azure.core.implementation.logging.LoggingUtils.removeThrowable;

/**
* This is a fluent logger helper class that wraps a pluggable {@link Logger}.
*
Expand Down Expand Up @@ -345,11 +347,10 @@ public <T extends Throwable> T logThowableAsWarning(T throwable) {
*/
public <T extends Throwable> T logThrowableAsWarning(T throwable) {
Objects.requireNonNull(throwable, "'throwable' cannot be null.");
if (!logger.isWarnEnabled()) {
return throwable;
if (logger.isWarnEnabled()) {
performLogging(LogLevel.WARNING, true, throwable.getMessage(), throwable);
}

performLogging(LogLevel.WARNING, true, throwable.getMessage(), throwable);
return throwable;
}

Expand Down Expand Up @@ -453,9 +454,9 @@ 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<String> messageSupplier, Throwable throwable) {
String message = removeNewLinesFromLogMessage(messageSupplier.get());
String throwableMessage = (throwable != null) ? throwable.getMessage() : "";
String message = messageSupplier.get();
message = removeNewLinesFromLogMessage(message);

switch (logLevel) {
case VERBOSE:
if (throwable != null) {
Expand Down Expand Up @@ -489,7 +490,6 @@ private void performDeferredLogging(LogLevel logLevel, Supplier<String> messageS
* @param args The arguments passed to evaluate suppliers in args.
* @return Return the argument with evaluated supplier
*/

Object[] evaluateSupplierArgument(Object[] args) {
if (isSupplierLogging(args)) {
args[0] = ((Supplier<?>) args[0]).get();
Expand Down Expand Up @@ -530,28 +530,89 @@ public boolean canLogAtLevel(LogLevel logLevel) {
}
}

/*
* Determines if the arguments contains a throwable that would be logged, SLF4J logs a throwable if it is the last
* element in the argument list.
/**
* Creates {@link LoggingEventBuilder} for {@code error} log level that can be
* used to enrich log with additional context.
* <p><strong>Code samples</strong></p>
*
* <p>Logging with context at error level.</p>
*
* @param args The arguments passed to format the log message.
* @return True if the last element is a throwable, false otherwise.
* <!-- src_embed com.azure.core.util.logging.clientlogger.atverbose.addKeyValue#primitive -->
* <pre>
* logger.atVerbose&#40;&#41;
* .addKeyValue&#40;&quot;key&quot;, 1L&#41;
* .log&#40;&#40;&#41; -&gt; String.format&#40;&quot;Param 1: %s, Param 2: %s, Param 3: %s&quot;, &quot;param1&quot;, &quot;param2&quot;, &quot;param3&quot;&#41;&#41;;
* </pre>
* <!-- end com.azure.core.util.logging.clientlogger.atverbose.addKeyValue#primitive -->
*
* @return instance of {@link LoggingEventBuilder} or no-op if error logging is disabled.
*/
private boolean doesArgsHaveThrowable(Object... args) {
if (args.length == 0) {
return false;
}
public LoggingEventBuilder atError() {
return LoggingEventBuilder.create(logger, LogLevel.ERROR, canLogAtLevel(LogLevel.ERROR));
}

/**
* Creates {@link LoggingEventBuilder} for {@code warning} log level that can be
* used to enrich log with additional context.
* <p><strong>Code samples</strong></p>
*
* <p>Logging with context at warning level.</p>
*
* <!-- src_embed com.azure.core.util.logging.clientlogger.atWarning -->
* <pre>
* logger.atWarning&#40;&#41;
* .addKeyValue&#40;&quot;key&quot;, &quot;value&quot;&#41;
* .log&#40;&quot;A formattable message. Hello, &#123;&#125;&quot;, name, exception&#41;;
* </pre>
* <!-- end com.azure.core.util.logging.clientlogger.atWarning -->
*
* @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 args[args.length - 1] instanceof Throwable;
/**
* Creates {@link LoggingEventBuilder} for {@code info} log level that can be
* used to enrich log with additional context.
*
* <p><strong>Code samples</strong></p>
*
* <p>Logging with context at info level.</p>
*
* <!-- src_embed com.azure.core.util.logging.clientlogger.atInfo -->
* <pre>
* logger.atInfo&#40;&#41;
* .addKeyValue&#40;&quot;key&quot;, &quot;value&quot;&#41;
* .log&#40;&quot;A formattable message. Hello, &#123;&#125;&quot;, name&#41;;
* </pre>
* <!-- end com.azure.core.util.logging.clientlogger.atInfo -->
*
* @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));
}

/*
* Removes the last element from the arguments as it is a throwable.
/**
* Creates {@link LoggingEventBuilder} for {@code verbose} log level that can be
* used to enrich log with additional context.
* <p><strong>Code samples</strong></p>
*
* <p>Logging with context at verbose level.</p>
*
* <!-- src_embed com.azure.core.util.logging.clientlogger.atverbose.addKeyValue#primitive -->
* <pre>
* logger.atVerbose&#40;&#41;
* .addKeyValue&#40;&quot;key&quot;, 1L&#41;
* .log&#40;&#40;&#41; -&gt; String.format&#40;&quot;Param 1: %s, Param 2: %s, Param 3: %s&quot;, &quot;param1&quot;, &quot;param2&quot;, &quot;param3&quot;&#41;&#41;;
* </pre>
* <!-- end com.azure.core.util.logging.clientlogger.atverbose.addKeyValue#primitive -->
*
* @param args The arguments passed to format the log message.
* @return The arguments with the last element removed.
* @return instance of {@link LoggingEventBuilder} or no-op if verbose logging is disabled.
*/
private Object[] removeThrowable(Object... args) {
return Arrays.copyOf(args, args.length - 1);
public LoggingEventBuilder atVerbose() {
return LoggingEventBuilder.create(logger, LogLevel.VERBOSE, canLogAtLevel(LogLevel.VERBOSE));
}
}
Loading

0 comments on commit 56e6410

Please sign in to comment.