Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add warning level log for failover to new endpoint #431

Merged
merged 22 commits into from
Aug 11, 2023
Merged

Add warning level log for failover to new endpoint #431

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
22 commits
Select commit Hold shift + click to select a range
6e3094e
first draft of failover log
amerjusupovic Jun 16, 2023
f328864
log whenever endpoint has changed after initial call, draft
amerjusupovic Jun 19, 2023
df4b09e
make message wording clearer
amerjusupovic Jun 20, 2023
2226027
add unit test
amerjusupovic Jun 20, 2023
78a1044
add logic to check if endpoint has changed, fix test
amerjusupovic Jun 20, 2023
711f7c9
remove unused using in loghelper
amerjusupovic Jun 20, 2023
45ddf1f
log for every endpoint retry
amerjusupovic Jun 23, 2023
3e37b11
add log when all endpoints failed, remove unnecessary failed boolean
amerjusupovic Jul 21, 2023
cfaefa2
check for all endpoints failed message in tests
amerjusupovic Jul 21, 2023
4d4cbad
change message to last endpoint failed
amerjusupovic Jul 21, 2023
043e07f
remove spaces
amerjusupovic Jul 21, 2023
0acd926
fix period on message
amerjusupovic Jul 21, 2023
bbf4d82
format message again
amerjusupovic Jul 21, 2023
9b98ee4
reuse previousendpoint
amerjusupovic Jul 27, 2023
65777c6
Merge branch 'main' of https://github.com/Azure/AppConfiguration-Dotn…
amerjusupovic Jul 27, 2023
cbbbf9b
Merge branch 'main' of https://github.com/Azure/AppConfiguration-Dotn…
amerjusupovic Jul 27, 2023
7da86cc
Merge branch 'main' into ajusupovic/failover-warning-log
amerjusupovic Aug 2, 2023
566a9fc
Merge branch 'main' into ajusupovic/failover-warning-log
amerjusupovic Aug 2, 2023
99becd7
Merge branch 'main' into ajusupovic/failover-warning-log
amerjusupovic Aug 2, 2023
82f9e12
change log method and constants, move logging to end of while loop
amerjusupovic Aug 3, 2023
ea4e9dc
add null checks for endpoints in loghelper
amerjusupovic Aug 3, 2023
630e241
null checks in provider code
amerjusupovic Aug 10, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 12 additions & 0 deletions ...Microsoft.Extensions.Configuration.AzureAppConfiguration/AzureAppConfigurationProvider.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -826,6 +826,7 @@ private async Task<T> ExecuteWithFailOverPolicyAsync<T>(IEnumerable<Configuratio

clientEnumerator.MoveNext();

Uri previousEndpoint = _configClientManager.GetEndpointForClient(clientEnumerator.Current);
ConfigurationClient currentClient;

while (true)
Expand Down Expand Up @@ -865,6 +866,8 @@ private async Task<T> ExecuteWithFailOverPolicyAsync<T>(IEnumerable<Configuratio
{
if (!success && backoffAllClients)
{
_logger.LogWarning(LogHelper.BuildLastEndpointFailedMessage(previousEndpoint?.ToString()));

do
avanigupta marked this conversation as resolved.
Show resolved Hide resolved
{
_configClientManager.UpdateClientStatus(currentClient, success);
Expand All @@ -878,6 +881,15 @@ private async Task<T> ExecuteWithFailOverPolicyAsync<T>(IEnumerable<Configuratio
_configClientManager.UpdateClientStatus(currentClient, success);
}
}

Uri currentEndpoint = _configClientManager.GetEndpointForClient(clientEnumerator.Current);

if (previousEndpoint != currentEndpoint)
{
_logger.LogWarning(LogHelper.BuildFailoverMessage(previousEndpoint?.ToString(), currentEndpoint?.ToString()));
}

previousEndpoint = currentEndpoint;
}
}

Expand Down
2 changes: 2 additions & 0 deletions src/Microsoft.Extensions.Configuration.AzureAppConfiguration/Constants/LoggingConstants.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -29,5 +29,7 @@ internal class LoggingConstants

// Other
public const string RefreshSkippedNoClientAvailable = "Refresh skipped because no endpoint is accessible.";
public const string RefreshFailedToGetSettingsFromEndpoint = "Failed to get configuration settings from endpoint";
public const string FailingOverToEndpoint = "Failing over to endpoint";
}
}
16 changes: 13 additions & 3 deletions src/Microsoft.Extensions.Configuration.AzureAppConfiguration/LogHelper.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@ internal static class LogHelper
{
public static string BuildKeyValueReadMessage(KeyValueChangeType changeType, string key, string label, string endpoint)
{
return $"{LoggingConstants.RefreshKeyValueRead} Change:'{changeType}' Key:'{key}' Label:'{label}' Endpoint:'{endpoint.TrimEnd('/')}'";
return $"{LoggingConstants.RefreshKeyValueRead} Change:'{changeType}' Key:'{key}' Label:'{label}' Endpoint:'{endpoint?.TrimEnd('/')}'";
}

public static string BuildKeyValueSettingUpdatedMessage(string key)
Expand All @@ -22,12 +22,12 @@ public static string BuildConfigurationUpdatedMessage()

public static string BuildFeatureFlagsUnchangedMessage(string endpoint)
{
return $"{LoggingConstants.RefreshFeatureFlagsUnchanged} Endpoint:'{endpoint.TrimEnd('/')}'";
return $"{LoggingConstants.RefreshFeatureFlagsUnchanged} Endpoint:'{endpoint?.TrimEnd('/')}'";
}

public static string BuildFeatureFlagReadMessage(string key, string label, string endpoint)
{
return $"{LoggingConstants.RefreshFeatureFlagRead} Key:'{key}' Label:'{label}' Endpoint:'{endpoint.TrimEnd('/')}'";
return $"{LoggingConstants.RefreshFeatureFlagRead} Key:'{key}' Label:'{label}' Endpoint:'{endpoint?.TrimEnd('/')}'";
}

public static string BuildFeatureFlagUpdatedMessage(string key)
Expand Down Expand Up @@ -74,5 +74,15 @@ public static string BuildPushNotificationUnregisteredEndpointMessage(string res
{
return $"{LoggingConstants.PushNotificationUnregisteredEndpoint} '{resourceUri}'.";
}

public static string BuildFailoverMessage(string originalEndpoint, string currentEndpoint)
{
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For the message it looks like it's currently

"Failed to get configuration settings from endpoint '{old endpoint}'. Trying to read from endpoint '{new endpoint}'."

I'm thinking to make the fall back clear:

"Failed to get configuration settings from endpoint '{old endpoint}'. Falling back to endpoint '{new endpoint}'."

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's a good idea, can we use "failover" instead of "fallback" though? That's the term we use in public docs too.

"Failed to get configuration settings from endpoint '{old endpoint}'. Initiating automatic failover to endpoint '{new endpoint}'."

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes. "Failing over to endpoint ..."

return $"{LoggingConstants.RefreshFailedToGetSettingsFromEndpoint} '{originalEndpoint?.TrimEnd('/')}'. {LoggingConstants.FailingOverToEndpoint} '{currentEndpoint?.TrimEnd('/')}'.";
}

public static string BuildLastEndpointFailedMessage(string endpoint)
{
return $"{LoggingConstants.RefreshFailedToGetSettingsFromEndpoint} '{endpoint?.TrimEnd('/')}'.";
}
}
}
66 changes: 66 additions & 0 deletions tests/Tests.AzureAppConfiguration/LoggingTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Configuration.AzureAppConfiguration;
using Microsoft.Extensions.Configuration.AzureAppConfiguration.AzureKeyVault;
using Microsoft.Extensions.Configuration.AzureAppConfiguration.Extensions;
using Moq;
using System;
using System.Collections.Generic;
Expand Down Expand Up @@ -289,6 +290,71 @@ public void ValidateOperationCanceledExceptionLoggedDuringRefresh()
Assert.Contains(LoggingConstants.RefreshCanceledError, warningInvocation);
}

