feat: add logging (#49)

Adds `slf4j` as well as a `log4j2` backend for testing. Also * add some log statements * catch only the exception emitted by GRPC when making GRPC calls
opentdf · May 20, 2024 · 9d20647 · 9d20647
1 parent 3eeb626
commit 9d20647
Show file tree

Hide file tree

Showing 7 changed files with 62 additions and 19 deletions.
diff --git a/README.md b/README.md
@@ -1,3 +1,6 @@
 # java-sdk
 
 OpenTDF Java SDK
+
+### Logging
+We use [slf4j](https://www.slf4j.org/), without providing a backend. We use log4j2 in our tests.
diff --git a/pom.xml b/pom.xml
@@ -37,21 +37,13 @@
                 <version>5.10.1</version>
                 <type>pom</type>
                 <scope>import</scope>
-            </dependency>
-             <dependency>
-                <groupId>org.apache.logging.log4j</groupId>
-                <artifactId>log4j-api</artifactId>
-                <version>${log4j.version}</version>
             </dependency>
             <dependency>
                 <groupId>org.apache.logging.log4j</groupId>
-                <artifactId>log4j-core</artifactId>
-                <version>${log4j.version}</version>
-            </dependency>
-            <dependency>
-                <groupId>org.apache.logging.log4j</groupId>
-                <artifactId>log4j-slf4j2-impl</artifactId>
-                <version>${log4j.version}</version>
+                <artifactId>log4j-bom</artifactId>
+                <version>2.23.1</version>
+                <type>pom</type>
+                <scope>import</scope>
             </dependency>
             <dependency>
                 <groupId>org.projectlombok</groupId>

diff --git a/protocol/pom.xml b/protocol/pom.xml
@@ -57,8 +57,6 @@
                                 <exec executable="buf" dir="../">
                                     <arg value="generate" />
                                     <arg value="https://github.com/opentdf/platform.git#branch=main,subdir=service" />
-                                    <arg value="--exclude-path"/>
-                                    <arg value="authorization/idp_plugin.proto"/>
                                 </exec>
                                 <exec executable="buf" dir="../">
                                     <arg value="generate" />

diff --git a/sdk/pom.xml b/sdk/pom.xml
@@ -17,6 +17,26 @@
             <artifactId>protocol</artifactId>
             <version>0.1.0-SNAPSHOT</version><!-- {x-version-update:java-sdk:current} -->
         </dependency>
+        <dependency>
+            <groupId>org.slf4j</groupId>
+            <artifactId>slf4j-api</artifactId>
+            <version>2.0.13</version>
+        </dependency>
+        <dependency>
+            <groupId>org.apache.logging.log4j</groupId>
+            <artifactId>log4j-slf4j2-impl</artifactId>
+            <scope>test</scope>
+        </dependency>
+        <dependency>
+        <groupId>org.apache.logging.log4j</groupId>
+            <artifactId>log4j-core</artifactId>
+            <scope>test</scope>
+        </dependency>
+        <dependency>
+            <groupId>org.apache.logging.log4j</groupId>
+            <artifactId>log4j-api</artifactId>
+            <scope>test</scope>
+        </dependency>
         <dependency>
             <groupId>org.junit.jupiter</groupId>
             <artifactId>junit-jupiter</artifactId>

diff --git a/sdk/src/main/java/io/opentdf/platform/sdk/GRPCAuthInterceptor.java b/sdk/src/main/java/io/opentdf/platform/sdk/GRPCAuthInterceptor.java
@@ -15,14 +15,15 @@
 import com.nimbusds.oauth2.sdk.http.HTTPRequest;
 import com.nimbusds.oauth2.sdk.http.HTTPResponse;
 import com.nimbusds.oauth2.sdk.token.AccessToken;
-import com.nimbusds.oauth2.sdk.tokenexchange.TokenExchangeGrant;
 import io.grpc.CallOptions;
 import io.grpc.Channel;
 import io.grpc.ClientCall;
 import io.grpc.ClientInterceptor;
 import io.grpc.ForwardingClientCall;
 import io.grpc.Metadata;
 import io.grpc.MethodDescriptor;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import java.net.URI;
 import java.net.URISyntaxException;
@@ -40,6 +41,9 @@ class GRPCAuthInterceptor implements ClientInterceptor {
     private final RSAKey rsaKey;
     private final URI tokenEndpointURI;
 
+    private static final Logger logger = LoggerFactory.getLogger(GRPCAuthInterceptor.class);
+
+
     /**
      * Constructs a new GRPCAuthInterceptor with the specified client authentication and RSA key.
      *
@@ -101,6 +105,8 @@ private synchronized AccessToken getToken() {
             // If the token is expired or initially null, get a new token
             if (token == null || isTokenExpired()) {
 
+                logger.trace("The current access token is expired or empty, getting a new one");
+
                 // Construct the client credentials grant
                 AuthorizationGrant clientGrant = new ClientCredentialsGrant();
 
@@ -124,9 +130,17 @@ private synchronized AccessToken getToken() {
                     throw new RuntimeException("Token request failed: " + error);
                 }
 
-                this.token = tokenResponse.toSuccessResponse().getTokens().getAccessToken();
-                // DPoPAccessToken dPoPAccessToken = tokens.getDPoPAccessToken();
 
+                var tokens = tokenResponse.toSuccessResponse().getTokens();
+                if (tokens.getDPoPAccessToken() != null) {
+                    logger.trace("retrieved a new DPoP access token");
+                } else if (tokens.getAccessToken() != null) {
+                    logger.trace("retrieved a new access token");
+                } else {
+                    logger.trace("got an access token of unknown type");
+                }
+
+                this.token = tokens.getAccessToken();
 
                 if (token.getLifetime() != 0) {
                     // Need some type of leeway but not sure whats best

diff --git a/sdk/src/main/java/io/opentdf/platform/sdk/SDKBuilder.java b/sdk/src/main/java/io/opentdf/platform/sdk/SDKBuilder.java
@@ -14,9 +14,12 @@
 import io.grpc.ManagedChannel;
 import io.grpc.ManagedChannelBuilder;
 import io.grpc.Status;
+import io.grpc.StatusRuntimeException;
 import io.opentdf.platform.wellknownconfiguration.GetWellKnownConfigurationRequest;
 import io.opentdf.platform.wellknownconfiguration.GetWellKnownConfigurationResponse;
 import io.opentdf.platform.wellknownconfiguration.WellKnownServiceGrpc;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import java.io.IOException;
 import java.util.UUID;
@@ -65,7 +68,7 @@ ManagedChannel buildChannel() {
             var stub = WellKnownServiceGrpc.newBlockingStub(bootstrapChannel);
             try {
                 config = stub.getWellKnownConfiguration(GetWellKnownConfigurationRequest.getDefaultInstance());
-            } catch (Exception e) {
+            } catch (StatusRuntimeException e) {
                 Status status = Status.fromThrowable(e);
                 throw new SDKException(String.format("Got grpc status [%s] when getting configuration", status), e);
             }
@@ -82,7 +85,7 @@ ManagedChannel buildChannel() {
                     .getFieldsOrThrow(PLATFORM_ISSUER)
                     .getStringValue();
 
-        } catch (Exception e) {
+        } catch (StatusRuntimeException e) {
             throw new SDKException("Error getting the issuer from the platform", e);
         }
 

diff --git a/sdk/src/test/resources/log4j2.xml b/sdk/src/test/resources/log4j2.xml
@@ -0,0 +1,13 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="WARN">
+    <appenders>
+        <Console name="Console" target="SYSTEM_OUT">
+            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
+        </Console>
+    </appenders>
+    <loggers>
+        <root level="trace">
+            <appender-ref ref="Console"/>
+        </root>
+    </loggers>
+</configuration>