feat: add client side logging with slf4j

.github/workflows/ci.yaml

@@ -255,6 +255,15 @@ jobs:
             -P enable-integration-tests \
             --batch-mode \
             --no-transfer-progress
+      # The `envVarLoggingTest` profile runs tests that require an environment variable
+      - name: Showcase integration tests - Logging
+        run: |
+          mvn verify -P '!showcase,enable-integration-tests,envVarLoggingTest' \
+            --batch-mode \
+            --no-transfer-progress
+        # Set the Env Var for this step only
+        env:
+          GOOGLE_SDK_JAVA_LOGGING: true
 
   showcase-native:
     runs-on: ubuntu-22.04

gapic-generator-java-pom-parent/pom.xml

@@ -38,6 +38,7 @@
     <j2objc-annotations.version>3.0.0</j2objc-annotations.version>
     <threetenbp.version>1.7.0</threetenbp.version>
     <junit.version>5.11.3</junit.version>
+    <slf4j.version>2.0.16</slf4j.version>
   </properties>
 
   <developers>

gax-java/dependencies.properties

@@ -76,6 +76,7 @@ maven.com_google_http_client_google_http_client_gson=com.google.http-client:goog
 maven.org_codehaus_mojo_animal_sniffer_annotations=org.codehaus.mojo:animal-sniffer-annotations:1.24
 maven.javax_annotation_javax_annotation_api=javax.annotation:javax.annotation-api:1.3.2
 maven.org_graalvm_sdk=org.graalvm.sdk:graal-sdk:22.3.5
+maven_org_slf4j_slf4j_api=org.slf4j:slf4j-api:2.0.16
 
 # Testing maven artifacts
 maven.junit_junit=junit:junit:4.13.2
@@ -88,3 +89,5 @@ maven.net_bytebuddy_byte_buddy=net.bytebuddy:byte-buddy:1.15.10
 maven.org_objenesis_objenesis=org.objenesis:objenesis:2.6
 maven.org_junit_jupiter_junit_jupiter_api=org.junit.jupiter:junit-jupiter-api:5.11.3
 maven.org_junit_jupiter_junit_jupiter_params=org.junit.jupiter:junit-jupiter-params:5.11.3
+maven.ch_qos_logback_logback_classic=ch.qos.logback:logback-classic:1.3.14
+maven.ch_qos_logback_logback_core=ch.qos.logback:logback-core:1.3.14

gax-java/gax-grpc/src/main/java/com/google/api/gax/grpc/GrpcLoggingInterceptor.java

