fix: Improve logging for API Request and API Response (#1295)

Author: congminh1254

src/main/java/com/box/sdk/BoxAPIRequest.java

@@ -1,5 +1,6 @@
 package com.box.sdk;
 
+import static com.box.sdk.BoxSensitiveDataSanitizer.sanitizeHeaders;
 import static com.box.sdk.internal.utils.CollectionUtils.mapToString;
 import static java.lang.String.format;
 
@@ -20,6 +21,7 @@
 import java.util.List;
 import java.util.Map;
 import java.util.Objects;
+import okhttp3.Headers;
 import okhttp3.MediaType;
 import okhttp3.Request;
 import okhttp3.RequestBody;
@@ -509,6 +511,10 @@ BoxFileUploadSessionPart sendForUploadPart(BoxFileUploadSession session, long of
      */
     @Override
     public String toString() {
+        return toStringWithHeaders(null);
+    }
+
+    private String toStringWithHeaders(Headers headers) {
         String lineSeparator = System.getProperty("line.separator");
         StringBuilder builder = new StringBuilder();
         builder.append("Request");
@@ -517,6 +523,11 @@ public String toString() {
         builder.append(' ');
         builder.append(this.url.toString());
         builder.append(lineSeparator);
+        if (headers != null) {
+            builder.append("Headers:").append(lineSeparator);
+            sanitizeHeaders(headers)
+                .forEach(h -> builder.append(format("%s: [%s]%s", h.getFirst(), h.getSecond(), lineSeparator)));
+        }
 
         String bodyString = this.bodyToString();
         if (bodyString != null) {
@@ -588,6 +599,7 @@ private BoxAPIResponse trySend(ProgressListener listener) {
         long start = System.currentTimeMillis();
         Request request = composeRequest(listener);
         Response response;
+        this.logRequest(request.headers());
         if (this.followRedirects) {
             response = api.execute(request);
         } else {
@@ -596,7 +608,6 @@ private BoxAPIResponse trySend(ProgressListener listener) {
         logDebug(format("[trySend] connection.connect() took %dms%n", (System.currentTimeMillis() - start)));
 
         BoxAPIResponse result = BoxAPIResponse.toBoxResponse(response);
-        this.logRequest();
         long getResponseStart = System.currentTimeMillis();
         logDebug(format(
             "[trySend] Get Response (read network) took %dms%n", System.currentTimeMillis() - getResponseStart
@@ -670,8 +681,8 @@ private void logDebug(String message) {
         }
     }
 
-    private void logRequest() {
-        logDebug(this.toString());
+    private void logRequest(Headers headers) {
+        logDebug(headers != null ? this.toStringWithHeaders(headers) : this.toString());
     }
 
     /**

src/main/java/com/box/sdk/BoxAPIResponse.java

@@ -80,13 +80,34 @@ public BoxAPIResponse(
         this(responseCode, requestMethod, requestUrl, headers, null, null, 0);
     }
 
+    public BoxAPIResponse(int responseCode,
+                          String requestMethod,
+                          String requestUrl,
+                          Map<String, List<String>> headers,
+                          String bodyString,
+                          String contentType) {
+        this(responseCode, requestMethod, requestUrl, headers, null, contentType, 0, bodyString);
+    }
+
     public BoxAPIResponse(int code,
                           String requestMethod,
                           String requestUrl,
                           Map<String, List<String>> headers,
                           InputStream body,
                           String contentType,
                           long contentLength
+    ) {
+        this(code, requestMethod, requestUrl, headers, body, contentType, contentLength, null);
+    }
+
+    public BoxAPIResponse(int code,
+                          String requestMethod,
+                          String requestUrl,
+                          Map<String, List<String>> headers,
+                          InputStream body,
+                          String contentType,
+                          long contentLength,
+                          String bodyString
     ) {
         this.responseCode = code;
         this.requestMethod = requestMethod;
@@ -97,7 +118,10 @@ public BoxAPIResponse(int code,
         this.rawInputStream = body;
         this.contentType = contentType;
         this.contentLength = contentLength;
-        storeBodyResponse(body);
+        this.bodyString = bodyString;
+        if (body != null) {
+            storeBodyResponse(body);
+        }
         if (isSuccess(responseCode)) {
             this.logResponse();
         } else {
@@ -106,28 +130,6 @@ public BoxAPIResponse(int code,
         }
     }
 
-    private void storeBodyResponse(InputStream body) {
-        try {
-            if (contentType != null && body != null && contentType.contains(APPLICATION_JSON) && body.available() > 0) {
-                InputStreamReader reader = new InputStreamReader(this.getBody(), UTF_8);
-                StringBuilder builder = new StringBuilder();
-                char[] buffer = new char[BUFFER_SIZE];
-
-                int read = reader.read(buffer, 0, BUFFER_SIZE);
-                while (read != -1) {
-                    builder.append(buffer, 0, read);
-                    read = reader.read(buffer, 0, BUFFER_SIZE);
-                }
-                reader.close();
-                this.disconnect();
-                bodyString = builder.toString();
-                rawInputStream = new ByteArrayInputStream(bodyString.getBytes(UTF_8));
-            }
-        } catch (IOException e) {
-            throw new RuntimeException("Cannot read body stream", e);
-        }
-    }
-
     private static boolean isSuccess(int responseCode) {
         return responseCode >= 200 && responseCode < 400;
     }
@@ -196,6 +198,28 @@ private static BoxAPIResponse emptyContentResponse(Response response) {
         );
     }
 
+    private void storeBodyResponse(InputStream body) {
+        try {
+            if (contentType != null && body != null && contentType.contains(APPLICATION_JSON) && body.available() > 0) {
+                InputStreamReader reader = new InputStreamReader(this.getBody(), UTF_8);
+                StringBuilder builder = new StringBuilder();
+                char[] buffer = new char[BUFFER_SIZE];
+
+                int read = reader.read(buffer, 0, BUFFER_SIZE);
+                while (read != -1) {
+                    builder.append(buffer, 0, read);
+                    read = reader.read(buffer, 0, BUFFER_SIZE);
+                }
+                reader.close();
+                this.disconnect();
+                bodyString = builder.toString();
+                rawInputStream = new ByteArrayInputStream(bodyString.getBytes(UTF_8));
+            }
+        } catch (IOException e) {
+            throw new RuntimeException("Cannot read body stream", e);
+        }
+    }
+
     /**
      * Gets the response code returned by the API.
      *
@@ -274,6 +298,8 @@ public String toString() {
             .append(this.requestMethod)
             .append(' ')
             .append(this.requestUrl)
+            .append(' ')
+            .append(this.responseCode)
             .append(lineSeparator)
             .append(contentType != null ? "Content-Type: " + contentType + lineSeparator : "")
             .append(headers.isEmpty() ? "" : "Headers:" + lineSeparator);
@@ -284,7 +310,10 @@ public String toString() {
 
         String bodyString = this.bodyToString();
         if (bodyString != null && !bodyString.equals("")) {
-            builder.append("Body:").append(lineSeparator).append(bodyString);
+            String sanitizedBodyString = contentType.equals(APPLICATION_JSON)
+                ? BoxSensitiveDataSanitizer.sanitizeJsonBody(Json.parse(bodyString).asObject()).toString()
+                : bodyString;
+            builder.append("Body:").append(lineSeparator).append(sanitizedBodyString);
         }
 
         return builder.toString().trim();
@@ -310,7 +339,7 @@ public void close() {
     /**
      * Returns a string representation of this response's body. This method is used when logging this response's body.
      * By default, it returns an empty string (to avoid accidentally logging binary data) unless the response contained
-     * an error message.
+     * an error message or content type is application/json.
      *
      * @return a string representation of this response's body.
      */

src/main/java/com/box/sdk/BoxJSONResponse.java

@@ -1,5 +1,6 @@
 package com.box.sdk;
 
+import com.box.sdk.http.ContentType;
 import com.eclipsesource.json.Json;
 import com.eclipsesource.json.JsonObject;
 import com.eclipsesource.json.ParseException;
@@ -48,7 +49,7 @@ public BoxJSONResponse(int responseCode,
                            Map<String, List<String>> headers,
                            JsonObject body
     ) {
-        super(responseCode, requestMethod, requestUrl, headers);
+        super(responseCode, requestMethod, requestUrl, headers, body.toString(), ContentType.APPLICATION_JSON);
         this.jsonObject = body;
     }
 

src/main/java/com/box/sdk/BoxSensitiveDataSanitizer.java

@@ -1,5 +1,6 @@
 package com.box.sdk;
 
+import com.eclipsesource.json.JsonObject;
 import java.util.Arrays;
 import java.util.HashSet;
 import java.util.Set;
@@ -44,6 +45,26 @@ static Headers sanitizeHeaders(Headers originalHeaders) {
         return sanitizedHeadersBuilder.build();
     }
 
+    /**
+     * Sanitize the json body. Only for the first level of the json.
+     *
+     * @param originalBody the original json body
+     * @return the sanitized json body
+     */
+    @NotNull
+    static JsonObject sanitizeJsonBody(JsonObject originalBody) {
+        JsonObject sanitizedBody = new JsonObject();
+
+        for (String key : originalBody.names()) {
+            if (isSensitiveKey(key)) {
+                sanitizedBody.set(key, "[REDACATED]");
+            } else {
+                sanitizedBody.set(key, originalBody.get(key));
+            }
+        }
+        return sanitizedBody;
+    }
+
     private static boolean isSensitiveKey(@NotNull String key) {
         return SENSITIVE_KEYS.contains(key.toLowerCase());
     }

src/test/java/com/box/sdk/BoxAPIResponseTest.java

@@ -9,6 +9,8 @@
 import static org.hamcrest.Matchers.contains;
 import static org.hamcrest.Matchers.is;
 
+import com.eclipsesource.json.Json;
+import com.eclipsesource.json.JsonObject;
 import java.io.ByteArrayInputStream;
 import java.io.IOException;
 import java.io.InputStream;
@@ -111,7 +113,7 @@ public void testResponseWithoutBodyToString() {
         BoxAPIResponse response = new BoxAPIResponse(200, "GET", "https://aaa.com", headers);
 
         String str = response.toString();
-        assertThat(str, is("Response\nGET https://aaa.com\nHeaders:\nfoo: [[bAr, zab]]"));
+        assertThat(str, is("Response\nGET https://aaa.com 200\nHeaders:\nfoo: [[bAr, zab]]"));
     }
 
     @Test
@@ -124,7 +126,7 @@ public void testBinaryResponseToString() {
         );
 
         String str = response.toString();
-        assertThat(str, is("Response\nGET https://aaa.com\nContent-Type: image/jpg\nHeaders:\nfoo: [[bAr, zab]]"));
+        assertThat(str, is("Response\nGET https://aaa.com 202\nContent-Type: image/jpg\nHeaders:\nfoo: [[bAr, zab]]"));
     }
 
     @Test
@@ -138,7 +140,27 @@ public void testJsonResponseToString() {
 
         String str = response.toString();
         assertThat(str, is(
-            "Response\nGET https://aaa.com\n"
+            "Response\nGET https://aaa.com 202\n"
+                + "Content-Type: application/json\n"
+                + "Headers:\nfoo: [[bAr, zab]]\n"
+                + "Body:\n{\"foo\":\"bar\"}")
+        );
+    }
+
+
+    @Test
+    public void testBoxJSONResponseToString() {
+        Map<String, List<String>> headers = new TreeMap<>();
+        headers.put("FOO", asList("bAr", "zab"));
+        String responseBody = "{\"foo\":\"bar\"}";
+        JsonObject jsonBody = Json.parse(responseBody).asObject();
+        BoxAPIResponse response = new BoxJSONResponse(
+            202, "GET", "https://aaa.com", headers, jsonBody
+        );
+
+        String str = response.toString();
+        assertThat(str, is(
+            "Response\nGET https://aaa.com 202\n"
                 + "Content-Type: application/json\n"
                 + "Headers:\nfoo: [[bAr, zab]]\n"
                 + "Body:\n{\"foo\":\"bar\"}")

src/test/java/com/box/sdk/BoxSensitiveDataSanitizerTest.java

@@ -3,6 +3,7 @@
 import static org.hamcrest.MatcherAssert.assertThat;
 import static org.hamcrest.Matchers.is;
 
+import com.eclipsesource.json.JsonObject;
 import java.util.HashMap;
 import java.util.Map;
 import okhttp3.Headers;
@@ -85,4 +86,15 @@ public void sanitizeAddedKeys() {
         assertThat(sanitizedHeaders.size(), is(1));
         assertThat(sanitizedHeaders.get("x-auth"), is("[REDACTED]"));
     }
+
+    @Test
+    public void removeSensitiveDataFromJsonBody() {
+        JsonObject body = new JsonObject()
+            .add("authorization", "token")
+            .add("user-agent", "java-sdk");
+        JsonObject sanitizedBody = BoxSensitiveDataSanitizer.sanitizeJsonBody(body);
+
+        assertThat(sanitizedBody.get("authorization").asString(), is("[REDACATED]"));
+        assertThat(sanitizedBody.get("user-agent").asString(), is("java-sdk"));
+    }
 }