chore: Use logging source generators (open-feature#189)

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 open-feature#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 open-feature#188, then I'll update open-feature#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 <austin@austindrenski.io> Signed-off-by: André Silva <2493377+askpt@users.noreply.github.com> Co-authored-by: André Silva <2493377+askpt@users.noreply.github.com> Signed-off-by: Artyom Tonoyan <artonoyan@servicetitan.com>
arttonoyan · Nov 17, 2024 · 78a9820 · 78a9820
1 parent 7c1cb80
commit 78a9820
Show file tree

Hide file tree

Showing 6 changed files with 36 additions and 22 deletions.
diff --git a/Directory.Packages.props b/Directory.Packages.props
@@ -6,9 +6,10 @@
 
   <ItemGroup Label="src">
     <PackageVersion Include="Microsoft.Bcl.AsyncInterfaces" Version="8.0.0" />
-    <PackageVersion Include="Microsoft.Extensions.Logging.Abstractions" Version="2.0.0" />
+    <PackageVersion Include="Microsoft.Extensions.Logging.Abstractions" Version="8.0.0" />
     <PackageVersion Include="System.Collections.Immutable" Version="1.7.1" />
     <PackageVersion Include="System.Threading.Channels" Version="6.0.0" />
+    <PackageVersion Include="System.ValueTuple" Version="4.5.0" />
   </ItemGroup>
 
   <ItemGroup Label="test">

diff --git a/build/Common.props b/build/Common.props
@@ -22,6 +22,7 @@
   <ItemGroup>
     <PackageReference Include="System.Collections.Immutable" Condition="'$(TargetFramework)' == 'net462' or '$(TargetFramework)' == 'netstandard2.0'" />
     <PackageReference Include="System.Threading.Channels" Condition="'$(TargetFramework)' == 'net462' or '$(TargetFramework)' == 'netstandard2.0'" />
+    <PackageReference Include="System.ValueTuple" Condition="'$(TargetFramework)' == 'net462'" />
   </ItemGroup>
 
   <ItemGroup Condition="'$(OS)' == 'Unix'">

diff --git a/src/OpenFeature/Api.cs b/src/OpenFeature/Api.cs
@@ -280,7 +280,7 @@ public void RemoveHandler(ProviderEventTypes type, EventHandlerDelegate handler)
         /// <param name="logger">The logger to be used</param>
         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
@@ -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<object> EventChannel = Channel.CreateBounded<object>(1);
@@ -21,17 +21,19 @@ internal class EventExecutor : IAsyncDisposable
         private readonly Dictionary<ProviderEventTypes, List<EventHandlerDelegate>> _apiHandlers = new Dictionary<ProviderEventTypes, List<EventHandlerDelegate>>();
         private readonly Dictionary<string, Dictionary<ProviderEventTypes, List<EventHandlerDelegate>>> _clientHandlers = new Dictionary<string, Dictionary<ProviderEventTypes, List<EventHandlerDelegate>>>();
 
-        internal ILogger Logger { get; set; }
+        private ILogger _logger;
 
         public EventExecutor()
         {
-            this.Logger = new Logger<EventExecutor>(new NullLoggerFactory());
+            this._logger = NullLogger<EventExecutor>.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
@@ -15,7 +15,7 @@ namespace OpenFeature
     /// <summary>
     ///
     /// </summary>
-    public sealed class FeatureClient : IFeatureClient
+    public sealed partial class FeatureClient : IFeatureClient
     {
         private readonly ClientMetadata _metadata;
         private readonly ConcurrentStack<Hook> _hooks = new ConcurrentStack<Hook>();
@@ -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<Api>(new NullLoggerFactory());
+            this._logger = logger ?? NullLogger<FeatureClient>.Instance;
             this._evaluationContext = context ?? EvaluationContext.Empty;
         }
 
@@ -252,15 +252,14 @@ private async Task<FlagEvaluationDetails<T>> EvaluateFlag<T>(
             }
             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<T>(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<T>(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<HookContext<T>> TriggerBeforeHooks<T>(IReadOnlyList<Hook> 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<T>(IReadOnlyList<Hook> hooks, HookContext<T
                 }
                 catch (Exception e)
                 {
-                    this._logger.LogError(e, "Error while executing Error hook {HookName}", hook.GetType().Name);
+                    this.ErrorHookError(hook.GetType().Name, e);
                 }
             }
         }
@@ -337,5 +335,20 @@ private async Task TriggerFinallyHooks<T>(IReadOnlyList<Hook> 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
@@ -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<EvaluationContext>());
 
-            mockedLogger.Received(1).Log(
-                LogLevel.Error,
-                Arg.Any<EventId>(),
-                Arg.Is<FormattedLogValues>(t => string.Equals($"Error while evaluating flag {flagName}", t.ToString(), StringComparison.InvariantCultureIgnoreCase)),
-                Arg.Any<Exception>(),
-                Arg.Any<Func<object, Exception, string>>());
+            mockedLogger.Received(1).IsEnabled(LogLevel.Error);
         }
 
         [Fact]