Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Structured logging with ClientLogger #25247

Merged
merged 16 commits into from
Nov 25, 2021
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