LogValues structs from LoggerMessage now implement IReadonlyDictionary<string, object>

[Scooletz]

This PR introduces an additional interface implementation for structs used for high-performance logging. The additional interface is IReadonlyDictionary<string, object> which should allow slightly faster querying of the state/scope object by ILogger implementations, especially taking into consideration that Log<TState> is a generic method, and there's some awesome work related to deviritualizing calls to structs implementing interfaces.

Usages

With a change like this, there's potential to replace some allocations in various libraries, without creating specific types (they can be inferred from the parsed format & values) and replacing the allocated dictionaries. For example:

• Azure Functions/Webjobs function executor: https://github.com/Azure/azure-webjobs-sdk/blob/77234d6aef493788cfa25c02467fe31e1db265d6/src/Microsoft.Azure.WebJobs.Host/Executors/FunctionExecutor.cs#L525-L529
• Azure Functions/Webjobs logger extensions: https://github.com/Azure/azure-webjobs-sdk/blob/b798412ad74ba97cf2d85487ae8479f277bdd85c/src/Microsoft.Azure.WebJobs.Host/Loggers/Logger/LoggerExtensions.cs

Benchmarks

To benchmark potential gains I used the following benchmark, trying to compare finding a value via LINQ over IReadOnlyList and a direct access to a dictionary API. Maybe there's a better way, but my assumption is that this is the way one would access it in the implementation.

[Benchmark]
public object ReadonlyList()
{
    return ((IReadOnlyList<KeyValuePair<string, object>>)values).FirstOrDefault(kvp => kvp.Key == Key).Value;
}

[Benchmark]
public object Dictionary()
{
    ((IReadOnlyDictionary<string, object>)values).TryGetValue(Key, out var value);
    return value;
}

BenchmarkDotNet=v0.11.5, OS=Windows 10.0.17134.829 (1803/April2018Update/Redstone4)
Intel Core i7-6700HQ CPU 2.60GHz (Skylake), 1 CPU, 8 logical and 4 physical cores
Frequency=2531248 Hz, Resolution=395.0620 ns, Timer=TSC
.NET Core SDK=2.2.203
  [Host] : .NET Core 2.2.4 (CoreCLR 4.6.27521.02, CoreFX 4.6.27521.01), 64bit RyuJIT
  Core   : .NET Core 2.2.4 (CoreCLR 4.6.27521.02, CoreFX 4.6.27521.01), 64bit RyuJIT

Job=Core  Runtime=Core  

Method	Mean	Error	StdDev	Median
ReadonlyList	92.16 ns	1.9167 ns	4.629 ns	91.18 ns
Dictionary	21.70 ns	0.7151 ns	1.993 ns	21.05 ns

[Scooletz]

If this PR is considered for merging, I'll provide some tests to cover the implementation. Looking forward to hearing from maintainers, is it something they consider for merging.

[analogrelay]

Seems reasonable to me. Thoughts @davidfowl @pakrym @BrennanConroy ?

The implementation looks good to me, as you say we'll need tests before merging. They are supposed to behave like dictionaries, so it seems reasonable to implement the interface.

[pakrym]

I'm not sure about the benefits.

All consumers would still have to stick to using IReadOnlyList<..> because LoggerValues would be the only one implementing IReadOnlyDictionary.
In addition the implementation of TryGetValue is linear scan and doesn't have major performance benefits over iterating IReadOnlyList.

[Scooletz]

Please find my answers below :-) @pakrym

I'm not sure about the motivation

My motivation is even better performance for LoggerMessage use cases for any logger capable and willing to take IReadonlyDictionary into consideration.

all consumers would still have to stick to using IReadOnlyList<..> because LoggerValues would be the only one implementing IReadOnlyDictionary

I could add it to the other structure if needed. My aim was to potentially speak up the high-perf scenario.

The requirement of implementing of IReadOnlyList<...> is not a part of current public seam. Maybe there's some rule in docs for implementing it, but the public seam does not include it:

https://github.com/aspnet/Extensions/blob/aedba48f269e03db2b9a626b9a04aa8bde4bfe72/src/Logging/Logging.Abstractions/src/ILogger.cs#L22

as the Log<TState> is generic, and when it's specified by a value type, it'll be JITted for the specific struct. One could imagine, that in the logger implementations we'd see

if (state is IDictionary<string,object>)
{
  var asDict = (IDictionary<string,object>)state;
}

as their implementors are aware of https://github.com/dotnet/coreclr/issues/14213 and dotnet/coreclr#14698

In addition the implementation of TryGetValue is linear scan and doesn't have major performance benefits over iterating IReadOnlyList.

My benchmarks show something else, as for cases when one would like to retrieve a value, it's likely that with list it'd be implemented as a LINQ call. I've added the results to the initial description of it.

[analogrelay]

I'm actually not too surprised that the IReadOnlyDictionary implementation is a little better. They are both linear scans, but the list one has to go through IEnumerable to yield each individual item the compare them, the dictionary one makes a single interface call to TryGetValue and then the concrete type does a linear scan.

[Scooletz]

I'm just providing data @anurse to questions raised above :-)

[pakrym]

Sure it is slightly slower, if not using LINQ it's around ~40% slower:

|              Method |      Mean |    Error |    StdDev |
|-------------------- |----------:|---------:|----------:|
|        ReadonlyList | 236.51 ns | 4.814 ns | 10.964 ns |
| ReadonlyListForeach | 108.40 ns | 2.222 ns |  2.079 ns |
|          Dictionary |  59.59 ns | 1.297 ns |  2.954 ns |

but no logger ever retrieves a single value, most logger implementations I've seen retrieve all of them or just call the formatter.

One could imagine, that in the logger implementations we'd see

Do you know of an existing logger implementation that would benefit from this change?

@anurse your call here but I don't think this addition solve an existing problem.

[Scooletz]

I see @pakrym . Maybe I should have been clear about the initial motivation of it. So my initial one was code operating on scope and state, checking for loglevel etx in https://github.com/Azure/azure-webjobs-sdk/blob/dev/src/Microsoft.Azure.WebJobs.Logging.ApplicationInsights/ApplicationInsightsLogger.cs but now, when I look through the implementation, it might be not worth it. Especially, as I doesn't use statements prepared with LoggerMessage.

Being given that the initial author of this PR is unsure whether it's worth it 😛 I can close this PR.

[analogrelay]

I guess I'm curious why the category name and log level are in the scope in your example instead of just using the values associated with the log message itself. Plus, you're already merging the scope data into a dictionary (as far as I can tell) so I'm not sure what the benefit is here.

Like I said, it doesn't seem problematic at all, but I do agree with @pakrym that in general a logger wants all the scope data, so the gain from using IReadOnlyDictionary vs just loading the data into a merged dictionary and querying it directly seems relatively minor.

Seems like maybe closing is what we're converging on here.

[Scooletz]

Thanks for chiming in @pakrym @anurse

Closing as described above