Improve logging on auth fail conditions in Hashicorp Vault KMS provider (kroxylicious#3212)

* Improve logging on auth fail conditions in Hashicorp Vault KMS provider

---------

Signed-off-by: Tiberiu Sabau <tibssabau@yahoo.com>
Signed-off-by: Robert Young <robertyoungnz@gmail.com>
Co-authored-by: Robert Young <robertyoungnz@gmail.com>

Author: tibisabau

kroxylicious-kms-providers/kroxylicious-kms-provider-hashicorp-vault/pom.xml

@@ -48,7 +48,6 @@
         <dependency>
             <groupId>org.slf4j</groupId>
             <artifactId>slf4j-api</artifactId>
-            <scope>test</scope>
         </dependency>
 
         <!-- third party dependencies - build and compile -->

kroxylicious-kms-providers/kroxylicious-kms-provider-hashicorp-vault/src/main/java/io/kroxylicious/kms/provider/hashicorp/vault/VaultKms.java

@@ -12,6 +12,7 @@
 import java.net.http.HttpClient;
 import java.net.http.HttpRequest;
 import java.net.http.HttpResponse;
+import java.nio.charset.StandardCharsets;
 import java.time.Duration;
 import java.util.Arrays;
 import java.util.Map;
@@ -24,6 +25,9 @@
 
 import javax.crypto.SecretKey;
 
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
 import com.fasterxml.jackson.core.JsonProcessingException;
 import com.fasterxml.jackson.core.type.TypeReference;
 import com.fasterxml.jackson.databind.ObjectMapper;
@@ -48,6 +52,7 @@
  */
 public class VaultKms implements Kms<String, VaultEdek> {
 
+    private static final Logger LOGGER = LoggerFactory.getLogger(VaultKms.class);
     private static final ObjectMapper OBJECT_MAPPER = new ObjectMapper();
     private static final String AES_KEY_ALGO = "AES";
     private static final Pattern LEGAL_API_VERSION_REGEX = Pattern.compile("^/?v1/.+");
@@ -153,6 +158,11 @@ private String createDecryptPostBody(VaultEdek edek) {
             return OBJECT_MAPPER.writeValueAsString(map);
         }
         catch (JsonProcessingException e) {
+            LOGGER.atWarn()
+                    .setCause(LOGGER.isDebugEnabled() ? e : null)
+                    .addArgument(edek.kekRef())
+                    .addArgument(e.getMessage())
+                    .log("Failed to build request body for key '{}', cause: {}. Increase log level to DEBUG for stacktrace");
             throw new KmsException("Failed to build request body for %s".formatted(edek.kekRef()));
         }
     }
@@ -183,24 +193,36 @@ private <T> CompletableFuture<T> sendAsync(String key,
                 .thenApply(VaultResponse::data);
     }
 
-    private static <T> VaultResponse<T> decodeJson(TypeReference<VaultResponse<T>> valueTypeRef, byte[] bytes) {
+    static <T> VaultResponse<T> decodeJson(TypeReference<VaultResponse<T>> valueTypeRef, byte[] bytes) {
         try {
             VaultResponse<T> result = OBJECT_MAPPER.readValue(bytes, valueTypeRef);
             Arrays.fill(bytes, (byte) 0);
             return result;
         }
         catch (IOException e) {
-            throw new UncheckedIOException(e);
+            var responseBody = new String(bytes, StandardCharsets.UTF_8);
+            LOGGER.atWarn()
+                    .setCause(LOGGER.isDebugEnabled() ? e : null)
+                    .addArgument(responseBody)
+                    .addArgument(e.getMessage())
+                    .log("Failed to decode Vault response as JSON, response body: {}, cause: {}. Increase log level to DEBUG for stacktrace");
+            throw new UncheckedIOException("Failed to decode Vault response as JSON", e);
         }
     }
 
     private static HttpResponse<byte[]> checkResponseStatus(String key,
                                                             HttpResponse<byte[]> response,
                                                             Function<String, KmsException> notFound) {
         if (response.statusCode() == 404 || response.statusCode() == 400) {
+            var uri = response.request().uri();
+            var responseBody = new String(response.body(), StandardCharsets.UTF_8);
+            LOGGER.warn("Key '{}' not found in Vault, request uri: {}, HTTP status code: {}, response: {}", key, uri, response.statusCode(), responseBody);
             throw notFound.apply("key '%s' is not found.".formatted(key));
         }
         else if (response.statusCode() != 200) {
+            var uri = response.request().uri();
+            var responseBody = new String(response.body(), StandardCharsets.UTF_8);
+            LOGGER.warn("Failed to retrieve key '{}' from Vault, request uri: {}, HTTP status code: {}, response: {}", key, uri, response.statusCode(), responseBody);
             throw new KmsException("fail to retrieve key '%s', HTTP status code %d.".formatted(key, response.statusCode()));
         }
         return response;

kroxylicious-kms-providers/kroxylicious-kms-provider-hashicorp-vault/src/test/java/io/kroxylicious/kms/provider/hashicorp/vault/VaultKmsTest.java

@@ -6,6 +6,7 @@
 
 package io.kroxylicious.kms.provider.hashicorp.vault;
 
+import java.io.UncheckedIOException;
 import java.net.URI;
 import java.net.http.HttpRequest;
 import java.nio.charset.StandardCharsets;
@@ -24,6 +25,7 @@
 import org.junit.jupiter.params.provider.Arguments;
 import org.junit.jupiter.params.provider.MethodSource;
 
+import com.fasterxml.jackson.core.type.TypeReference;
 import com.github.tomakehurst.wiremock.WireMockServer;
 
 import io.kroxylicious.kms.provider.hashicorp.vault.config.Config;
@@ -247,4 +249,14 @@ void detectsUnacceptableVaultTransitEnginePaths(String name, URI uri) {
 
     }
 
+    @Test
+    void decodeJsonFailure() {
+        TypeReference<VaultResponse<VaultResponse.ReadKeyData>> typeRef = new TypeReference<>() {
+        };
+        byte[] invalidBytes = { 1, 2, 3 };
+        assertThatThrownBy(() -> VaultKms.decodeJson(typeRef, invalidBytes))
+                .isInstanceOf(UncheckedIOException.class)
+                .hasMessageContaining("Failed to decode Vault response as JSON");
+    }
+
 }