Logger Improvements

[nathanmascitelli]

Description

A high number of string allocations were found to come from DefaultUnleash.DetermineIsEnabledAndStrategy:

I believe this is due to the logging that's done if the toggle isn't available:

This will always allocate a string even if logging is disabled (or log level Warning is disabled). We should instead be passing a Func<string> which is a smaller allocation that will only get evaluated if logging is on.

Also, in looking at this I noticed there was inconsistant checking if a log level was enabled in LogExtensions so I will clean that up as well.

Type of change

• [x] Bug fix (non-breaking change which fixes an issue)

How Has This Been Tested?

Using the following benchmark (note IsEnabled2 has my changes):

[MemoryDiagnoser]
public class Benchmark
{
    readonly UnleashContext context = new();
    readonly DefaultUnleash client = new(new UnleashSettings());

    public Benchmark()
    {
    }

    [Benchmark(Baseline = true)]
    public bool Current() => client.IsEnabled("Moo", context);

    [Benchmark]
    public bool New() => client.IsEnabled2("Moo", context);
}

The following results were obtained:	Method	Mean	Error	StdDev	Ratio	Gen0	Allocated	Alloc Ratio
Current	179.3 ns	1.80 ns	1.69 ns	1.00	0.0408	512 B	1.00
New	105.2 ns	1.00 ns	0.94 ns	0.58	0.0254	320 B	0.63

[nathanmascitelli]

@daveleek there are three parts of the changes to LibLog that would have an impact on performance. The first is updating the methods to always check if the log level is enabled before trying to log. So if you look at this method:

public static void Error(this ILog logger, Func<string> messageFunc)
{
    GuardAgainstNullLogger(logger);
    logger.Log(LogLevel.Error, WrapLogInternal(messageFunc));
}

While it checks to see if the logger is null it does not check to see if logging is enabled for LogLevel.Error before logging. This does have a performance impact as the underlying logger implementation may or may not actually log without this check.

The second change is the removal of wrapping the input message functions in WrapLogInternal, as seen in the example above. I was not sure what exactly this was trying to accomplish to be honest, we have a similar logging interface in our application and just pass the message functions around without wrapping.

The final change is the removal of the methods that accept a string instead of Func<string>. Allocating a string will always use more memory then allocating a function if that function is not invoked. Given various log levels may not be invoked.

Other than those things everhting else is athestic. Looking at the compiler directives I'm guessing this is public when the SDK is published? I missed that, I can understand that changing the API interface would be a problem.

How about I revert the interface changes so that the methods that were removed are present if LIBLOG_PUBLIC is true? That way internally to the SDK we can always use functions but if anyone else was using the string methods they would be unaffected?

[daveleek]

While it checks to see if the logger is null it does not check to see if logging is enabled for LogLevel.Error before logging. This does have a performance impact as the underlying logger implementation may or may not actually log without this check.

Yeah I see what you mean. And the string LogFormat overload only checks if logging is enabled for the LogLevel, doesn't guard against null. Interesting quirk, but I'm not familiar with that code.

How about I revert the interface changes so that the methods that were removed are present if LIBLOG_PUBLIC is true? That way internally to the SDK we can always use functions but if anyone else was using the string methods they would be unaffected?

That would be great, we could get that tested and shipped.

Speaking of shipping, could I ask you to take a quick look at the comment I just added to your #187 PR @nathanmascitelli ? Would be nice if we could get that in shape and merged, then we can push a new version :)

[nathanmascitelli]

@daveleek I put the public API back.

[daveleek]

Perfect, thank you, saw the other one as well @nathanmascitelli!