Skip to content

Commit 24761d6

Browse files
authoredFeb 24, 2025··
feat: add client logging with slf4j (#1586)
This Pr contains changes for adding client logging capability to auth. see [go/java-client-logging-design](http://goto.google.com/java-client-logging-design) Some logging setups are mirror of same setting in Gax ([pr 3403](googleapis/sdk-platform-java#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](https://docs.google.com/document/d/1g8HJCstkEEZZc73gFlQO8uPGs07SkWKkr7NG-Yg4bvM/edit?tab=t.0#heading=h.9t58aw3up7to)). - 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
1 parent 54b4c1a commit 24761d6

23 files changed

+1733
-22
lines changed
 

‎.github/workflows/ci.yaml

+16
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,22 @@ jobs:
3636
- run: .kokoro/build.sh
3737
env:
3838
JOB_TYPE: test
39+
units-logging:
40+
runs-on: ubuntu-latest
41+
strategy:
42+
fail-fast: false
43+
matrix:
44+
java: [11, 17, 21]
45+
steps:
46+
- uses: actions/checkout@v4
47+
- uses: actions/setup-java@v4
48+
with:
49+
distribution: temurin
50+
java-version: ${{matrix.java}}
51+
- run: java -version
52+
- run: .kokoro/build.sh
53+
env:
54+
JOB_TYPE: test-logging
3955
units-java8:
4056
# Building using Java 17 and run the tests with Java 8 runtime
4157
name: "units (8)"

‎.github/workflows/sonar.yaml

+2
Original file line numberDiff line numberDiff line change
@@ -38,9 +38,11 @@ jobs:
3838
SONAR_TOKEN: ${{ secrets.SONAR_TOKEN }}
3939
run: |
4040
mvn -B verify -Dcheckstyle.skip \
41+
-Djacoco.skip=true \
4142
-DenableFullTestCoverage \
4243
-Dsonar.coverage.jacoco.xmlReportPaths=oauth2_http/target/site/jacoco/jacoco.xml \
4344
org.sonarsource.scanner.maven:sonar-maven-plugin:sonar \
4445
-Dsonar.projectKey=googleapis_google-auth-library-java \
4546
-Dsonar.organization=googleapis \
4647
-Dsonar.host.url=https://sonarcloud.io
48+

‎.kokoro/build.sh

+8-2
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,11 @@ test)
5151
mvn test -B -ntp -Dclirr.skip=true -Denforcer.skip=true ${SUREFIRE_JVM_OPT}
5252
RETURN_CODE=$?
5353
;;
54+
test-logging)
55+
echo "SUREFIRE_JVM_OPT: ${SUREFIRE_JVM_OPT}"
56+
mvn clean test -P '!slf4j2x,slf4j2x-test' -B -ntp -Dclirr.skip=true -Denforcer.skip=true ${SUREFIRE_JVM_OPT}
57+
RETURN_CODE=$?
58+
;;
5459
lint)
5560
mvn com.coveo:fmt-maven-plugin:check -B -ntp
5661
RETURN_CODE=$?
@@ -66,6 +71,7 @@ integration)
6671
-DtrimStackTrace=false \
6772
-Dclirr.skip=true \
6873
-Denforcer.skip=true \
74+
-Djacoco.skip=true \
6975
-fae \
7076
verify
7177
RETURN_CODE=$?
@@ -74,14 +80,14 @@ graalvmA)
7480
# Run Unit and Integration Tests with Native Image
7581
bash .kokoro/populate-secrets.sh
7682
export GOOGLE_APPLICATION_CREDENTIALS="${KOKORO_GFILE_DIR}/secret_manager/java-it-service-account"
77-
mvn -B ${INTEGRATION_TEST_ARGS} -ntp -Pnative -Pnative-test test -pl 'oauth2_http'
83+
mvn -B ${INTEGRATION_TEST_ARGS} -ntp -Pnative -Pnative-test -Pslf4j2x test -pl 'oauth2_http'
7884
RETURN_CODE=$?
7985
;;
8086
graalvmB)
8187
# Run Unit and Integration Tests with Native Image
8288
bash .kokoro/populate-secrets.sh
8389
export GOOGLE_APPLICATION_CREDENTIALS="${KOKORO_GFILE_DIR}/secret_manager/java-it-service-account"
84-
mvn -B ${INTEGRATION_TEST_ARGS} -ntp -Pnative -Pnative-test test -pl 'oauth2_http'
90+
mvn -B ${INTEGRATION_TEST_ARGS} -ntp -Pnative -Pnative-test -Pslf4j2x test -pl 'oauth2_http'
8591
RETURN_CODE=$?
8692
;;
8793
samples)

‎.kokoro/dependencies.sh

+1
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,7 @@ retry_with_backoff 3 10 \
5454
mvn install -B -V -ntp \
5555
-DskipTests=true \
5656
-Dmaven.javadoc.skip=true \
57+
-Djacoco.skip=true \
5758
-Dclirr.skip=true
5859

5960
mvn -B dependency:analyze -DfailOnWarning=true

‎oauth2_http/java/com/google/auth/oauth2/ComputeEngineCredentials.java

+30
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,7 @@
5151
import com.google.common.base.Joiner;
5252
import com.google.common.base.MoreObjects.ToStringHelper;
5353
import com.google.common.collect.ImmutableList;
54+
import com.google.common.collect.ImmutableMap;
5455
import com.google.common.collect.ImmutableSet;
5556
import com.google.errorprone.annotations.CanIgnoreReturnValue;
5657
import java.io.BufferedReader;
@@ -94,6 +95,8 @@ public class ComputeEngineCredentials extends GoogleCredentials
9495
static final Duration COMPUTE_REFRESH_MARGIN = Duration.ofMinutes(3).plusSeconds(45);
9596

9697
private static final Logger LOGGER = Logger.getLogger(ComputeEngineCredentials.class.getName());
98+
private static final LoggerProvider LOGGER_PROVIDER =
99+
LoggerProvider.forClazz(ComputeEngineCredentials.class);
97100

98101
static final String DEFAULT_METADATA_SERVER_URL = "http://metadata.google.internal";
99102

@@ -371,11 +374,14 @@ public AccessToken refreshAccessToken() throws IOException {
371374
throw new IOException(METADATA_RESPONSE_EMPTY_CONTENT_ERROR_MESSAGE);
372375
}
373376
GenericData responseData = response.parseAs(GenericData.class);
377+
LoggingUtils.logResponsePayload(
378+
responseData, LOGGER_PROVIDER, "Response payload for access token");
374379
String accessToken =
375380
OAuth2Utils.validateString(responseData, "access_token", PARSE_ERROR_PREFIX);
376381
int expiresInSeconds =
377382
OAuth2Utils.validateInt32(responseData, "expires_in", PARSE_ERROR_PREFIX);
378383
long expiresAtMilliseconds = clock.currentTimeMillis() + expiresInSeconds * 1000;
384+
379385
return new AccessToken(accessToken, new Date(expiresAtMilliseconds));
380386
}
381387

@@ -430,6 +436,12 @@ public IdToken idTokenWithAudience(String targetAudience, List<IdTokenProvider.O
430436
throw new IOException(METADATA_RESPONSE_EMPTY_CONTENT_ERROR_MESSAGE);
431437
}
432438
String rawToken = response.parseAsString();
439+
440+
LoggingUtils.log(
441+
LOGGER_PROVIDER,
442+
Level.FINE,
443+
ImmutableMap.of("idToken", rawToken),
444+
"Response Payload for ID token");
433445
return IdToken.create(rawToken);
434446
}
435447

@@ -451,7 +463,23 @@ private HttpResponse getMetadataResponse(
451463
request.setThrowExceptionOnExecuteError(false);
452464
HttpResponse response;
453465
try {
466+
String requestMessage;
467+
String responseMessage;
468+
if (requestType.equals(RequestType.ID_TOKEN_REQUEST)) {
469+
requestMessage = "Sending request to get ID token";
470+
responseMessage = "Received response for ID token request";
471+
} else if (requestType.equals(RequestType.ACCESS_TOKEN_REQUEST)) {
472+
requestMessage = "Sending request to refresh access token";
473+
responseMessage = "Received response for refresh access token";
474+
} else {
475+
// TODO: this includes get universe domain and get default sa.
476+
// refactor for more clear logging message.
477+
requestMessage = "Sending request for universe domain/default service account";
478+
responseMessage = "Received response for universe domain/default service account";
479+
}
480+
LoggingUtils.logRequest(request, LOGGER_PROVIDER, requestMessage);
454481
response = request.execute();
482+
LoggingUtils.logResponse(response, LOGGER_PROVIDER, responseMessage);
455483
} catch (UnknownHostException exception) {
456484
throw new IOException(
457485
"ComputeEngineCredentials cannot find the metadata server. This is"
@@ -730,6 +758,8 @@ private String getDefaultServiceAccount() throws IOException {
730758
throw new IOException(METADATA_RESPONSE_EMPTY_CONTENT_ERROR_MESSAGE);
731759
}
732760
GenericData responseData = response.parseAs(GenericData.class);
761+
LoggingUtils.logResponsePayload(
762+
responseData, LOGGER_PROVIDER, "Received default service account payload");
733763
Map<String, Object> defaultAccount =
734764
OAuth2Utils.validateMap(responseData, "default", PARSE_ERROR_ACCOUNT);
735765
return OAuth2Utils.validateString(defaultAccount, "email", PARSE_ERROR_ACCOUNT);

‎oauth2_http/java/com/google/auth/oauth2/IamUtils.java

+12
Original file line numberDiff line numberDiff line change
@@ -72,6 +72,7 @@ class IamUtils {
7272
"https://iamcredentials.%s/v1/projects/-/serviceAccounts/%s:signBlob";
7373
private static final String PARSE_ERROR_MESSAGE = "Error parsing error message response. ";
7474
private static final String PARSE_ERROR_SIGNATURE = "Error parsing signature response. ";
75+
private static final LoggerProvider LOGGER_PROVIDER = LoggerProvider.forClazz(IamUtils.class);
7576

7677
// Following guidance for IAM retries:
7778
// https://cloud.google.com/iam/docs/retry-strategy#errors-to-retry
@@ -154,7 +155,11 @@ private static String getSignature(
154155
IamUtils.IAM_RETRYABLE_STATUS_CODES.contains(response.getStatusCode())));
155156
request.setIOExceptionHandler(new HttpBackOffIOExceptionHandler(backoff));
156157

158+
LoggingUtils.logRequest(
159+
request, LOGGER_PROVIDER, "Sending request to get signature to sign the blob");
157160
HttpResponse response = request.execute();
161+
LoggingUtils.logResponse(
162+
response, LOGGER_PROVIDER, "Received response for signature to sign the blob");
158163
int statusCode = response.getStatusCode();
159164
if (statusCode >= 400 && statusCode < HttpStatusCodes.STATUS_CODE_SERVER_ERROR) {
160165
GenericData responseError = response.parseAs(GenericData.class);
@@ -181,6 +186,8 @@ private static String getSignature(
181186
}
182187

183188
GenericData responseData = response.parseAs(GenericData.class);
189+
LoggingUtils.logResponsePayload(
190+
responseData, LOGGER_PROVIDER, "Response payload for sign blob");
184191
return OAuth2Utils.validateString(responseData, "signedBlob", PARSE_ERROR_SIGNATURE);
185192
}
186193

@@ -234,7 +241,10 @@ static IdToken getIdToken(
234241
MetricsUtils.getGoogleCredentialsMetricsHeader(
235242
RequestType.ID_TOKEN_REQUEST, credentialTypeForMetrics));
236243

244+
LoggingUtils.logRequest(request, LOGGER_PROVIDER, "Sending request to get ID token");
237245
HttpResponse response = request.execute();
246+
247+
LoggingUtils.logResponse(response, LOGGER_PROVIDER, "Received response for ID token request");
238248
int statusCode = response.getStatusCode();
239249
if (statusCode >= 400 && statusCode < HttpStatusCodes.STATUS_CODE_SERVER_ERROR) {
240250
GenericData responseError = response.parseAs(GenericData.class);
@@ -259,6 +269,8 @@ static IdToken getIdToken(
259269
}
260270

261271
GenericJson responseData = response.parseAs(GenericJson.class);
272+
LoggingUtils.logResponsePayload(
273+
responseData, LOGGER_PROVIDER, "Response payload for ID token request");
262274
String rawToken = OAuth2Utils.validateString(responseData, "token", PARSE_ERROR_MESSAGE);
263275
return IdToken.create(rawToken);
264276
}

‎oauth2_http/java/com/google/auth/oauth2/ImpersonatedCredentials.java

+7
Original file line numberDiff line numberDiff line change
@@ -110,6 +110,8 @@ public class ImpersonatedCredentials extends GoogleCredentials
110110
private int lifetime;
111111
private String iamEndpointOverride;
112112
private final String transportFactoryClassName;
113+
private static final LoggerProvider LOGGER_PROVIDER =
114+
LoggerProvider.forClazz(ImpersonatedCredentials.class);
113115

114116
private transient HttpTransportFactory transportFactory;
115117

@@ -553,12 +555,17 @@ public AccessToken refreshAccessToken() throws IOException {
553555

554556
HttpResponse response = null;
555557
try {
558+
LoggingUtils.logRequest(request, LOGGER_PROVIDER, "Sending request to refresh access token");
556559
response = request.execute();
560+
LoggingUtils.logResponse(
561+
response, LOGGER_PROVIDER, "Received response for refresh access token");
557562
} catch (IOException e) {
558563
throw new IOException("Error requesting access token", e);
559564
}
560565

561566
GenericData responseData = response.parseAs(GenericData.class);
567+
LoggingUtils.logResponsePayload(
568+
responseData, LOGGER_PROVIDER, "Response payload for access token");
562569
response.disconnect();
563570

564571
String accessToken =
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,55 @@
1+
/*
2+
* Copyright 2025 Google LLC
3+
*
4+
* Redistribution and use in source and binary forms, with or without
5+
* modification, are permitted provided that the following conditions are
6+
* met:
7+
*
8+
* * Redistributions of source code must retain the above copyright
9+
* notice, this list of conditions and the following disclaimer.
10+
* * Redistributions in binary form must reproduce the above
11+
* copyright notice, this list of conditions and the following disclaimer
12+
* in the documentation and/or other materials provided with the
13+
* distribution.
14+
*
15+
* * Neither the name of Google LLC nor the names of its
16+
* contributors may be used to endorse or promote products derived from
17+
* this software without specific prior written permission.
18+
*
19+
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
20+
* "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
21+
* LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
22+
* A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
23+
* OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
24+
* SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
25+
* LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
26+
* DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
27+
* THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
28+
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
29+
* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
30+
*/
31+
32+
package com.google.auth.oauth2;
33+
34+
import org.slf4j.Logger;
35+
36+
class LoggerProvider {
37+
38+
private Logger logger;
39+
private final Class<?> clazz;
40+
41+
private LoggerProvider(Class<?> clazz) {
42+
this.clazz = clazz;
43+
}
44+
45+
static LoggerProvider forClazz(Class<?> clazz) {
46+
return new LoggerProvider(clazz);
47+
}
48+
49+
Logger getLogger() {
50+
if (logger == null) {
51+
this.logger = Slf4jUtils.getLogger(clazz);
52+
}
53+
return logger;
54+
}
55+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,88 @@
1+
/*
2+
* Copyright 2025 Google LLC
3+
*
4+
* Redistribution and use in source and binary forms, with or without
5+
* modification, are permitted provided that the following conditions are
6+
* met:
7+
*
8+
* * Redistributions of source code must retain the above copyright
9+
* notice, this list of conditions and the following disclaimer.
10+
* * Redistributions in binary form must reproduce the above
11+
* copyright notice, this list of conditions and the following disclaimer
12+
* in the documentation and/or other materials provided with the
13+
* distribution.
14+
*
15+
* * Neither the name of Google LLC nor the names of its
16+
* contributors may be used to endorse or promote products derived from
17+
* this software without specific prior written permission.
18+
*
19+
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
20+
* "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
21+
* LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
22+
* A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
23+
* OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
24+
* SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
25+
* LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
26+
* DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
27+
* THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
28+
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
29+
* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
30+
*/
31+
32+
package com.google.auth.oauth2;
33+
34+
import com.google.api.client.http.HttpRequest;
35+
import com.google.api.client.http.HttpResponse;
36+
import com.google.api.client.util.GenericData;
37+
import java.util.Map;
38+
import java.util.logging.Level;
39+
40+
class LoggingUtils {
41+
42+
static final String GOOGLE_SDK_JAVA_LOGGING = "GOOGLE_SDK_JAVA_LOGGING";
43+
private static EnvironmentProvider environmentProvider =
44+
SystemEnvironmentProvider.getInstance(); // this may be reset for testing purpose
45+
46+
private static boolean loggingEnabled = isLoggingEnabled();
47+
48+
// expose this setter only for testing purposes
49+
static void setEnvironmentProvider(EnvironmentProvider provider) {
50+
environmentProvider = provider;
51+
// Recalculate LOGGING_ENABLED after setting the new provider
52+
loggingEnabled = isLoggingEnabled();
53+
}
54+
55+
static boolean isLoggingEnabled() {
56+
String enableLogging = environmentProvider.getEnv(GOOGLE_SDK_JAVA_LOGGING);
57+
return "true".equalsIgnoreCase(enableLogging);
58+
}
59+
60+
static void logRequest(HttpRequest request, LoggerProvider loggerProvider, String message) {
61+
if (loggingEnabled) {
62+
Slf4jLoggingHelpers.logRequest(request, loggerProvider, message);
63+
}
64+
}
65+
66+
static void logResponse(HttpResponse response, LoggerProvider loggerProvider, String message) {
67+
if (loggingEnabled) {
68+
Slf4jLoggingHelpers.logResponse(response, loggerProvider, message);
69+
}
70+
}
71+
72+
static void logResponsePayload(
73+
GenericData genericData, LoggerProvider loggerProvider, String message) {
74+
if (loggingEnabled) {
75+
Slf4jLoggingHelpers.logResponsePayload(genericData, loggerProvider, message);
76+
}
77+
}
78+
79+
// generic log method to use when not logging standard request, response and payload
80+
static void log(
81+
LoggerProvider loggerProvider, Level level, Map<String, Object> contextMap, String message) {
82+
if (loggingEnabled) {
83+
Slf4jLoggingHelpers.log(loggerProvider, level, contextMap, message);
84+
}
85+
}
86+
87+
private LoggingUtils() {}
88+
}

0 commit comments

Comments
 (0)
Please sign in to comment.