Enhance logging to include CF-RAY ID in error messages for fetch failures.

Author: novalisdenahi

src/main/java/com/configcat/ConfigCatLogMessages.java

@@ -20,15 +20,17 @@ final class ConfigCatLogMessages {
      * Log message for Config Service Cache Read error. The log eventId is 2200.
      */
     public static final String CONFIG_SERVICE_CACHE_READ_ERROR = "Error occurred while reading the cache.";
-    /**
-     * Log message for Fetch Failed Due To Unexpected error. The log eventId is 1103.
-     */
-    public static final String FETCH_FAILED_DUE_TO_UNEXPECTED_ERROR = "Unexpected error occurred while trying to fetch config JSON. It is most likely due to a local network issue. Please make sure your application can reach the ConfigCat CDN servers (or your proxy server) over HTTP.";
 
     /**
      * Log message for Fetch Failed Due To Invalid Sdk Key error. The log eventId is 1100.
      */
     private static final String FETCH_FAILED_DUE_TO_INVALID_SDK_KEY_ERROR = "Your SDK Key seems to be wrong. You can find the valid SDK Key at https://app.configcat.com/sdkkey";
+
+    /**
+     * Log message for Fetch Failed Due To Unexpected error. The log eventId is 1103.
+     */
+    private static final String FETCH_FAILED_DUE_TO_UNEXPECTED_ERROR = "Unexpected error occurred while trying to fetch config JSON. It is most likely due to a local network issue. Please make sure your application can reach the ConfigCat CDN servers (or your proxy server) over HTTP.";
+
     /**
      * Log message for Fetch Failed Due To Redirect Loop error. The log eventId is 1104.
      */
@@ -167,12 +169,29 @@ public static FormattableLogMessage getFetchFailedDueToUnexpectedHttpResponse(fi
      * @param connectTimeoutMillis Connect timeout in milliseconds.
      * @param readTimeoutMillis    Read timeout in milliseconds.
      * @param writeTimeoutMillis   Write timeout in milliseconds.
+     * @param cfRayId The http response CF-RAY header value.
      * @return The formattable log message.
      */
-    public static FormattableLogMessage getFetchFailedDueToRequestTimeout(final Integer connectTimeoutMillis, final Integer readTimeoutMillis, final Integer writeTimeoutMillis) {
+    public static FormattableLogMessage getFetchFailedDueToRequestTimeout(final Integer connectTimeoutMillis, final Integer readTimeoutMillis, final Integer writeTimeoutMillis, final String cfRayId) {
+        if (cfRayId != null) {
+            return new FormattableLogMessage("Request timed out while trying to fetch config JSON. Timeout values: [connect: %dms, read: %dms, write: %dms]  %s", connectTimeoutMillis, readTimeoutMillis, writeTimeoutMillis, ConfigCatLogMessages.getCFRayIdPostFix(cfRayId));
+        }
         return new FormattableLogMessage("Request timed out while trying to fetch config JSON. Timeout values: [connect: %dms, read: %dms, write: %dms]", connectTimeoutMillis, readTimeoutMillis, writeTimeoutMillis);
     }
 
+    /**
+     * Log message for Fetch Failed Due To Unexpected error. The log eventId is 1103.
+     *
+     * @param cfRayId The http response CF-RAY header value.
+     * @return The formattable log message.
+     */
+    public static FormattableLogMessage getFetchFailedDueToUnexpectedError(final String cfRayId) {
+        if (cfRayId != null) {
+            return new FormattableLogMessage(FETCH_FAILED_DUE_TO_UNEXPECTED_ERROR + " %s", ConfigCatLogMessages.getCFRayIdPostFix(cfRayId));
+        }
+        return new FormattableLogMessage(FETCH_FAILED_DUE_TO_UNEXPECTED_ERROR);
+    }
+
     /**
      * Log message for Fetch Failed Due To Redirect Loop error. The log eventId is 1104.
      *

src/main/java/com/configcat/ConfigFetcher.java

@@ -82,7 +82,7 @@ private CompletableFuture<FetchResponse> executeFetchAsync(int executionCount, S
                 }
 
             } catch (Exception exception) {
-                this.logger.error(1103, ConfigCatLogMessages.FETCH_FAILED_DUE_TO_UNEXPECTED_ERROR, exception);
+                this.logger.error(1103, ConfigCatLogMessages.getFetchFailedDueToUnexpectedError(fetchResponse.cfRayId()), exception);
                 return CompletableFuture.completedFuture(fetchResponse);
             }
 
@@ -98,11 +98,11 @@ private CompletableFuture<FetchResponse> getResponseAsync(final String eTag) {
             @Override
             public void onFailure(@NotNull Call call, @NotNull IOException e) {
                 int logEventId = 1103;
-                Object message = ConfigCatLogMessages.FETCH_FAILED_DUE_TO_UNEXPECTED_ERROR;
+                Object message = ConfigCatLogMessages.getFetchFailedDueToUnexpectedError(null);
                 if (!isClosed.get()) {
                     if (e instanceof SocketTimeoutException) {
                         logEventId = 1102;
-                        message = ConfigCatLogMessages.getFetchFailedDueToRequestTimeout(httpClient.connectTimeoutMillis(), httpClient.readTimeoutMillis(), httpClient.writeTimeoutMillis());
+                        message = ConfigCatLogMessages.getFetchFailedDueToRequestTimeout(httpClient.connectTimeoutMillis(), httpClient.readTimeoutMillis(), httpClient.writeTimeoutMillis(), null);
                     }
                     logger.error(logEventId, message, e);
                 }
@@ -111,8 +111,9 @@ public void onFailure(@NotNull Call call, @NotNull IOException e) {
 
             @Override
             public void onResponse(@NotNull Call call, @NotNull Response response) {
+                String cfRayId = null;
                 try (ResponseBody body = response.body()) {
-                    String cfRayId = response.header("CF-RAY");
+                    cfRayId = response.header("CF-RAY");
                     if (response.code() == 200) {
                         String content = body != null ? body.string() : null;
                         String eTag = response.header("ETag");
@@ -140,13 +141,13 @@ public void onResponse(@NotNull Call call, @NotNull Response response) {
                         future.complete(FetchResponse.failed(formattableLogMessage, false, cfRayId));
                     }
                 } catch (SocketTimeoutException e) {
-                    FormattableLogMessage formattableLogMessage = ConfigCatLogMessages.getFetchFailedDueToRequestTimeout(httpClient.connectTimeoutMillis(), httpClient.readTimeoutMillis(), httpClient.writeTimeoutMillis());
+                    FormattableLogMessage formattableLogMessage = ConfigCatLogMessages.getFetchFailedDueToRequestTimeout(httpClient.connectTimeoutMillis(), httpClient.readTimeoutMillis(), httpClient.writeTimeoutMillis(), cfRayId);
                     logger.error(1102, formattableLogMessage, e);
-                    future.complete(FetchResponse.failed(formattableLogMessage, false, null));
+                    future.complete(FetchResponse.failed(formattableLogMessage, false, cfRayId));
                 } catch (Exception e) {
-                    String message = ConfigCatLogMessages.FETCH_FAILED_DUE_TO_UNEXPECTED_ERROR;
-                    logger.error(1103, message, e);
-                    future.complete(FetchResponse.failed(message, false, null));
+                    FormattableLogMessage formattableLogMessage = ConfigCatLogMessages.getFetchFailedDueToUnexpectedError(cfRayId);
+                    logger.error(1103, formattableLogMessage, e);
+                    future.complete(FetchResponse.failed(formattableLogMessage, false, cfRayId));
                 }
             }
         });

src/test/java/com/configcat/ConfigFetcherTest.java

@@ -85,6 +85,29 @@ public void fetchException() throws IOException, ExecutionException, Interrupted
         fetch.close();
     }
 
+    @Test
+    public void fetchExceptionContainsCFRayIdIfPresented() throws IOException, ExecutionException, InterruptedException {
+
+        ConfigFetcher fetch = new ConfigFetcher(new OkHttpClient.Builder()
+                .readTimeout(1, TimeUnit.SECONDS)
+                .build(),
+                logger,
+                "",
+                this.server.url("/").toString(),
+                false,
+                PollingModes.manualPoll().getPollingIdentifier());
+
+        this.server.enqueue(new MockResponse().setBody("test").setHeader("CF-RAY", "12345").setBodyDelay(2, TimeUnit.SECONDS));
+        FetchResponse response = fetch.fetchAsync(null).get();
+        assertTrue(response.isFailed());
+        assertTrue(response.entry().isEmpty());
+        assertTrue(response.entry().getConfig().isEmpty());
+
+        assertEquals("12345", response.cfRayId());
+
+        fetch.close();
+    }
+
     @Test
     public void fetchedETagNotUpdatesCache() throws Exception {
         this.server.enqueue(new MockResponse().setResponseCode(200).setBody(TEST_JSON).setHeader("ETag", "fakeETag"));