Skip to content

Commit

Permalink
feat: add client side logging with slf4j (#3403)
Browse files Browse the repository at this point in the history
Changes to introduce client logging debug feature to Gax. Guide on usage
will be added separately to README file.

- Brings in `slf4j-api` as optional dependency to gax-java
- `LoggingUtils`, `LogData` and `LoggerProvider` are public because
access are needed from gax-grpc and gax-httpjson packages
- `LoggingUtils` handles logic to enable/disable from env var, and
contains shared utility methods for record data for logging and record
logs (abstracting away any need for SLF4J classes).
  - `Slf4jUtils` any logic interacting with SLF4J classes.
- `LoggerProvider` provides the SLF4J Logger. This is so that Logger
interceptor classes do not declare Logger directly.
- This feature is guarded by env var GOOGLE_SDK_JAVA_LOGGING, only
turned on if true.
- By default it is off, user app should act as before (usual tests
behaves as usual)

__Tests added:__
- Unit tests in Gax that need either GOOGLE_SDK_JAVA_LOGGING unset, or
do not depend on env var
- LoggingEnabledTest: test for logger correctly setups when
GOOGLE_SDK_JAVA_LOGGING = true. This is added to existing `envVarTest`
profile
- Showcase tests:
- ITLoggingDisabled: test no logging event should record when env var is
turned off.
  - ITLogging: test logging event with slf4j2.x+logback
  - ITLogging1x: test logging event with slf4j1.x+logback
These tests may not compile depending on the logging dependency brought
in. Set up profiles to control test compile and run:
- Slf4j2_logback, slf4j1_logback, disabledLogging: brings in logging
dependencies and setup compile config exclusions
- Do not include `it/logging` folder for compile by default, or
`enable-golden-tests`. `native` is also excluded for now.

__Notable changes since last reviewed:__
- Changes related to get slf4j-api deps as optional
- Logics to switch logging behavior based on slf4j major version
- Moved helper methods into Gax
- Revamped test setup
- use Protobuf utils to serialize message

__Context:__
[go/java-client-logging-design](http://goto.google.com/java-client-logging-design)

TODO:
- add rules for renovate bot to bypass some versions for testing
  • Loading branch information
zhumin8 authored Feb 24, 2025
1 parent ad26cf9 commit fe002fa
Show file tree
Hide file tree
Showing 36 changed files with 3,090 additions and 9 deletions.
31 changes: 31 additions & 0 deletions .github/workflows/ci.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ jobs:
env:
GOOGLE_CLOUD_UNIVERSE_DOMAIN: random.com
GOOGLE_CLOUD_ENABLE_DIRECT_PATH_XDS: true
GOOGLE_SDK_JAVA_LOGGING: true
- run: bazelisk version
- name: Install Maven modules
run: |
Expand Down Expand Up @@ -82,6 +83,7 @@ jobs:
env:
GOOGLE_CLOUD_UNIVERSE_DOMAIN: random.com
GOOGLE_CLOUD_ENABLE_DIRECT_PATH_XDS: true
GOOGLE_SDK_JAVA_LOGGING: true
- run: bazelisk version
- name: Install Maven modules
run: |
Expand Down Expand Up @@ -133,6 +135,7 @@ jobs:
env:
GOOGLE_CLOUD_UNIVERSE_DOMAIN: random.com
GOOGLE_CLOUD_ENABLE_DIRECT_PATH_XDS: true
GOOGLE_SDK_JAVA_LOGGING: true

build-java8-gapic-generator-java:
name: "build(8) for gapic-generator-java"
Expand Down Expand Up @@ -255,6 +258,34 @@ jobs:
-P enable-integration-tests \
--batch-mode \
--no-transfer-progress
# The `slf4j2_logback` profile brings logging dependency and compiles logging tests, require env var to be set
- name: Showcase integration tests - Logging SLF4J 2.x
working-directory: showcase
run: |
mvn clean verify -P '!showcase,enable-integration-tests,loggingTestBase,slf4j2_logback' \
--batch-mode \
--no-transfer-progress
# Set the Env Var for this step only
env:
GOOGLE_SDK_JAVA_LOGGING: true
# The `slf4j1_logback` profile brings logging dependency and compiles logging tests, require env var to be set
- name: Showcase integration tests - Logging SLF4J 1.x
working-directory: showcase
run: |
mvn clean verify -P '!showcase,enable-integration-tests,loggingTestBase,slf4j1_logback' \
--batch-mode \
--no-transfer-progress
# Set the Env Var for this step only
env:
GOOGLE_SDK_JAVA_LOGGING: true
# The `disabledLogging` profile tests logging disabled when logging dependency present,
# do not set env var for this step
- name: Showcase integration tests - Logging disabed
working-directory: showcase
run: |
mvn clean verify -P '!showcase,enable-integration-tests,loggingTestBase,disabledLogging' \
--batch-mode \
--no-transfer-progress
showcase-clirr:
if: ${{ github.base_ref != '' }} # Only execute on pull_request trigger event
Expand Down
1 change: 1 addition & 0 deletions gapic-generator-java-pom-parent/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@
<j2objc-annotations.version>3.0.0</j2objc-annotations.version>
<threetenbp.version>1.7.0</threetenbp.version>
<junit.version>5.11.4</junit.version>
<slf4j.version>2.0.16</slf4j.version>
</properties>

<developers>
Expand Down
2 changes: 2 additions & 0 deletions gax-java/dependencies.properties
Original file line number Diff line number Diff line change
Expand Up @@ -76,6 +76,8 @@ 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:nativeimage:24.1.2
maven.org_slf4j_slf4j_api=org.slf4j:slf4j-api:2.0.16
maven.com_google_protobuf_protobuf_java_util=com.google.protobuf:protobuf-java-util:3.25.5

# Testing maven artifacts
maven.junit_junit=junit:junit:4.13.2
Expand Down
6 changes: 6 additions & 0 deletions gax-java/gax-grpc/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -92,6 +92,12 @@
<artifactId>auto-value-annotations</artifactId>
<scope>provided</scope>
</dependency>
<!-- Logging dependency -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<optional>true</optional>
</dependency>

<!-- test dependencies -->
<dependency>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,136 @@
/*
* Copyright 2025 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 static com.google.api.gax.logging.LoggingUtils.executeWithTryCatch;
import static com.google.api.gax.logging.LoggingUtils.logRequest;
import static com.google.api.gax.logging.LoggingUtils.logResponse;
import static com.google.api.gax.logging.LoggingUtils.recordResponseHeaders;
import static com.google.api.gax.logging.LoggingUtils.recordResponsePayload;
import static com.google.api.gax.logging.LoggingUtils.recordServiceRpcAndRequestHeaders;

import com.google.api.core.InternalApi;
import com.google.api.gax.logging.LogData;
import com.google.api.gax.logging.LoggerProvider;
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.HashMap;
import java.util.Map;

@InternalApi
public class GrpcLoggingInterceptor implements ClientInterceptor {

private static final LoggerProvider LOGGER_PROVIDER =
LoggerProvider.forClazz(GrpcLoggingInterceptor.class);

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) {
recordServiceRpcAndRequestHeaders(
method.getServiceName(),
method.getFullMethodName(),
null, // endpoint is for http request only
metadataHeadersToMap(headers),
logDataBuilder,
LOGGER_PROVIDER);
SimpleForwardingClientCallListener<RespT> responseLoggingListener =
new SimpleForwardingClientCallListener<RespT>(responseListener) {
@Override
public void onHeaders(Metadata headers) {
recordResponseHeaders(
metadataHeadersToMap(headers), logDataBuilder, LOGGER_PROVIDER);
super.onHeaders(headers);
}

@Override
public void onMessage(RespT message) {
recordResponsePayload(message, logDataBuilder, LOGGER_PROVIDER);
super.onMessage(message);
}

@Override
public void onClose(Status status, Metadata trailers) {
logResponse(status.getCode().toString(), logDataBuilder, LOGGER_PROVIDER);
super.onClose(status, trailers);
}
};
currentListener = responseLoggingListener;
super.start(responseLoggingListener, headers);
}

@Override
public void sendMessage(ReqT message) {
logRequest(message, logDataBuilder, LOGGER_PROVIDER);
super.sendMessage(message);
}
};
}

// Helper methods for logging
private static Map<String, String> metadataHeadersToMap(Metadata headers) {

Map<String, String> headersMap = new HashMap<>();
executeWithTryCatch(
() -> {
for (String key : headers.keys()) {
// grpc header values can be either ASCII strings or binary
// https://grpc.io/docs/guides/metadata/#overview
// this condition identified binary headers and skip for logging
if (key.endsWith(Metadata.BINARY_HEADER_SUFFIX)) {
continue;
}
Metadata.Key<String> metadataKey =
Metadata.Key.of(key, Metadata.ASCII_STRING_MARSHALLER);
String headerValue = headers.get(metadataKey);

headersMap.put(key, headerValue);
}
});

return headersMap;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -681,6 +681,7 @@ private ManagedChannel createSingleChannel() throws IOException {
builder =
builder
.intercept(new GrpcChannelUUIDInterceptor())
.intercept(new GrpcLoggingInterceptor())
.intercept(headerInterceptor)
.intercept(metadataHandlerInterceptor)
.userAgent(headerInterceptor.getUserAgentHeader())
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,104 @@
/*
* Copyright 2025 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 static org.mockito.ArgumentMatchers.any;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.spy;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;

import com.google.api.gax.grpc.testing.FakeMethodDescriptor;
import io.grpc.CallOptions;
import io.grpc.Channel;
import io.grpc.ClientCall;
import io.grpc.ClientInterceptors;
import io.grpc.Metadata;
import io.grpc.MethodDescriptor;
import io.grpc.Status;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.ExtendWith;
import org.mockito.Mock;
import org.mockito.Mockito;
import org.mockito.junit.jupiter.MockitoExtension;

@ExtendWith(MockitoExtension.class)
class GrpcLoggingInterceptorTest {
@Mock private Channel channel;

@Mock private ClientCall<String, Integer> call;

private static final MethodDescriptor<String, Integer> method = FakeMethodDescriptor.create();

@Test
void testInterceptor_basic() {
when(channel.newCall(Mockito.<MethodDescriptor<String, Integer>>any(), any(CallOptions.class)))
.thenReturn(call);
GrpcLoggingInterceptor interceptor = new GrpcLoggingInterceptor();
Channel intercepted = ClientInterceptors.intercept(channel, interceptor);
@SuppressWarnings("unchecked")
ClientCall.Listener<Integer> listener = mock(ClientCall.Listener.class);
ClientCall<String, Integer> interceptedCall = intercepted.newCall(method, CallOptions.DEFAULT);
// Simulate starting the call
interceptedCall.start(listener, new Metadata());
// Verify that the underlying call's start() method is invoked
verify(call).start(any(ClientCall.Listener.class), any(Metadata.class));

// Simulate sending a message
String requestMessage = "test request";
interceptedCall.sendMessage(requestMessage);
// Verify that the underlying call's sendMessage() method is invoked
verify(call).sendMessage(requestMessage);
}

@Test
void testInterceptor_responseListener() {
when(channel.newCall(Mockito.<MethodDescriptor<String, Integer>>any(), any(CallOptions.class)))
.thenReturn(call);
GrpcLoggingInterceptor interceptor = spy(new GrpcLoggingInterceptor());
Channel intercepted = ClientInterceptors.intercept(channel, interceptor);
@SuppressWarnings("unchecked")
ClientCall.Listener<Integer> listener = mock(ClientCall.Listener.class);
ClientCall<String, Integer> interceptedCall = intercepted.newCall(method, CallOptions.DEFAULT);
interceptedCall.start(listener, new Metadata());

// Simulate respond interceptor calls
Metadata responseHeaders = new Metadata();
responseHeaders.put(
Metadata.Key.of("test-header", Metadata.ASCII_STRING_MARSHALLER), "header-value");
interceptor.currentListener.onHeaders(responseHeaders);

interceptor.currentListener.onMessage(null);

Status status = Status.OK;
interceptor.currentListener.onClose(status, new Metadata());
}
}
6 changes: 6 additions & 0 deletions gax-java/gax-httpjson/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,12 @@
<artifactId>auto-value-annotations</artifactId>
<scope>provided</scope>
</dependency>
<!-- Logging dependency -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<optional>true</optional>
</dependency>

<!-- test dependencies -->
<dependency>
Expand Down
Loading

0 comments on commit fe002fa

Please sign in to comment.