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

• 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

[thomasheartman]

@nathanmascitelli Thanks for another improvement PR. This looks like a good change to me, but I'd like to have @daveleek have a look at it as well, just to make sure.

As for src/Unleash/LibLog.cs, that looks like a very elegant simplification made. Nice work 🙌🏼

[daveleek]

Great work @nathanmascitelli, this looks good! As much as I like the simplification changes to LibLog, it's an Open Source framework we've embedded and bundled. So we'll have some discussions around that part internally. Did these changes have any impact on the performance aspects of this PR? Or could we split this PR in two?

[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!

[daveleek]

Thank you @nathanmascitelli, good to have the public API back. I have a question around a LIBLOG_PORTABLE check here, but apart from that this looks good!

[daveleek]

Why should we check PORTABLE here?

[nathanmascitelli]

@daveleek the function WrapLogSafeInternal is only used on line 684 which is also behind a PORTABLE check. I wanted to make sure that this function wasn't used by the client itself as it adds allocations. It makes sense in the context where a callback is passed from the user of the unleash client and we want to protect the client but it doesn't make sense for use by the client itself IMO.

Does that make sense?

[daveleek]

Ok fair enough. Doesn't look like it changes any behavior and it's an internal method so shouldn't be implemented/consumed by anyone outside Unleash. Yeah that should be fine @nathanmascitelli! Thanks