@@ -0,0 +1,197 @@
+/*
+ * Copyright 2024 Google LLC
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are
+ * met:
+ *
+ *     * Redistributions of source code must retain the above copyright
+ * notice, this list of conditions and the following disclaimer.
+ *     * Redistributions in binary form must reproduce the above
+ * copyright notice, this list of conditions and the following disclaimer
+ * in the documentation and/or other materials provided with the
+ * distribution.
+ *     * Neither the name of Google LLC nor the names of its
+ * contributors may be used to endorse or promote products derived from
+ * this software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+ * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+ * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+ * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+ * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+ * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+ * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+ * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ */
+
+package com.google.api.gax.grpc;
+
+import com.google.api.core.InternalApi;
+import com.google.api.gax.logging.LogData;
+import com.google.api.gax.logging.LoggingUtils;
+import com.google.gson.Gson;
+import com.google.gson.JsonObject;
+import io.grpc.CallOptions;
+import io.grpc.Channel;
+import io.grpc.ClientCall;
+import io.grpc.ClientInterceptor;
+import io.grpc.ForwardingClientCall;
+import io.grpc.ForwardingClientCallListener.SimpleForwardingClientCallListener;
+import io.grpc.Metadata;
+import io.grpc.MethodDescriptor;
+import io.grpc.Status;
+import java.util.Map;
+import org.slf4j.Logger;
+import org.slf4j.event.Level;
+
+@InternalApi
+public class GrpcLoggingInterceptor implements ClientInterceptor {
+
+  private static final Logger LOGGER = LoggingUtils.getLogger(GrpcLoggingInterceptor.class);
+  private static final Gson GSON = new Gson();
+
+  ClientCall.Listener<?> currentListener; // expose for test setup
+
+  @Override
+  public <ReqT, RespT> ClientCall<ReqT, RespT> interceptCall(
+      MethodDescriptor<ReqT, RespT> method, CallOptions callOptions, Channel next) {
+
+    return new ForwardingClientCall.SimpleForwardingClientCall<ReqT, RespT>(
+        next.newCall(method, callOptions)) {
+      LogData.Builder logDataBuilder = LogData.builder();
+
+      @Override
+      public void start(Listener<RespT> responseListener, Metadata headers) {
+        logRequestInfo(method, logDataBuilder, LOGGER);
+        recordRequestHeaders(headers, logDataBuilder);
+        SimpleForwardingClientCallListener<RespT> responseLoggingListener =
+            new SimpleForwardingClientCallListener<RespT>(responseListener) {
+              @Override
+              public void onHeaders(Metadata headers) {
+                recordResponseHeaders(headers, logDataBuilder);
+                super.onHeaders(headers);
+              }
+
+              @Override
+              public void onMessage(RespT message) {
+                recordResponsePayload(message, logDataBuilder);
+                super.onMessage(message);
+              }
+
+              @Override
+              public void onClose(Status status, Metadata trailers) {
+                logResponse(status, logDataBuilder, LOGGER);
+                super.onClose(status, trailers);
+              }
+            };
+        currentListener = responseLoggingListener;
+        super.start(responseLoggingListener, headers);
+      }
+
+      @Override
+      public void sendMessage(ReqT message) {
+        logRequestDetails(message, logDataBuilder);
+        super.sendMessage(message);
+      }
+    };
+  }
+
+  // Helper methods for logging
+  // some duplications with http equivalent to avoid exposing as public method for now
+  <ReqT, RespT> void logRequestInfo(
+      MethodDescriptor<ReqT, RespT> method, LogData.Builder logDataBuilder, Logger logger) {
+    try {
+      if (logger.isInfoEnabled()) {
+        logDataBuilder.serviceName(method.getServiceName()).rpcName(method.getFullMethodName());
+
+        if (!logger.isDebugEnabled()) {
+          LoggingUtils.logWithMDC(
+              logger, Level.INFO, logDataBuilder.build().toMapRequest(), "Sending gRPC request");
+        }
+      }
+    } catch (Exception e) {
+      logger.error("Error logging request info (and headers)", e);
+    }
+  }
+
+  private void recordRequestHeaders(Metadata headers, LogData.Builder logDataBuilder) {
+    try {
+      if (LOGGER.isDebugEnabled()) {
+        JsonObject requestHeaders = mapHeadersToJsonObject(headers);
+        logDataBuilder.requestHeaders(GSON.toJson(requestHeaders));
+      }
+    } catch (Exception e) {
+      LOGGER.error("Error recording request headers", e);
+    }
+  }
+
+  void recordResponseHeaders(Metadata headers, LogData.Builder logDataBuilder) {
+    try {
+      if (LOGGER.isDebugEnabled()) {
+        JsonObject responseHeaders = mapHeadersToJsonObject(headers);
+        logDataBuilder.responseHeaders(GSON.toJson(responseHeaders));
+      }
+    } catch (Exception e) {
+      LOGGER.error("Error recording response headers", e);
+    }
+  }
+
+  <RespT> void recordResponsePayload(RespT message, LogData.Builder logDataBuilder) {
+    try {
+      if (LOGGER.isDebugEnabled()) {
+        logDataBuilder.responsePayload(GSON.toJsonTree(message));
+      }
+    } catch (Exception e) {
+      LOGGER.error("Error recording response payload", e);
+    }
+  }
+
+  void logResponse(Status status, LogData.Builder logDataBuilder, Logger logger) {
+    try {
+      if (logger.isInfoEnabled()) {
+        logDataBuilder.responseStatus(status.getCode().toString());
+      }
+      if (logger.isInfoEnabled() && !logger.isDebugEnabled()) {
+        Map<String, String> responseData = logDataBuilder.build().toMapResponse();
+        LoggingUtils.logWithMDC(logger, Level.INFO, responseData, "Received Grpc response");
+      }
+      if (logger.isDebugEnabled()) {
+        Map<String, String> responsedDetailsMap = logDataBuilder.build().toMapResponse();
+        LoggingUtils.logWithMDC(logger, Level.DEBUG, responsedDetailsMap, "Received Grpc response");
+      }
+    } catch (Exception e) {
+      logger.error("Error logging request response", e);
+    }
+  }
+
+  <RespT> void logRequestDetails(RespT message, LogData.Builder logDataBuilder) {
+    try {
+      if (LOGGER.isDebugEnabled()) {
+        logDataBuilder.requestPayload(GSON.toJsonTree(message));
+        Map<String, String> requestDetailsMap = logDataBuilder.build().toMapRequest();
+        LoggingUtils.logWithMDC(
+            LOGGER, Level.DEBUG, requestDetailsMap, "Sending gRPC request: request payload");
+      }
+    } catch (Exception e) {
+      LOGGER.error("Error logging request details", e);
+    }
+  }
+
+  private static JsonObject mapHeadersToJsonObject(Metadata headers) {
+    JsonObject jsonHeaders = new JsonObject();
+    headers
+        .keys()
+        .forEach(
+            key -> {
+              Metadata.Key<String> metadataKey =
+                  Metadata.Key.of(key, Metadata.ASCII_STRING_MARSHALLER);
+              String headerValue = headers.get(metadataKey);
+              jsonHeaders.addProperty(key, headerValue);
+            });
+    return jsonHeaders;
+  }
+}

gax-java/gax-grpc/src/main/java/com/google/api/gax/grpc/InstantiatingGrpcChannelProvider.java

@@ -467,6 +467,7 @@ private ManagedChannel createSingleChannel() throws IOException {
     builder =
         builder
             .intercept(new GrpcChannelUUIDInterceptor())
+            .intercept(new GrpcLoggingInterceptor())
             .intercept(headerInterceptor)
             .intercept(metadataHandlerInterceptor)
             .userAgent(headerInterceptor.getUserAgentHeader())