[Fact]
public void ValidateFailoverToDifferentEndpointMessageLoggedAfterFailover()
{
IConfigurationRefresher refresher = null;
var mockClient1 = GetMockConfigurationClient();
var mockClient2 = GetMockConfigurationClient();

mockClient1.Setup(c => c.GetConfigurationSettingAsync(It.IsAny<ConfigurationSetting>(), It.IsAny<bool>(), It.IsAny<CancellationToken>()))
.Throws(new RequestFailedException(HttpStatusCodes.TooManyRequests, "Too many requests"));
mockClient1.Setup(c => c.ToString()).Returns("client");
mockClient1.Setup(c => c.Equals(mockClient1)).Returns(true);
mockClient2.Setup(c => c.Equals(mockClient1)).Returns(true);

ConfigurationClientWrapper cw1 = new ConfigurationClientWrapper(TestHelpers.PrimaryConfigStoreEndpoint, mockClient1.Object);
ConfigurationClientWrapper cw2 = new ConfigurationClientWrapper(TestHelpers.SecondaryConfigStoreEndpoint, mockClient2.Object);

var clientList = new List<ConfigurationClientWrapper>() { cw1, cw2 };
var configClientManager = new ConfigurationClientManager(clientList);

string warningInvocation = "";
using var _ = new AzureEventSourceListener(
(args, s) =>
{
if (args.Level == EventLevel.Warning)
{
warningInvocation += s;
}
}, EventLevel.Verbose);

var config = new ConfigurationBuilder()
.AddAzureAppConfiguration(options =>
{
options.ClientManager = configClientManager;
options.ConfigureRefresh(refreshOptions =>
{
refreshOptions.Register("TestKey1", "label")
.SetCacheExpiration(CacheExpirationTime);
});

refresher = options.GetRefresher();
})
.Build();

Assert.Equal("TestValue1", config["TestKey1"]);
FirstKeyValue.Value = "newValue1";

Thread.Sleep(CacheExpirationTime);
refresher.TryRefreshAsync().Wait();

Assert.Equal("newValue1", config["TestKey1"]);
Assert.Contains(LogHelper.BuildFailoverMessage(TestHelpers.PrimaryConfigStoreEndpoint.ToString(), TestHelpers.SecondaryConfigStoreEndpoint.ToString()), warningInvocation);

mockClient2.Setup(c => c.GetConfigurationSettingAsync(It.IsAny<ConfigurationSetting>(), It.IsAny<bool>(), It.IsAny<CancellationToken>()))
.Throws(new RequestFailedException(HttpStatusCodes.TooManyRequests, "Too many requests"));
mockClient2.Setup(c => c.ToString()).Returns("client");

FirstKeyValue.Value = "TestValue1";

Thread.Sleep(CacheExpirationTime);
refresher.TryRefreshAsync().Wait();

Assert.Equal("newValue1", config["TestKey1"]);
Assert.Contains(LogHelper.BuildLastEndpointFailedMessage(TestHelpers.SecondaryConfigStoreEndpoint.ToString()), warningInvocation);
}

[Fact]
public void ValidateConfigurationUpdatedSuccessLoggedDuringRefresh()
{
Expand Down