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.

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

chore: Use logging source generators #189

Merged
merged 2 commits into from
Apr 9, 2024

Conversation

austindrenski
Copy link
Member

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:

@austindrenski austindrenski requested a review from a team as a code owner January 17, 2024 17:45
<MicrosoftSourceLinkGitHubPkgVer>[1.0.0,2.0)</MicrosoftSourceLinkGitHubPkgVer>
</PropertyGroup>

<ItemGroup>
<PackageReference Include="System.Collections.Immutable" Version="[1.7.1,)" />
<PackageReference Include="System.Threading.Channels" Version="[6.0.0,)" />
<PackageReference Include="System.ValueTuple" Version="[4.5.0,)" Condition="'$(TargetFramework)' == 'net462'" />
Copy link
Member Author

Choose a reason for hiding this comment

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

This is actually an interesting side-effect of bumping the MELA dependency.

Our original (ancient) MELA dependency resolves to 2.0.2 which only includes a target for netstandard2.0, whereas starting with version 6.0.0, MELA provided targets for net461, netstandard2.0, and net6.0. This continued into the 7.x series with targets for net462, netstandard2.0, net6.0, and net7.0, as well as into the 8.x series with targets for net462, netstandard2.0, net6.0, net7.0, and net8.0.

So by bumping to a modern MELA, our transitive reference to System.ValueTuple via the netstandard2.0 reference was lost, thus requiring us to take a direct dependency on System.ValueTuple.

Now it's been a minute since I had to deal with this in a real app, but when I last encountered this^ in the wild, IIRC, you always end up with a System.ValueTuple dependency somewhere in the graph, so if you were skirting it before with a faux target of net462 -> netstandard2.0, you still needed the impl bits from System.ValueTuple available by run-time, else chaos ensued.


public EventExecutor()
{
this.Logger = new Logger<EventExecutor>(new NullLoggerFactory());
this._logger = NullLogger<EventExecutor>.Instance;
Copy link
Member Author

Choose a reason for hiding this comment

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

This is effectively the same thing, but (1) it saves two allocations (albeit insignificant ones), (2) its the common/recommended pattern, and (3) its sometimes nice to be able to drop a breakpoint inside NullLogger<T> and catch callers to it, so this makes it a little more obvious what's happening in those cases.

this._logger = logger ?? new Logger<Api>(new NullLoggerFactory());
this._logger = logger ?? NullLogger<FeatureClient>.Instance;
Copy link
Member Author

Choose a reason for hiding this comment

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

Note the logger name/category change here. It doesn't actually matter for the no-op logger, but prestaging the change while I'm at it because this will matter in the post-#181 world because when #181 registers IFeatureClient it injects a named logger similar to how HttpClient loggers work so that consumer apps can exercise granular control over logging sources.

builder.Services.TryAddKeyedSingleton(providerName, static (services, providerName) => providerName switch
{
null => services.GetRequiredService<ILogger<FeatureClient>>(),
not null => services.GetRequiredService<ILoggerFactory>().CreateLogger($"OpenFeature.FeatureClient.{providerName}")
});

Such that a consumer app could do something like this in their appsettings.json to vary the minimum log levels by provider:

{
  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "OpenFeature": "Information",
      "OpenFeature.FeatureClient": "Warning",
      "OpenFeature.FeatureClient.No-op Provider": "Warning",
      "OpenFeature.FeatureClient.flagd Provider": "Information",
    }
  }
}

Comment on lines -183 to +182
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);
Copy link
Member Author

Choose a reason for hiding this comment

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

This call still happens, but the arg type is an internal type (e.g. LoggerMessage.LogValues<T>) which makes call checking a little peevish since we can't reference the type, so opted to change this to just check that we made it to the IsEnabled(...) check.

If there are any strong feelings about this, I can hack together something closer to the original assertion using reflection, just let me know.

For reference, here's a snippet of what the source generator emits at compile-time:

// <auto-generated/>
#nullable enable

namespace OpenFeature
{
    partial class FeatureClient
    {
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "8.0.9.3103")]
        private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __FlagEvaluationErrorCallback =
            global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Error, new global::Microsoft.Extensions.Logging.EventId(101, nameof(FlagEvaluationError)), "Error while evaluating flag {FlagKey}", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "8.0.9.3103")]
        partial void FlagEvaluationError(global::System.String flagKey, global::System.Exception exception)
        {
            if (_logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Error))
            {
                __FlagEvaluationErrorCallback(_logger, flagKey, exception);
            }
        }
    }
}

Signed-off-by: Austin Drenski <austin@austindrenski.io>
Copy link

codecov bot commented Jan 19, 2024

Codecov Report

Attention: Patch coverage is 72.72727% with 3 lines in your changes are missing coverage. Please review.

Project coverage is 94.20%. Comparing base (e654222) to head (a45f8cf).
Report is 1 commits behind head on main.

❗ Current head a45f8cf differs from pull request most recent head 160dbb9. Consider uploading reports for the commit 160dbb9 to get more accurate results

Files Patch % Lines
src/OpenFeature/Api.cs 0.00% 1 Missing ⚠️
src/OpenFeature/EventExecutor.cs 75.00% 1 Missing ⚠️
src/OpenFeature/OpenFeatureClient.cs 83.33% 1 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #189      +/-   ##
==========================================
- Coverage   95.50%   94.20%   -1.31%     
==========================================
  Files          27       23       -4     
  Lines        1113      949     -164     
  Branches      120       99      -21     
==========================================
- Hits         1063      894     -169     
  Misses         33       33              
- Partials       17       22       +5     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

@askpt askpt mentioned this pull request Jan 30, 2024
Copy link
Member

@benjiro benjiro left a comment

Choose a reason for hiding this comment

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

I'm fine with pushing forward bumping to the latest of anything in Microsoft.Extensions they all have great TFM now. I find of late a lot of libraries are taking this approach.

@askpt askpt added this to the 2.0 (breaking) milestone Apr 8, 2024
@beeme1mr beeme1mr requested review from askpt and toddbaert April 8, 2024 17:42
Signed-off-by: André Silva <2493377+askpt@users.noreply.github.com>
@beeme1mr beeme1mr merged commit d70e27f into open-feature:main Apr 9, 2024
9 of 11 checks passed
askpt added a commit that referenced this pull request Apr 11, 2024
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 <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: André Silva <2493377+askpt@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants