Skip to content

Commit

Permalink
Include Cloudflare Ray ID into log messages when the HTTP response is…
Browse files Browse the repository at this point in the history
… not successful
  • Loading branch information
adams85 committed Aug 22, 2024
1 parent e6e4d77 commit df43e4b
Show file tree
Hide file tree
Showing 5 changed files with 70 additions and 25 deletions.
25 changes: 25 additions & 0 deletions src/ConfigCat.Client.Tests/BasicConfigCatClientIntegrationTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -475,4 +475,29 @@ public async Task SpecialCharacters_Works(string settingKey, string userId, stri
var actual = await client.GetValueAsync(settingKey, "NOT_CAT", new User(userId));
Assert.AreEqual(expectedValue, actual);
}

[TestMethod]
public async Task ShouldIncludeRayIdInLogMessagesWhenHttpResponseIsNotSuccessful()
{
var logEvents = new List<LogEvent>();
var logger = LoggingHelper.CreateCapturingLogger(logEvents, LogLevel.Info);

using IConfigCatClient client = ConfigCatClient.Get("configcat-sdk-1/~~~~~~~~~~~~~~~~~~~~~~/~~~~~~~~~~~~~~~~~~~~~~", options =>
{
options.PollingMode = PollingModes.ManualPoll;
options.Logger = logger;
});

await client.ForceRefreshAsync();

var errors = logEvents.Where(evt => evt.EventId == 1100).ToArray();
Assert.AreEqual(1, errors.Length);

var rayId = errors[0].Message.ArgValues[0] as string;
Assert.IsNotNull(rayId);
Assert.AreNotEqual("", rayId);
Assert.AreNotEqual(LoggerExtensions.FormatRayId(null), rayId);

StringAssert.Contains(errors[0].Message.InvariantFormattedMessage, rayId);
}
}
10 changes: 5 additions & 5 deletions src/ConfigCatClient/ConfigService/DefaultConfigFetcher.cs
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ private async ValueTask<FetchResult> FetchInternalAsync(ProjectConfig lastConfig
if (config is null)
{
var exception = deserializedResponse.Exception;
logMessage = this.logger.FetchReceived200WithInvalidBody(exception);
logMessage = this.logger.FetchReceived200WithInvalidBody(response.RayId, exception);
return FetchResult.Failure(lastConfig, RefreshErrorCode.InvalidHttpResponseContent, logMessage.ToLazyString(), exception);
}

Expand All @@ -104,21 +104,21 @@ private async ValueTask<FetchResult> FetchInternalAsync(ProjectConfig lastConfig
case HttpStatusCode.NotModified:
if (lastConfig.IsEmpty)
{
logMessage = this.logger.FetchReceived304WhenLocalCacheIsEmpty((int)response.StatusCode, response.ReasonPhrase);
logMessage = this.logger.FetchReceived304WhenLocalCacheIsEmpty((int)response.StatusCode, response.ReasonPhrase, response.RayId);
return FetchResult.Failure(lastConfig, RefreshErrorCode.InvalidHttpResponseWhenLocalCacheIsEmpty, logMessage.ToLazyString());
}

return FetchResult.NotModified(lastConfig.With(ProjectConfig.GenerateTimeStamp()));

case HttpStatusCode.Forbidden:
case HttpStatusCode.NotFound:
logMessage = this.logger.FetchFailedDueToInvalidSdkKey();
logMessage = this.logger.FetchFailedDueToInvalidSdkKey(response.RayId);

// We update the timestamp for extra protection against flooding.
return FetchResult.Failure(lastConfig.With(ProjectConfig.GenerateTimeStamp()), RefreshErrorCode.InvalidSdkKey, logMessage.ToLazyString());

default:
logMessage = this.logger.FetchFailedDueToUnexpectedHttpResponse((int)response.StatusCode, response.ReasonPhrase);
logMessage = this.logger.FetchFailedDueToUnexpectedHttpResponse((int)response.StatusCode, response.ReasonPhrase, response.RayId);
return FetchResult.Failure(lastConfig, RefreshErrorCode.UnexpectedHttpResponse, logMessage.ToLazyString());
}
}
Expand Down Expand Up @@ -193,7 +193,7 @@ private async ValueTask<DeserializedResponse> FetchRequestAsync(string? httpETag

if (maxExecutionCount <= 1)
{
this.logger.FetchFailedDueToRedirectLoop();
this.logger.FetchFailedDueToRedirectLoop(response.RayId);
return new DeserializedResponse(response, config);
}

Expand Down
27 changes: 21 additions & 6 deletions src/ConfigCatClient/ConfigService/FetchResponse.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,7 @@
using System.Linq;
using System.Net;
using System.Net.Http;
using System.Net.Http.Headers;

namespace ConfigCat.Client;

Expand All @@ -7,17 +10,27 @@ namespace ConfigCat.Client;
/// </summary>
public readonly struct FetchResponse
{
/// <summary>
/// Initializes a new instance of the <see cref="FetchResponse"/> struct.
/// </summary>
public FetchResponse(HttpStatusCode statusCode, string? reasonPhrase, string? eTag, string? body)
internal static FetchResponse From(HttpResponseMessage httpResponse, string? httpResponseBody = null)
{
return new FetchResponse(httpResponse.StatusCode, httpResponse.ReasonPhrase, httpResponse.Headers, httpResponseBody);
}

private readonly object? headersOrETag; // either null or a string or HttpResponseHeaders

private FetchResponse(HttpStatusCode statusCode, string? reasonPhrase, object? headersOrETag, string? body)
{
StatusCode = statusCode;
ReasonPhrase = reasonPhrase;
ETag = eTag;
this.headersOrETag = headersOrETag;
Body = body;
}

/// <summary>
/// Initializes a new instance of the <see cref="FetchResponse"/> struct.
/// </summary>
public FetchResponse(HttpStatusCode statusCode, string? reasonPhrase, string? eTag, string? body)
: this(statusCode, reasonPhrase, (object?)eTag, body) { }

/// <summary>
/// The HTTP status code.
/// </summary>
Expand All @@ -31,7 +44,9 @@ public FetchResponse(HttpStatusCode statusCode, string? reasonPhrase, string? eT
/// <summary>
/// The value of the <c>ETag</c> HTTP response header.
/// </summary>
public string? ETag { get; }
public string? ETag => this.headersOrETag is HttpResponseHeaders headers ? headers.ETag?.Tag : (string?)this.headersOrETag;

internal string? RayId => this.headersOrETag is HttpResponseHeaders headers && headers.TryGetValues("CF-RAY", out var values) ? values.FirstOrDefault() : null;

/// <summary>
/// The response body.
Expand Down
4 changes: 2 additions & 2 deletions src/ConfigCatClient/ConfigService/HttpClientConfigFetcher.cs
Original file line number Diff line number Diff line change
Expand Up @@ -90,11 +90,11 @@ public async Task<FetchResponse> FetchAsync(FetchRequest request, CancellationTo
var httpResponseBody = await httpResponse.Content.ReadAsStringAsync().ConfigureAwait(TaskShim.ContinueOnCapturedContext);
#endif

return new FetchResponse(httpResponse.StatusCode, httpResponse.ReasonPhrase, httpResponse.Headers.ETag?.Tag, httpResponseBody);
return FetchResponse.From(httpResponse, httpResponseBody);
}
else
{
var response = new FetchResponse(httpResponse.StatusCode, httpResponse.ReasonPhrase, eTag: null, body: null);
var response = FetchResponse.From(httpResponse);
if (!response.IsExpected)
{
this.httpClient = null;
Expand Down
29 changes: 17 additions & 12 deletions src/ConfigCatClient/Logging/LogMessages.cs
Original file line number Diff line number Diff line change
Expand Up @@ -38,14 +38,15 @@ public static FormattableLogMessage ForceRefreshError(this LoggerWrapper logger,
$"Error occurred in the `{methodName}` method.",
"METHOD_NAME");

public static FormattableLogMessage FetchFailedDueToInvalidSdkKey(this LoggerWrapper logger) => logger.Log(
public static FormattableLogMessage FetchFailedDueToInvalidSdkKey(this LoggerWrapper logger, string? rayId) => logger.LogInterpolated(
LogLevel.Error, 1100,
"Your SDK Key seems to be wrong. You can find the valid SDK Key at https://app.configcat.com/sdkkey");
$"Your SDK Key seems to be wrong. You can find the valid SDK Key at https://app.configcat.com/sdkkey (Ray ID: {FormatRayId(rayId)})",
"RAY_ID");

public static FormattableLogMessage FetchFailedDueToUnexpectedHttpResponse(this LoggerWrapper logger, int statusCode, string? reasonPhrase) => logger.LogInterpolated(
public static FormattableLogMessage FetchFailedDueToUnexpectedHttpResponse(this LoggerWrapper logger, int statusCode, string? reasonPhrase, string? rayId) => logger.LogInterpolated(
LogLevel.Error, 1101,
$"Unexpected HTTP response was received while trying to fetch config JSON: {statusCode} {reasonPhrase}",
"STATUS_CODE", "REASON_PHRASE");
$"Unexpected HTTP response was received while trying to fetch config JSON: {statusCode} {reasonPhrase} (Ray ID: {FormatRayId(rayId)})",
"STATUS_CODE", "REASON_PHRASE", "RAY_ID");

public static FormattableLogMessage FetchFailedDueToRequestTimeout(this LoggerWrapper logger, TimeSpan timeout, Exception ex) => logger.LogInterpolated(
LogLevel.Error, 1102, ex,
Expand All @@ -56,18 +57,20 @@ public static FormattableLogMessage FetchFailedDueToUnexpectedError(this LoggerW
LogLevel.Error, 1103, ex,
"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.");

public static FormattableLogMessage FetchFailedDueToRedirectLoop(this LoggerWrapper logger) => logger.Log(
public static FormattableLogMessage FetchFailedDueToRedirectLoop(this LoggerWrapper logger, string? rayId) => logger.LogInterpolated(
LogLevel.Error, 1104,
"Redirection loop encountered while trying to fetch config JSON. Please contact us at https://configcat.com/support/");
$"Redirection loop encountered while trying to fetch config JSON. Please contact us at https://configcat.com/support/ (Ray ID: {FormatRayId(rayId)})",
"RAY_ID");

public static FormattableLogMessage FetchReceived200WithInvalidBody(this LoggerWrapper logger, Exception? ex) => logger.Log(
public static FormattableLogMessage FetchReceived200WithInvalidBody(this LoggerWrapper logger, string? rayId, Exception? ex) => logger.LogInterpolated(
LogLevel.Error, 1105, ex,
"Fetching config JSON was successful but the HTTP response content was invalid.");
$"Fetching config JSON was successful but the HTTP response content was invalid. (Ray ID: {FormatRayId(rayId)})",
"RAY_ID");

public static FormattableLogMessage FetchReceived304WhenLocalCacheIsEmpty(this LoggerWrapper logger, int statusCode, string? reasonPhrase) => logger.LogInterpolated(
public static FormattableLogMessage FetchReceived304WhenLocalCacheIsEmpty(this LoggerWrapper logger, int statusCode, string? reasonPhrase, string? rayId) => logger.LogInterpolated(
LogLevel.Error, 1106,
$"Unexpected HTTP response was received when no config JSON is cached locally: {statusCode} {reasonPhrase}",
"STATUS_CODE", "REASON_PHRASE");
$"Unexpected HTTP response was received when no config JSON is cached locally: {statusCode} {reasonPhrase} (Ray ID: {FormatRayId(rayId)})",
"STATUS_CODE", "REASON_PHRASE", "RAY_ID");

public static FormattableLogMessage AutoPollConfigServiceErrorDuringPolling(this LoggerWrapper logger, Exception ex) => logger.Log(
LogLevel.Error, 1200, ex,
Expand Down Expand Up @@ -194,4 +197,6 @@ public static FormattableLogMessage LocalFileDataSourceReloadsFile(this LoggerWr
#region SDK-specific info messages (6000-6999)

#endregion

internal static string FormatRayId(string? value) => value ?? "n/a";
}

0 comments on commit df43e4b

Please sign in to comment.