Structured logging with ClientLogger (Azure#25247)

* Structured logging implementation

Author: Liudmila Molkova

eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml

@@ -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"/>
 

eng/code-quality-reports/src/main/resources/spotbugs/spotbugs-exclude.xml

@@ -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>

sdk/core/azure-core/src/main/java/com/azure/core/implementation/logging/LoggingUtils.java

@@ -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() {
     }
 
@@ -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);
+    }
 }

sdk/core/azure-core/src/main/java/com/azure/core/util/logging/ClientLogger.java

@@ -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}.
  *
@@ -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;
     }
 
@@ -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) {
@@ -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();
@@ -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));
     }
 }