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

feat: add client side logging with slf4j #3403

wants to merge 47 commits into from

Conversation

zhumin8
Copy link
Contributor

@zhumin8 zhumin8 commented Nov 27, 2024

WIP - test failures still expected.
Will update description when ready

@product-auto-label product-auto-label bot added the size: l Pull request size is large. label Nov 27, 2024
@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).

@product-auto-label product-auto-label bot added size: xl Pull request size is extra large. and removed size: l Pull request size is large. labels Dec 6, 2024
.getHeaders()
.forEach((key, value) -> requestHeaders.addProperty(key, value.toString()));
logDataBuilder.requestHeaders(gson.toJson(requestHeaders));
logDataBuilder.requestHeaders(gson.toJson(requestHeaders));
Copy link

Choose a reason for hiding this comment

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

Why are we calling this twice?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

That's a mistake. Thanks for catching this!

@zhumin8 zhumin8 changed the title [POC] add client side logging feat: add client side logging with slf4j Dec 11, 2024
@zhumin8
Copy link
Contributor Author

zhumin8 commented Dec 11, 2024

ci intergration are failing because cannot find slf4j classes.

external/com_google_api_gax_java/gax/src/main/java/com/google/api/gax/logging/LoggingUtils.java:39: error: symbol not found org.slf4j.Logger
import org.slf4j.Logger;

I added deps to dependencies.properties file: 172701d
Is any where else I need to add these dependencies to? Or are the names malformed? @blakeli0

@zhumin8 zhumin8 marked this pull request as ready for review December 11, 2024 15:49
import org.slf4j.event.Level;

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

@@ -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
Copy link
Collaborator

Choose a reason for hiding this comment

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

Suggested change
maven_org_slf4j_slf4j_api=org.slf4j:slf4j-api:2.0.16
maven.org_slf4j_slf4j_api=org.slf4j:slf4j-api:2.0.16

}
}
} catch (Exception e) {
logger.error("Error logging request info (and headers)", e);
Copy link
Collaborator

Choose a reason for hiding this comment

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

What are the possible errors? I think we need to make sure there are no errors. Even if there are possible errors due to misconfiguration, we should fail more gracefully. This would result in one error log entry for every request which would flood customer's application log.
Same thing for all other try catch blocks.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

These are catch-all safe guard to ensure logging logic never cause user application to crash. Especially due to original timeline, I was concerned that I would miss anything. I will definitely take another look at these logging logic.

That said, I still lean to keep these try-catch blocks as safety net. If we are concerned about flooding customers's log, maybe we can do nothing in the catch and let logging silently fail, which I think is acceptable.

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

public class GrpcLoggingInterceptor implements ClientInterceptor {

private static final Logger LOGGER = LoggingUtils.getLogger(GrpcLoggingInterceptor.class);
private static final Gson GSON = new Gson();
Copy link
Collaborator

Choose a reason for hiding this comment

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

I don't think gax-grpc depends on gson as of now, we need to be careful introducing new dependencies. Can we try to not use gson if possible? If we have to use it, can we extract the common logic to gax?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I was under impression that gax-grpc already depends on gson. I will try to extract to gax.

<RespT> void recordResponsePayload(RespT message, LogData.Builder logDataBuilder) {
try {
if (LOGGER.isDebugEnabled()) {
logDataBuilder.responsePayload(GSON.toJsonTree(message));
Copy link
Collaborator

Choose a reason for hiding this comment

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

message is a Protobuf message, so we should use Protobuf utils to serialize it to Json if we have to. See how we serialized it in ProtoRestSerializer. Same comment for the request payload logging below.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thanks for the pointer. Will look into.


/** Represents the default system environment provider. */
@InternalApi
public class SystemEnvironmentProvider implements EnvironmentProvider {
Copy link
Collaborator

Choose a reason for hiding this comment

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

Is this class needed? Can we do System::getEnv?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This class is needed because of the current test setup, again was something of lower priority because it is not public and only for test setup.
I will look into migrate tests to only use ci setups to control env vars, in that case, I will be able to get rid of this.

};
}

// Helper methods for logging
Copy link
Collaborator

Choose a reason for hiding this comment

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

Since we are exposing public util classes in gax already, I think it's better to move these to gax to prevent duplication. This can also help us remove the dependency of gson in gax-grpc, and LogData does not have to exposed publicly.

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. I was inclined to do this as refactoring later, but I agree these are better of as utils methods from gax.

Copy link

Quality Gate Failed Quality Gate failed for 'gapic-generator-java-root'

Failed conditions
66.8% Coverage on New Code (required ≥ 80%)

See analysis details on SonarQube Cloud

Copy link

Quality Gate Failed Quality Gate failed for 'java_showcase_integration_tests'

Failed conditions
39.6% Coverage on New Code (required ≥ 80%)

See analysis details on SonarQube Cloud

@@ -205,6 +210,20 @@
</exclusions>
<scope>test</scope>
</dependency>
<!-- Logback for testing -->
<dependency>
Copy link
Collaborator

Choose a reason for hiding this comment

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

It would be great if we don't have to add logback in unit tests. Maybe create our own SLF4J test logger, similar to the JUL TestLogger


@Override
public void start(Listener<RespT> responseListener, Metadata headers) {
logRequestInfo(method, logDataBuilder, LOGGER);
Copy link
Collaborator

Choose a reason for hiding this comment

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

There is a chance that a call is started but failed before sending messages, so it would be better if we only record the log data (headers) here, and do the actual logging in sendMessage.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
size: xl Pull request size is extra large.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants