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

feat: add client side logging with slf4j #3403

Open
wants to merge 47 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 10 commits
Commits
Show all changes
47 commits
Select commit Hold shift + click to select a range
59b5d73
poc: add log in grpc interceptor.
zhumin8 Nov 19, 2024
d34ec88
try out basics with httpjson interceptor.
zhumin8 Nov 20, 2024
b6417ae
implement conditional logging, use JUL when no binding. log formattin…
zhumin8 Nov 25, 2024
0c169ad
temp manual testing with showcase.
zhumin8 Nov 25, 2024
9ced175
simplify logic for conditional logger.
zhumin8 Nov 25, 2024
681f7d5
implement logging for basic case.
zhumin8 Nov 26, 2024
5c01ef2
add a JsonContextMapHandler to format in JUL case.
zhumin8 Nov 27, 2024
6605ef3
fix response payload for streaming. Add if guards to bypass log when …
zhumin8 Nov 27, 2024
ebbae15
when logging disabled, assign NOPLogger directly.
zhumin8 Nov 27, 2024
543298d
some temp settings for testing with showcase.
zhumin8 Dec 2, 2024
aac66f2
remove JUL wrapper for now. refactor getLogger(). Add tests for Loggi…
zhumin8 Dec 5, 2024
487614c
minor clean up.:
zhumin8 Dec 5, 2024
cc3465b
fix test after adding interceptor for logging for http.
zhumin8 Dec 5, 2024
211a3d1
cleanup and fix response header.
zhumin8 Dec 6, 2024
2970210
lint
zhumin8 Dec 6, 2024
32f8b7c
lint: license.
zhumin8 Dec 6, 2024
245c14d
refactor GrpcLoggingInterceptor for readability, intro LogData.
zhumin8 Dec 6, 2024
8358497
minor cleanups.
zhumin8 Dec 6, 2024
97087b2
GrpcLoggingInterceptor fix for thread safe, separate out debug loggin…
zhumin8 Dec 6, 2024
727a3e9
minor changes + add showcase it test.(need to run with env var, setup…
zhumin8 Dec 6, 2024
23bc111
refactor HttpJsonLoggingInterceptor. remove public modifier from logg…
zhumin8 Dec 6, 2024
bbe0700
add GrpcLoggingInterceptorTest and test interceptor structure.
zhumin8 Dec 8, 2024
3d7c7f9
fix status code '0'.
zhumin8 Dec 10, 2024
b870d81
merge logs in interceptors, record log data. remove request id.
zhumin8 Dec 10, 2024
56a2870
replace txt message to json message with all fields duplicated.
zhumin8 Dec 10, 2024
83eedf0
add try catch to logging methods
zhumin8 Dec 10, 2024
d85c848
add showcase tests. expose logging interceptors as public to setup te…
zhumin8 Dec 10, 2024
1919809
add internal api annotation.
zhumin8 Dec 10, 2024
613b6c8
lint
zhumin8 Dec 10, 2024
1169eaa
fix typo
zhumin8 Dec 11, 2024
a6b5433
remove unused test class.
zhumin8 Dec 11, 2024
fb0966e
try to exclude test from showcase-native.
zhumin8 Dec 11, 2024
77939fe
fix logback version.
zhumin8 Dec 11, 2024
04ef774
revert accidental change.
zhumin8 Dec 11, 2024
439e071
fix typo in ci.
zhumin8 Dec 11, 2024
673c9fe
cleanup gax pom. add tests.
zhumin8 Dec 11, 2024
c2b607b
add test.
zhumin8 Dec 11, 2024
3df39fa
Merge branch 'main' into client-log
zhumin8 Dec 11, 2024
4190dc7
rm redundant assignment.
zhumin8 Dec 11, 2024
fefb436
add logging test setup in httpjson.
zhumin8 Dec 11, 2024
7901d8a
add log response test to interceptors.
zhumin8 Dec 11, 2024
20f9f5a
remove redundant code.
zhumin8 Dec 11, 2024
172701d
add slf4j and test dep to dependencies.properties.
zhumin8 Dec 11, 2024
d25e742
Merge branch 'main' into client-log
zhumin8 Dec 11, 2024
a8d2f20
make requestPayload also as JsonElement in LogData.
zhumin8 Dec 11, 2024
df97834
fix typo in dependencies.properties.
zhumin8 Dec 12, 2024
32dbd0e
add test assertion to verify logger not enabled at levels when env no…
zhumin8 Dec 12, 2024
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,118 @@
package com.google.api.gax.grpc;

import com.google.api.gax.logging.LoggingUtils;
import com.google.gson.Gson;
import com.google.gson.JsonArray;
import com.google.gson.JsonObject;
import io.grpc.*;
zhumin8 marked this conversation as resolved.
Show resolved Hide resolved
import java.util.HashMap;
import java.util.Map;
import java.util.UUID;
import org.slf4j.Logger;
import org.slf4j.event.Level;

public class GrpcLoggingInterceptor implements ClientInterceptor {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This can be package private. Same thing for HttpJsonLoggingInterceptor.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With the current test setup, these needs to be public for testing purposes. I'll look into the test setup again


private static final Logger logger = LoggingUtils.getLogger(GrpcLoggingInterceptor.class);
private static final Gson gson = new Gson();

@Override
public <ReqT, RespT> ClientCall<ReqT, RespT> interceptCall(
MethodDescriptor<ReqT, RespT> method, CallOptions callOptions, Channel next) {

Map<String, String> serviceAndRpc = new HashMap<>();
Map<String, String> requestLogData = new HashMap<>();
Map<String, String> responseLogData = new HashMap<>();

// Initialize a JsonArray to hold all responses
JsonArray responsePayloads = new JsonArray();
return new ForwardingClientCall.SimpleForwardingClientCall<ReqT, RespT>(
next.newCall(method, callOptions)) {

@Override
public void start(Listener<RespT> responseListener, Metadata headers) {
if (logger.isInfoEnabled()) {
String requestId = UUID.randomUUID().toString();
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think requestId is for debugging purpose for now and would be removed later?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes for now. Later when we also log in tracer, we may need some requestID to track (not this one).

String serviceName = method.getServiceName();
String methodName = method.getFullMethodName();

serviceAndRpc.put("serviceName", serviceName);
serviceAndRpc.put("rpcName", methodName);
serviceAndRpc.put("requestId", requestId);
}
if (logger.isInfoEnabled() && !logger.isDebugEnabled()) {
LoggingUtils.logWithMDC(logger, Level.INFO, serviceAndRpc, "Sending gRPC request");
}

if (logger.isDebugEnabled()) {
requestLogData.putAll(serviceAndRpc);

JsonObject requestHeaders = mapHeadersToJsonObject(headers);
requestLogData.put("request.headers", gson.toJson(requestHeaders));
}

super.start(
new ForwardingClientCallListener.SimpleForwardingClientCallListener<RespT>(
responseListener) {
@Override
public void onMessage(RespT message) {
if (logger.isDebugEnabled()) {
// Add each message to the array
responsePayloads.add(gson.toJsonTree(message));
}
super.onMessage(message);
}

@Override
public void onClose(Status status, Metadata trailers) {
if (logger.isInfoEnabled()) {
serviceAndRpc.put("response.status", status.getCode().name());
responseLogData.putAll(serviceAndRpc);
}
if (logger.isInfoEnabled() && !logger.isDebugEnabled()) {
LoggingUtils.logWithMDC(logger, Level.INFO, serviceAndRpc, "Received response.");
}
if (logger.isDebugEnabled()) {
// Access and add response headers
JsonObject responseHeaders = mapHeadersToJsonObject(trailers);
responseLogData.put("response.headers", gson.toJson(responseHeaders));
// Add the array of payloads to the responseLogData
responseLogData.put("response.payload", gson.toJson(responsePayloads));

LoggingUtils.logWithMDC(
logger, Level.DEBUG, responseLogData, "Received response.");
}

super.onClose(status, trailers);
}
},
headers);
}

@Override
public void sendMessage(ReqT message) {

if (logger.isDebugEnabled()) {
requestLogData.put("request.payload", gson.toJson(message));
LoggingUtils.logWithMDC(logger, Level.DEBUG, requestLogData, "Sending gRPC request.");
}

super.sendMessage(message);
}
};
}

private static JsonObject mapHeadersToJsonObject(Metadata headers) {
JsonObject jsonHeaders = new JsonObject();
headers
.keys()
.forEach(
key -> {
Metadata.Key<String> metadataKey =
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

gRPC metadata could be binary, see https://grpc.io/docs/guides/metadata/. I'm not sure if this is going to fail or not if the value is binary, can you test it out? Either way, I think we should exclude binary headers as they don't provide much value.

Metadata.Key.of(key, Metadata.ASCII_STRING_MARSHALLER);
String headerValue = headers.get(metadataKey);
jsonHeaders.addProperty(key, headerValue);
});
return jsonHeaders;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -467,6 +467,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,116 @@
package com.google.api.gax.httpjson;

import com.google.api.gax.httpjson.ForwardingHttpJsonClientCall.SimpleForwardingHttpJsonClientCall;
import com.google.api.gax.logging.LoggingUtils;
import com.google.gson.Gson;
import com.google.gson.JsonArray;
import com.google.gson.JsonObject;
import java.util.HashMap;
import java.util.Map;
import java.util.UUID;
import org.slf4j.Logger;
import org.slf4j.event.Level;

public class HttpJsonLoggingInterceptor implements HttpJsonClientInterceptor {

private static final Logger logger = LoggingUtils.getLogger(HttpJsonLoggingInterceptor.class);
private static final Gson gson = new Gson();

@Override
public <ReqT, RespT> HttpJsonClientCall<ReqT, RespT> interceptCall(
ApiMethodDescriptor<ReqT, RespT> method,
HttpJsonCallOptions callOptions,
HttpJsonChannel next) {
Map<String, String> requestLogData = new HashMap<>();

// Initialize a JsonArray to hold all responses
JsonArray responsePayloads = new JsonArray();
String endpoint = ((ManagedHttpJsonChannel) next).getEndpoint();
return new SimpleForwardingHttpJsonClientCall<ReqT, RespT>(next.newCall(method, callOptions)) {
@Override
public void start(
HttpJsonClientCall.Listener<RespT> responseListener, HttpJsonMetadata headers) {

Map<String, String> serviceAndRpc = new HashMap<>();
if (logger.isInfoEnabled()) {
String requestId = UUID.randomUUID().toString();
// Capture request details
String methodName = method.getFullMethodName();
String httpMethod = method.getHttpMethod();
serviceAndRpc.put("rpcName", methodName);
serviceAndRpc.put("requestId", requestId);
requestLogData.putAll(serviceAndRpc);
requestLogData.put("request.url", endpoint);
requestLogData.put("request.method", httpMethod);
}
if (logger.isDebugEnabled()) {
// Capture and log headers
JsonObject jsonHeaders = new JsonObject();
headers
.getHeaders()
.forEach((key, value) -> jsonHeaders.addProperty(key, value.toString()));
requestLogData.put("request.headers", gson.toJson(jsonHeaders));
}

if (logger.isInfoEnabled() && !logger.isDebugEnabled()) {
LoggingUtils.logWithMDC(logger, Level.INFO, serviceAndRpc, "Sending HTTP request");
}
Map<String, String> responseLogData = new HashMap<>();
super.start(
new HttpJsonClientCall.Listener<RespT>() {
@Override
public void onMessage(RespT message) {
if (logger.isDebugEnabled()) {
// Add each message to the array
responsePayloads.add(gson.toJsonTree(message));
}
responseListener.onMessage(message);
}

@Override
public void onClose(int status, HttpJsonMetadata trailers) {
if (logger.isInfoEnabled()) {

serviceAndRpc.put("response.status", String.valueOf(status));
responseLogData.putAll(serviceAndRpc);
}
if (logger.isInfoEnabled() && !logger.isDebugEnabled()) {
LoggingUtils.logWithMDC(
logger, Level.INFO, serviceAndRpc, "HTTP request finished.");
}
if (logger.isDebugEnabled()) {

JsonObject jsonHeaders = new JsonObject();
headers
.getHeaders()
.forEach((key, value) -> jsonHeaders.addProperty(key, value.toString()));
responseLogData.put("response.headers", gson.toJson(jsonHeaders));

// Add the array of payloads to the responseLogData
responseLogData.put("response.payload", gson.toJson(responsePayloads));
LoggingUtils.logWithMDC(
logger,
Level.DEBUG,
responseLogData,
"Received response header and payload.");
}

responseListener.onClose(status, trailers);
}
},
headers);
}

@Override
public void sendMessage(ReqT message) {
if (logger.isDebugEnabled()) {
requestLogData.put("request.payload", gson.toJson(message));
LoggingUtils.logWithMDC(
logger, Level.DEBUG, requestLogData, "HTTP request header and payload.");
}

super.sendMessage(message);
}
};
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -196,6 +196,7 @@ private HttpJsonTransportChannel createChannel() throws IOException, GeneralSecu
HttpJsonClientInterceptor headerInterceptor =
new HttpJsonHeaderInterceptor(headerProvider.getHeaders());

channel = new ManagedHttpJsonInterceptorChannel(channel, new HttpJsonLoggingInterceptor());
channel = new ManagedHttpJsonInterceptorChannel(channel, headerInterceptor);
if (interceptorProvider != null && interceptorProvider.getInterceptors() != null) {
for (HttpJsonClientInterceptor interceptor : interceptorProvider.getInterceptors()) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,10 @@ protected ManagedHttpJsonChannel() {
this(null, true, null, null);
}

String getEndpoint() {
return endpoint;
}

private ManagedHttpJsonChannel(
Executor executor,
boolean usingDefaultExecutor,
Expand Down
6 changes: 6 additions & 0 deletions gax-java/gax/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -69,6 +69,12 @@
<artifactId>opentelemetry-api</artifactId>
<optional>true</optional>
</dependency>
<!-- Logging dependency -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>2.0.16</version>
</dependency>
</dependencies>

<build>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,82 @@
/*
* 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.logging;

import com.google.gson.Gson;
import com.google.gson.GsonBuilder;
import java.util.HashMap;
import java.util.Map;
import java.util.logging.ConsoleHandler;
import java.util.logging.Handler;
import java.util.logging.LogRecord;

public class JsonContextMapHandler extends Handler {
zhumin8 marked this conversation as resolved.
Show resolved Hide resolved

private final Gson gson = new GsonBuilder().setPrettyPrinting().create();

@Override
public void publish(LogRecord record) {
Object[] params = record.getParameters();

ConsoleHandler consoleHandler = new ConsoleHandler();
if (params != null && params.length > 0 && params[0] instanceof Map) {
@SuppressWarnings("unchecked")
Map<String, String> contextMap = (Map<String, String>) params[0];

// Create a map to hold all log data
Map<String, Object> logData = new HashMap<>();
logData.put("message", record.getMessage());
logData.put("severity", record.getLevel().getName());
logData.put("timestamp", record.getMillis());
logData.put("logger", record.getLoggerName());

// Add all context data to the top level
logData.putAll(contextMap);

// Convert to JSON
String jsonLog = gson.toJson(logData);

LogRecord jsonRecord = new LogRecord(record.getLevel(), jsonLog);
consoleHandler.publish(jsonRecord);
} else {
// Handle cases where the context map is not present
LogRecord messageRecord =
new LogRecord(record.getLevel(), "Log message without context: " + record.getMessage());
consoleHandler.publish(messageRecord);
}
}

@Override
public void flush() {}

@Override
public void close() throws SecurityException {}
}
Loading
Loading