From d70e27f387d12cf17ef7313ab1aaba0c6c8b7452 Mon Sep 17 00:00:00 2001 From: Austin Drenski Date: Tue, 9 Apr 2024 17:27:10 -0400 Subject: [PATCH] chore: Use logging source generators (#189) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This PR updates `OpenFeature` to use the latest MELA source generators to produce compile-time logging delegates. The most obvious critique of this PR is likely to be that, much like #188, this PR changes the dependency graph by bumping our MELA dependency from `[2.0.0,) => [8.0.0,)`. To that^ critique, I continue to contend that depending on an ancient version of MELA is unlikely to aid many real-world consumers of this SDK, since new versions of MELA provide robust TFM coverage, as well as my personal disbelief that anyone looking to consume this library in 2024 is deploying an app that won't already have transitively referenced MELA `8.0.0` somewhere in its package graph. _(If you are a user or potential user of this SDK and have a real-world use case of a legacy app that __does not and cannot__ reference MELA `>= 8.0.0`, please ping back here! Would love to hear from you and adjust my disbelief accordingly!)_ _(Note: if this PR lands before #188, then I'll update #188 to remove its added dependency on `Microsoft.Bcl.AsyncInterfaces`, since it flows transitively from MELA `8.0.0`.)_ Upon request, I am happy to provide a soapbox diatribe on why I think we should care about source generators, hook perf, and incidental logging allocations, especially as an SDK that wants to be trusted and baked into all kinds of consumer apps, but eliding that for now in favor of some docs refs: - https://learn.microsoft.com/dotnet/core/extensions/high-performance-logging - https://learn.microsoft.com/dotnet/core/extensions/logger-message-generator Signed-off-by: Austin Drenski Signed-off-by: André Silva <2493377+askpt@users.noreply.github.com> Co-authored-by: André Silva <2493377+askpt@users.noreply.github.com> --- Directory.Packages.props | 3 +- build/Common.props | 1 + src/OpenFeature/Api.cs | 2 +- src/OpenFeature/EventExecutor.cs | 15 ++++++---- src/OpenFeature/OpenFeatureClient.cs | 29 ++++++++++++++----- .../OpenFeatureClientTests.cs | 8 +---- 6 files changed, 36 insertions(+), 22 deletions(-) diff --git a/Directory.Packages.props b/Directory.Packages.props index b57473e4..9b67b6aa 100644 --- a/Directory.Packages.props +++ b/Directory.Packages.props @@ -6,9 +6,10 @@ - + + diff --git a/build/Common.props b/build/Common.props index 9f807b2c..5cc12515 100644 --- a/build/Common.props +++ b/build/Common.props @@ -22,6 +22,7 @@ + diff --git a/src/OpenFeature/Api.cs b/src/OpenFeature/Api.cs index 6dc0f863..fbafa695 100644 --- a/src/OpenFeature/Api.cs +++ b/src/OpenFeature/Api.cs @@ -280,7 +280,7 @@ public void RemoveHandler(ProviderEventTypes type, EventHandlerDelegate handler) /// The logger to be used public void SetLogger(ILogger logger) { - this._eventExecutor.Logger = logger; + this._eventExecutor.SetLogger(logger); } internal void AddClientHandler(string client, ProviderEventTypes eventType, EventHandlerDelegate handler) diff --git a/src/OpenFeature/EventExecutor.cs b/src/OpenFeature/EventExecutor.cs index a80c92d4..816bf13e 100644 --- a/src/OpenFeature/EventExecutor.cs +++ b/src/OpenFeature/EventExecutor.cs @@ -10,7 +10,7 @@ namespace OpenFeature { - internal class EventExecutor : IAsyncDisposable + internal sealed partial class EventExecutor : IAsyncDisposable { private readonly object _lockObj = new object(); public readonly Channel EventChannel = Channel.CreateBounded(1); @@ -21,17 +21,19 @@ internal class EventExecutor : IAsyncDisposable private readonly Dictionary> _apiHandlers = new Dictionary>(); private readonly Dictionary>> _clientHandlers = new Dictionary>>(); - internal ILogger Logger { get; set; } + private ILogger _logger; public EventExecutor() { - this.Logger = new Logger(new NullLoggerFactory()); + this._logger = NullLogger.Instance; var eventProcessing = new Thread(this.ProcessEventAsync); eventProcessing.Start(); } public ValueTask DisposeAsync() => new(this.Shutdown()); + internal void SetLogger(ILogger logger) => this._logger = logger; + internal void AddApiLevelHandler(ProviderEventTypes eventType, EventHandlerDelegate handler) { lock (this._lockObj) @@ -209,7 +211,7 @@ private void EmitOnRegistration(FeatureProvider? provider, ProviderEventTypes ev } catch (Exception exc) { - this.Logger.LogError(exc, "Error running handler"); + this.ErrorRunningHandler(exc); } } } @@ -311,7 +313,7 @@ private void InvokeEventHandler(EventHandlerDelegate eventHandler, Event e) } catch (Exception exc) { - this.Logger.LogError(exc, "Error running handler"); + this.ErrorRunningHandler(exc); } } @@ -321,6 +323,9 @@ public async Task Shutdown() await this.EventChannel.Reader.Completion.ConfigureAwait(false); } + + [LoggerMessage(100, LogLevel.Error, "Error running handler")] + partial void ErrorRunningHandler(Exception exception); } internal class Event diff --git a/src/OpenFeature/OpenFeatureClient.cs b/src/OpenFeature/OpenFeatureClient.cs index 77cd8754..6145094e 100644 --- a/src/OpenFeature/OpenFeatureClient.cs +++ b/src/OpenFeature/OpenFeatureClient.cs @@ -15,7 +15,7 @@ namespace OpenFeature /// /// /// - public sealed class FeatureClient : IFeatureClient + public sealed partial class FeatureClient : IFeatureClient { private readonly ClientMetadata _metadata; private readonly ConcurrentStack _hooks = new ConcurrentStack(); @@ -76,7 +76,7 @@ public void SetContext(EvaluationContext? context) public FeatureClient(string? name, string? version, ILogger? logger = null, EvaluationContext? context = null) { this._metadata = new ClientMetadata(name, version); - this._logger = logger ?? new Logger(new NullLoggerFactory()); + this._logger = logger ?? NullLogger.Instance; this._evaluationContext = context ?? EvaluationContext.Empty; } @@ -252,15 +252,14 @@ private async Task> EvaluateFlag( } catch (FeatureProviderException ex) { - this._logger.LogError(ex, "Error while evaluating flag {FlagKey}. Error {ErrorType}", flagKey, - ex.ErrorType.GetDescription()); + this.FlagEvaluationErrorWithDescription(flagKey, ex.ErrorType.GetDescription(), ex); evaluation = new FlagEvaluationDetails(flagKey, defaultValue, ex.ErrorType, Reason.Error, string.Empty, ex.Message); await this.TriggerErrorHooks(allHooksReversed, hookContext, ex, options).ConfigureAwait(false); } catch (Exception ex) { - this._logger.LogError(ex, "Error while evaluating flag {FlagKey}", flagKey); + this.FlagEvaluationError(flagKey, ex); var errorCode = ex is InvalidCastException ? ErrorType.TypeMismatch : ErrorType.General; evaluation = new FlagEvaluationDetails(flagKey, defaultValue, errorCode, Reason.Error, string.Empty, ex.Message); await this.TriggerErrorHooks(allHooksReversed, hookContext, ex, options).ConfigureAwait(false); @@ -289,8 +288,7 @@ private async Task> TriggerBeforeHooks(IReadOnlyList hoo } else { - this._logger.LogDebug("Hook {HookName} returned null, nothing to merge back into context", - hook.GetType().Name); + this.HookReturnedNull(hook.GetType().Name); } } @@ -317,7 +315,7 @@ private async Task TriggerErrorHooks(IReadOnlyList hooks, HookContext(IReadOnlyList hooks, HookContext } } } + + [LoggerMessage(100, LogLevel.Debug, "Hook {HookName} returned null, nothing to merge back into context")] + partial void HookReturnedNull(string hookName); + + [LoggerMessage(101, LogLevel.Error, "Error while evaluating flag {FlagKey}")] + partial void FlagEvaluationError(string flagKey, Exception exception); + + [LoggerMessage(102, LogLevel.Error, "Error while evaluating flag {FlagKey}: {ErrorType}")] + partial void FlagEvaluationErrorWithDescription(string flagKey, string errorType, Exception exception); + + [LoggerMessage(103, LogLevel.Error, "Error while executing Error hook {HookName}")] + partial void ErrorHookError(string hookName, Exception exception); + + [LoggerMessage(104, LogLevel.Error, "Error while executing Finally hook {HookName}")] + partial void FinallyHookError(string hookName, Exception exception); } } diff --git a/test/OpenFeature.Tests/OpenFeatureClientTests.cs b/test/OpenFeature.Tests/OpenFeatureClientTests.cs index 9509eb8a..7c656cec 100644 --- a/test/OpenFeature.Tests/OpenFeatureClientTests.cs +++ b/test/OpenFeature.Tests/OpenFeatureClientTests.cs @@ -6,7 +6,6 @@ using AutoFixture; using FluentAssertions; using Microsoft.Extensions.Logging; -using Microsoft.Extensions.Logging.Internal; using NSubstitute; using NSubstitute.ExceptionExtensions; using OpenFeature.Constant; @@ -182,12 +181,7 @@ public async Task OpenFeatureClient_Should_Return_DefaultValue_When_Type_Mismatc _ = mockedFeatureProvider.Received(1).ResolveStructureValue(flagName, defaultValue, Arg.Any()); - mockedLogger.Received(1).Log( - LogLevel.Error, - Arg.Any(), - Arg.Is(t => string.Equals($"Error while evaluating flag {flagName}", t.ToString(), StringComparison.InvariantCultureIgnoreCase)), - Arg.Any(), - Arg.Any>()); + mockedLogger.Received(1).IsEnabled(LogLevel.Error); } [Fact]