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

Fix contention in LoggerFactory.CreateLogger #87904

Merged
merged 1 commit into from
Jun 22, 2023

Conversation

stephentoub
Copy link
Member

@stephentoub stephentoub commented Jun 22, 2023

Some ASP.NET code paths end up calling this a lot, and it takes a lock on every call, even though the vast majority are satisifed by the cache and require no mutation. We can use a ConcurrentDictionary instead of a Dictionary, with double-checked locking. Nothing is ever removed from or overwritten in the dictionary, so there's no problem doing the hot-path read outside of the lock; we still do the mutation inside of the lock so that all of the mutation work is performed atomically and synchronized with the actions from AddProvider and RefreshFilter.

Method Toolchain Mean Ratio
Serial \main\corerun.exe 21.646 ns 1.00
Serial \pr\corerun.exe 8.408 ns 0.39
Parallel \main\corerun.exe 371,691,606.667 ns 1.00
Parallel \pr\corerun.exe 19,181,294.940 ns 0.05
using BenchmarkDotNet.Attributes;
using BenchmarkDotNet.Running;
using Microsoft.Extensions.Logging;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;

[MemoryDiagnoser(false)]
public class Program
{
    static void Main(string[] args) => BenchmarkSwitcher.FromAssembly(typeof(Program).Assembly).Run(args);

    private LoggerFactory _factory = new LoggerFactory();

    [Benchmark]
    public ILogger Serial() => _factory.CreateLogger("test");

    [Benchmark]
    public async Task Parallel()
    {
        var b = new Barrier(12);
        await Task.WhenAll(from i in Enumerable.Range(0, b.ParticipantCount)
                           select Task.Run(() =>
                           {
                               b.SignalAndWait();
                               for (int j = 0; j < 1_000_000; j++)
                               {
                                   _factory.CreateLogger("test");
                               }
                           }));
    }
}

Fixes #83609

Some ASP.NET code paths end up calling this _a lot_, and it takes a lock on every call, even though the vast majority are satisifed by the cache and require no mutation.  We can use a ConcurrentDictionary instead of a Dictionary, with double-checked locking.  Nothing is ever removed from or overwritten in the dictionary, so there's no problem doing the hot-path read outside of the lock; we still do the mutation inside of the lock so that all of the mutation work is performed atomically and synchronized with the actions from AddProvider and RefreshFilter.
@ghost
Copy link

ghost commented Jun 22, 2023

Tagging subscribers to this area: @dotnet/area-extensions-logging
See info in area-owners.md if you want to be subscribed.

Issue Details

Some ASP.NET code paths end up calling this a lot, and it takes a lock on every call, even though the vast majority are satisifed by the cache and require no mutation. We can use a ConcurrentDictionary instead of a Dictionary, with double-checked locking. Nothing is ever removed from or overwritten in the dictionary, so there's no problem doing the hot-path read outside of the lock; we still do the mutation inside of the lock so that all of the mutation work is performed atomically and synchronized with the actions from AddProvider and RefreshFilter.

Method Toolchain Mean Ratio
Serial \main\corerun.exe 21.646 ns 1.00
Serial \pr\corerun.exe 8.408 ns 0.39
Parallel \main\corerun.exe 371,691,606.667 ns 1.00
Parallel \pr\corerun.exe 19,181,294.940 ns 0.05
using BenchmarkDotNet.Attributes;
using BenchmarkDotNet.Running;
using Microsoft.Extensions.Logging;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;

[MemoryDiagnoser(false)]
public class Program
{
    static void Main(string[] args) => BenchmarkSwitcher.FromAssembly(typeof(Program).Assembly).Run(args);

    private LoggerFactory _factory = new LoggerFactory();

    [Benchmark]
    public ILogger Serial() => _factory.CreateLogger("test");

    [Benchmark]
    public async Task Parallel()
    {
        var b = new Barrier(12);
        await Task.WhenAll(from i in Enumerable.Range(0, b.ParticipantCount)
                           select Task.Run(() =>
                           {
                               b.SignalAndWait();
                               for (int j = 0; j < 1_000_000; j++)
                               {
                                   _factory.CreateLogger("test");
                               }
                           }));
    }
}
Author: stephentoub
Assignees: stephentoub
Labels:

area-Extensions-Logging

Milestone: -

Copy link
Member

@davidfowl davidfowl left a comment

Choose a reason for hiding this comment

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

Simple, clean and a huge performance boost!

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Lock contention in LoggerFactory.CreateLogger
2 participants