From ea2b393ada004fa49dc746f79810fd12818efbbe Mon Sep 17 00:00:00 2001 From: Kyle Julian <38759683+kylejuliandev@users.noreply.github.com> Date: Thu, 9 Jan 2025 20:56:51 +0000 Subject: [PATCH] Add unit tests to cover new LoggingHook Signed-off-by: Kyle Julian <38759683+kylejuliandev@users.noreply.github.com> --- Directory.Packages.props | 1 + src/OpenFeature/Hooks/LoggingHook.cs | 11 +- .../Hooks/LoggingHookTests.cs | 503 ++++++++++++++++++ .../OpenFeature.Tests.csproj | 3 +- 4 files changed, 514 insertions(+), 4 deletions(-) create mode 100644 test/OpenFeature.Tests/Hooks/LoggingHookTests.cs diff --git a/Directory.Packages.props b/Directory.Packages.props index ab69e552..e83d449a 100644 --- a/Directory.Packages.props +++ b/Directory.Packages.props @@ -23,6 +23,7 @@ + diff --git a/src/OpenFeature/Hooks/LoggingHook.cs b/src/OpenFeature/Hooks/LoggingHook.cs index 0a78e5fe..92b9d824 100644 --- a/src/OpenFeature/Hooks/LoggingHook.cs +++ b/src/OpenFeature/Hooks/LoggingHook.cs @@ -22,6 +22,8 @@ public sealed partial class LoggingHook : Hook /// public LoggingHook(ILogger logger, bool includeContext = false) { + if (logger == null) throw new ArgumentNullException(nameof(logger)); + this._logger = logger; this._includeContext = includeContext; } @@ -78,19 +80,16 @@ public override ValueTask AfterAsync(HookContext context, FlagEvaluationDe } [LoggerMessage( - EventId = 0, Level = LogLevel.Debug, Message = "Before Flag Evaluation {Content}")] partial void HookBeforeStageExecuted(LoggingHookContent content); [LoggerMessage( - EventId = 0, Level = LogLevel.Error, Message = "Error during Flag Evaluation {Content}")] partial void HookErrorStageExecuted(LoggingHookContent content); [LoggerMessage( - EventId = 0, Level = LogLevel.Debug, Message = "After Flag Evaluation {Content}")] partial void HookAfterStageExecuted(LoggingHookContent content); @@ -166,6 +165,12 @@ public override string ToString() if (value.IsBoolean) return value.AsBoolean.ToString(); + if (value.IsNumber) + { + if (value.AsDouble != null) return value.AsDouble.ToString(); + if (value.AsInteger != null) return value.AsInteger.ToString(); + } + if (value.IsDateTime) return value.AsDateTime?.ToString("O"); diff --git a/test/OpenFeature.Tests/Hooks/LoggingHookTests.cs b/test/OpenFeature.Tests/Hooks/LoggingHookTests.cs new file mode 100644 index 00000000..f1b00adc --- /dev/null +++ b/test/OpenFeature.Tests/Hooks/LoggingHookTests.cs @@ -0,0 +1,503 @@ +using System; +using System.Threading.Tasks; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Testing; +using OpenFeature.Constant; +using OpenFeature.Hooks; +using OpenFeature.Model; +using Xunit; + +namespace OpenFeature.Tests.Hooks; + +public class LoggingHookTests +{ + [Fact] + public async Task BeforeAsync_Without_EvaluationContext_Generates_Debug_Log() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var hook = new LoggingHook(logger, includeContext: false); + + // Act + await hook.BeforeAsync(context); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + + Assert.Equal(LogLevel.Debug, record.Level); + Assert.Equal( + """ + Before Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + + """, + record.Message); + } + + [Fact] + public async Task BeforeAsync_Without_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var hook = new LoggingHook(logger, includeContext: false); + + // Act + await hook.BeforeAsync(context); + + // Assert + var record = logger.LatestRecord; + + Assert.Equal( + """ + Before Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + + """, + record.Message); + } + + [Fact] + public async Task BeforeAsync_With_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var evaluationContext = EvaluationContext.Builder() + .Set("key_1", "value") + .Set("key_2", false) + .Set("key_3", 1.531) + .Set("key_4", 42) + .Set("key_5", DateTime.Parse("2025-01-01T11:00:00.0000000Z")) + .Build(); + + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, evaluationContext); + + var hook = new LoggingHook(logger, includeContext: true); + + // Act + await hook.BeforeAsync(context); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + Assert.Equal(LogLevel.Debug, record.Level); + + Assert.Contains( + """ + Before Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + Context: + """, + record.Message); + Assert.Multiple( + () => Assert.Contains("key_1:value", record.Message), + () => Assert.Contains("key_2:False", record.Message), + () => Assert.Contains("key_3:1.531", record.Message), + () => Assert.Contains("key_4:42", record.Message), + () => Assert.Contains("key_5:2025-01-01T11:00:00.0000000+00:00", record.Message) + ); + } + + [Fact] + public async Task BeforeAsync_With_No_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + // Act + var hook = new LoggingHook(logger, includeContext: true); + + await hook.BeforeAsync(context); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + Assert.Equal(LogLevel.Debug, record.Level); + + Assert.Equal( + """ + Before Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + Context: + + """, + record.Message); + } + + [Fact] + public async Task ErrorAsync_Without_EvaluationContext_Generates_Error_Log() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var hook = new LoggingHook(logger, includeContext: false); + + var exception = new Exception("Error within hook!"); + + // Act + await hook.ErrorAsync(context, exception); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + + Assert.Equal(LogLevel.Error, record.Level); + } + + [Fact] + public async Task ErrorAsync_Without_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var hook = new LoggingHook(logger, includeContext: false); + + var exception = new Exception("Error within hook!"); + + // Act + await hook.ErrorAsync(context, exception); + + // Assert + var record = logger.LatestRecord; + + Assert.Equal( + """ + Error during Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + + """, + record.Message); + } + + [Fact] + public async Task ErrorAsync_With_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var evaluationContext = EvaluationContext.Builder() + .Set("key_1", " ") + .Set("key_2", true) + .Set("key_3", 0.002154) + .Set("key_4", -15) + .Set("key_5", DateTime.Parse("2099-01-01T01:00:00.0000000Z")) + .Build(); + + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, evaluationContext); + + var hook = new LoggingHook(logger, includeContext: true); + + var exception = new Exception("Error within hook!"); + + // Act + await hook.ErrorAsync(context, exception); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + Assert.Equal(LogLevel.Error, record.Level); + + Assert.Contains( + """ + Error during Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + Context: + """, + record.Message); + Assert.Multiple( + () => Assert.Contains("key_1: ", record.Message), + () => Assert.Contains("key_2:True", record.Message), + () => Assert.Contains("key_3:0.002154", record.Message), + () => Assert.Contains("key_4:-15", record.Message), + () => Assert.Contains("key_5:2099-01-01T01:00:00.0000000+00:00", record.Message) + ); + } + + [Fact] + public async Task ErrorAsync_With_No_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var hook = new LoggingHook(logger, includeContext: true); + + var exception = new Exception("Error within hook!"); + + // Act + await hook.ErrorAsync(context, exception); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + Assert.Equal(LogLevel.Error, record.Level); + + Assert.Equal( + """ + Error during Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + Context: + + """, + record.Message); + } + + [Fact] + public async Task AfterAsync_Without_EvaluationContext_Generates_Debug_Log() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var details = new FlagEvaluationDetails("test", true, ErrorType.None, reason: null, variant: null); + + var hook = new LoggingHook(logger, includeContext: false); + + // Act + await hook.AfterAsync(context, details); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + Assert.Equal(LogLevel.Debug, record.Level); + } + + [Fact] + public async Task AfterAsync_Without_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var details = new FlagEvaluationDetails("test", true, ErrorType.None, reason: null, variant: null); + + var hook = new LoggingHook(logger, includeContext: false); + + // Act + await hook.AfterAsync(context, details); + + // Assert + var record = logger.LatestRecord; + + Assert.Equal( + """ + After Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + + """, + record.Message); + } + + [Fact] + public async Task AfterAsync_With_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var evaluationContext = EvaluationContext.Builder() + .Set("key_1", "") + .Set("key_2", false) + .Set("key_3", double.MinValue) + .Set("key_4", int.MaxValue) + .Set("key_5", DateTime.MinValue) + .Build(); + + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, evaluationContext); + + var details = new FlagEvaluationDetails("test", true, ErrorType.None, reason: null, variant: null); + + var hook = new LoggingHook(logger, includeContext: true); + + // Act + await hook.AfterAsync(context, details); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + Assert.Equal(LogLevel.Debug, record.Level); + + Assert.Contains( + """ + After Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + Context: + """, + record.Message); + + // .NET Framework uses G15 formatter on double.ToString + // .NET uses G17 formatter on double.ToString +#if NET462 + var expectedMaxDoubleString = "-1.79769313486232E+308"; +#else + var expectedMaxDoubleString = "-1.7976931348623157E+308"; +#endif + Assert.Multiple( + () => Assert.Contains("key_1:", record.Message), + () => Assert.Contains("key_2:False", record.Message), + () => Assert.Contains($"key_3:{expectedMaxDoubleString}", record.Message), + () => Assert.Contains("key_4:2147483647", record.Message), + () => Assert.Contains("key_5:0001-01-01T00:00:00.0000000", record.Message) + ); + } + + [Fact] + public async Task AfterAsync_With_No_EvaluationContext_Generates_Correct_Log_Message() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, EvaluationContext.Empty); + + var details = new FlagEvaluationDetails("test", true, ErrorType.None, reason: null, variant: null); + + var hook = new LoggingHook(logger, includeContext: true); + + // Act + await hook.AfterAsync(context, details); + + // Assert + Assert.Equal(1, logger.Collector.Count); + + var record = logger.LatestRecord; + Assert.Equal(LogLevel.Debug, record.Level); + + Assert.Equal( + """ + After Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + Context: + + """, + record.Message); + } + + [Fact] + public void Create_LoggingHook_Without_Logger() + { + Assert.Throws(() => new LoggingHook(null!, includeContext: true)); + } + + [Fact] + public async Task With_Structure_Type_In_Context_Returns_Qualified_Name_Of_Value() + { + // Arrange + var logger = new FakeLogger(); + + var clientMetadata = new ClientMetadata("client", "1.0.0"); + var providerMetadata = new Metadata("provider"); + var evaluationContext = EvaluationContext.Builder() + .Set("key_1", Structure.Builder().Set("inner_key_1", false).Build()) + .Build(); + + var context = new HookContext("test", false, FlagValueType.Object, clientMetadata, + providerMetadata, evaluationContext); + + var details = new FlagEvaluationDetails("test", true, ErrorType.None, reason: null, variant: null); + + var hook = new LoggingHook(logger, includeContext: true); + + // Act + await hook.AfterAsync(context, details); + + // Assert + var record = logger.LatestRecord; + + // Raw string literals will convert tab to spaces (the File index style) + var tabSize = 4; + var message = record.Message.Replace("\t", new string(' ', tabSize)); + + Assert.Equal( + """ + After Flag Evaluation Domain:client + ProviderName:provider + FlagKey:test + DefaultValue:False + Context: + key_1:OpenFeature.Model.Value + + """, + message + ); + } +} diff --git a/test/OpenFeature.Tests/OpenFeature.Tests.csproj b/test/OpenFeature.Tests/OpenFeature.Tests.csproj index 4df0c681..270b6a50 100644 --- a/test/OpenFeature.Tests/OpenFeature.Tests.csproj +++ b/test/OpenFeature.Tests/OpenFeature.Tests.csproj @@ -1,4 +1,4 @@ - + net8.0;net9.0 @@ -17,6 +17,7 @@ runtime; build; native; contentfiles; analyzers; buildtransitive +