diff --git a/src/ConfigCat.Client.Tests/BasicConfigCatClientIntegrationTests.cs b/src/ConfigCat.Client.Tests/BasicConfigCatClientIntegrationTests.cs index 7dd29dad..50f88840 100644 --- a/src/ConfigCat.Client.Tests/BasicConfigCatClientIntegrationTests.cs +++ b/src/ConfigCat.Client.Tests/BasicConfigCatClientIntegrationTests.cs @@ -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(); + 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); + } } diff --git a/src/ConfigCatClient/ConfigService/DefaultConfigFetcher.cs b/src/ConfigCatClient/ConfigService/DefaultConfigFetcher.cs index d503ca5f..d3ba178c 100644 --- a/src/ConfigCatClient/ConfigService/DefaultConfigFetcher.cs +++ b/src/ConfigCatClient/ConfigService/DefaultConfigFetcher.cs @@ -89,7 +89,7 @@ private async ValueTask 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); } @@ -104,7 +104,7 @@ private async ValueTask 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()); } @@ -112,13 +112,13 @@ private async ValueTask FetchInternalAsync(ProjectConfig lastConfig 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()); } } @@ -193,7 +193,7 @@ private async ValueTask FetchRequestAsync(string? httpETag if (maxExecutionCount <= 1) { - this.logger.FetchFailedDueToRedirectLoop(); + this.logger.FetchFailedDueToRedirectLoop(response.RayId); return new DeserializedResponse(response, config); } diff --git a/src/ConfigCatClient/ConfigService/FetchResponse.cs b/src/ConfigCatClient/ConfigService/FetchResponse.cs index d1907a1b..1ba381f3 100644 --- a/src/ConfigCatClient/ConfigService/FetchResponse.cs +++ b/src/ConfigCatClient/ConfigService/FetchResponse.cs @@ -1,4 +1,7 @@ +using System.Linq; using System.Net; +using System.Net.Http; +using System.Net.Http.Headers; namespace ConfigCat.Client; @@ -7,17 +10,27 @@ namespace ConfigCat.Client; /// public readonly struct FetchResponse { - /// - /// Initializes a new instance of the struct. - /// - 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; } + /// + /// Initializes a new instance of the struct. + /// + public FetchResponse(HttpStatusCode statusCode, string? reasonPhrase, string? eTag, string? body) + : this(statusCode, reasonPhrase, (object?)eTag, body) { } + /// /// The HTTP status code. /// @@ -31,7 +44,9 @@ public FetchResponse(HttpStatusCode statusCode, string? reasonPhrase, string? eT /// /// The value of the ETag HTTP response header. /// - 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; /// /// The response body. diff --git a/src/ConfigCatClient/ConfigService/HttpClientConfigFetcher.cs b/src/ConfigCatClient/ConfigService/HttpClientConfigFetcher.cs index 546d6bf3..517f0883 100644 --- a/src/ConfigCatClient/ConfigService/HttpClientConfigFetcher.cs +++ b/src/ConfigCatClient/ConfigService/HttpClientConfigFetcher.cs @@ -90,11 +90,11 @@ public async Task 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; diff --git a/src/ConfigCatClient/Logging/LogMessages.cs b/src/ConfigCatClient/Logging/LogMessages.cs index 433e40fb..12a6fbdb 100644 --- a/src/ConfigCatClient/Logging/LogMessages.cs +++ b/src/ConfigCatClient/Logging/LogMessages.cs @@ -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, @@ -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, @@ -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"; }