feat: add client logging with slf4j

[zhumin8]

This Pr contains changes for adding client logging capability to auth.
see go/java-client-logging-design

Some logging setups are mirror of same setting in Gax (pr 3403)

Changes includes:

• add slf4j as optional dependency, enable logging only when GOOGLE_SDK_JAVA_LOGGING=true
• user app should add SLF4J + binding dependencies accordingly. For SLF4J 1x, we record extra info with MDC; for SLF4J2x, we record extra info with KeyValuePairs. More user guide to be added via README (see draft).
• If env var not true, or no binding present, default to no-op.
• Add log for request and response made to auth endpoints for UserCredentials, ServiceAccountCredentials, ComputeEngineCredentials, ImpersonatedCredentials. For token values included, added hash in log. Note this PR mainly focuses on adding logging setups, logging statements can be added incrementally later if necessary.

Here is an example logging output for access token request from UserCredentials when DEBUG level is allowed. (TO UPDATE)

{"@timestamp":"2024-12-04T21:10:48.596382834-05:00","@version":"1","message":"Sending auth request to refresh access token.","logger_name":"com.google.auth.oauth2.UserCredentials","thread_name":"main","severity":"DEBUG","level_value":10000,"request.method":"POST","request.headers":{"x-goog-api-client":"gl-java/19.0.1 auth/1.32.2-SNAPSHOT cred-type/u","accept-encoding":["gzip"]},"request.url":"https://foo.com/bar","request.payload":{"refresh_token":"bae0258be92ea1d1e14f984507bee05ff4502a29104f4101d22a4a88706b0fc0","grant_type":"refresh_token","client_secret":"2d3c802ef65d75e88b098792e2268cd3f55a08bcbb8c8c4672f1195d1951d4b5","client_id":"ya29.1.AADtN_UtlxN3PuGAxrN2XQnZTVRvDyVWnYq4I6dws"}}
{"@timestamp":"2024-12-04T21:10:48.624914522-05:00","@version":"1","message":"Received auth respond for refresh access token.","logger_name":"com.google.auth.oauth2.UserCredentials","thread_name":"main","severity":"INFO","level_value":20000,"response.status":"200","response.headers":"{}"}
{"@timestamp":"2024-12-04T21:10:48.627483862-05:00","@version":"1","message":"Auth response payload.","logger_name":"com.google.auth.oauth2.UserCredentials","thread_name":"main","severity":"DEBUG","level_value":10000,"access_token":"1/MkS*****KPY2","refresh_token":"1/Tl6*****yGWY","token_type":"Bearer","expires_in":"3600"}

Testing setup - Currently added flavor of tests:

• unit tests with no extra dependency
• unit tests depending on either binding be present, or logback implementation to capture logging for test
• test for log behaviors for various requests where logs are added. (see LoggingTest)

Remaining issue with test scenarios:

1. when no binding present: this is tested via regular tests
2. when env var is T and binding present: tested via test-logging (profile with logback deps)
3. no SLF4J present: same logic as 1, it should be fine with coverage of 1. This is hard to setup this because SLF4J is needed at compile.
4. SLF4J 1x + binding: Hard to setup because SLF4J 2x is needed at compile

One possibility to setup tests for 3 and 4 perhaps is to setup a separate module for testing, but that would require to expose logging classes as public to access outside of package. If no better options, I am inclined to do some manual testing, and do not expose these classes. WDYT?

[zhumin8]

@lqiu96 I still have some trouble with the test env, but wanted to put it out there so you can get a preview of the changes. Can you take a quick look and let me know if you have any concerns.

[lqiu96]

Can we move this to LoggingUtils since this seems to be used in the other credentials?

[zhumin8]

They are slightly different, but I will try to extract any useful shared logics into LoggingUtils.

[lqiu96]

Can you highlight the difference? From what I see, the other Credentials also end up calling GenericData responseData = response.parseAs(GenericData.class); but this is moved to a function.

Might be missing something, but I don't see what is preventing this from going into LoggingUtils.

[zhumin8]

Hope #1586 (comment) answers this question too.

[lqiu96]

Suggested change

	request, LOGGER_PROVIDER, "Sending request to get ID token via Oauth endpoint");
	request, LOGGER_PROVIDER, "Sending request to get ID token");

I think it would be better to not include the internal implementation details. I think it would be better to keep it as ... retrieving ID Token or similar.

[zhumin8]

hmm, I feel like this could be helpful information for debugging.
Also, fyi - we currently publish client debug logging with disclaimer. And we will be able to make changes to these log messages without breaking change.

[lqiu96]

Users don't get to configure any settings to choose whether to hit the Oauth or IAM endpoint. It's an implementation detail and we decide based on the UD value of the Credentials. As long as users see that it's trying to retrieve the ID token, I think that's should suffice for the log.

The request.url value should be populated as part of the structure log IIUC and that could be helpful to determine exactly which endpoint is sent.

[zhumin8]

That's fair. I will remove the endpoint part.

[lqiu96]

I think logging here makes sense, I am just wondering if it would make sense to have the Credential pass the logger in here. I don't know what the standard would be and I'll defer to you.

I think this would currently show up as something like:
IamUtils.class - Sending request to get signature to sign the blob

The concern that pops up is that IamUtils is an internal class and doesn't tell the user which Credentials is actually access the sign call.

Do you think it would be better as:
ComputeEngineCredentials - Sending request to get signature to sign the blob

[zhumin8]

hmm, usually the convention is to logging in the class where it occurs. Although to your point, we can probably add another log entry before entering the IamUtils methods, but I am not sure if that's too much details?

[lqiu96]

Ok gotcha I see. In the case I think it's fine. Maybe if anything it could be something like Sending request to get signature to sign the blob for %s, Credentials.getClass()). That also might be overkill. I think we can keep as is and improve it from user feedback.

[lqiu96]

Is there a naming convention for the key here? hyphens to seperate the words, camelCase?

[zhumin8]

Good point. I don't think there is not a generic naming convention. However, I agree we should keep consistent as possible. Following most camelCases in this doc, and be consistent with other payload fields like "includeEmail", I am going to change this to "idToken"

[lqiu96]

LGTM. Added a few comment.

[sonarqubecloud]

Quality Gate failed

Failed conditions
0.0% Coverage on New Code (required ≥ 80%)
E Security Rating on New Code (required ≥ A)

See analysis details on SonarQube Cloud

Catch issues before they fail your Quality Gate with our IDE extension SonarQube for IDE