runtime: Reading from Event Log is > 20 times too slow

The “new” way to read event logs is to use EventLogReader which is with .NET since a long time. Some people have been wondering why it is so much slower than the plain Eventlog class. Besides the different Win32 APIs which are called there is a huge difference in the EventLogReader class which is responsible for the really bad perf:

https://github.com/dotnet/runtime/blob/6d395de48ac718a913e567ae80961050f2a9a4fa/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/ProviderMetadataCachedInformation.cs#L159

According to the docu two lines above this will throw when while the process is running an ETW provider was uninstalled. Not sure if we really need such a rigor error handling but this results in hugely degraded performance.

This innocent looking call calls into

this.GetProviderListProperty(_handle, UnsafeNativeMethods.EvtPublisherMetadataPropertyId.EvtPublisherMetadataTasks);

which will format into an array all named Tasks of the given ETW provider. For some providers there are only a few but e.g. the Security Event Log has over 60 of them which are all string formatted in a localized manner and then thrown immediately away.

Check out that simple application:

using System;
using System.Diagnostics;
using System.Diagnostics.Eventing.Reader;


namespace ConsoleApp1
{
    class Program
    {
        static void Main(string[] args)
        {
                string log = "Security";
                if (args.Length > 0)
                {
                    log = args[0];
                }
                var reader = new EventLogReader(log, PathType.LogName);

                EventRecord record = null;
                for (int i = 0; i < 1 && ((record = reader.ReadEvent()) != null); i++)
                {
                    Console.WriteLine("Got {0} {1} {2}", record.FormatDescription(), record.Task, record.ProviderName);
                    const int Runs = 1000;
                    var sw = Stopwatch.StartNew();
                    for (int k = 0; k < Runs; k++)
                    {
                        var tmp = record.FormatDescription();
                    }
                    sw.Stop();
                    Console.WriteLine($"Did format message {Runs} times in {sw.Elapsed.TotalSeconds:F3}s");
                }
            }
    }
}

On my machine I get for reading a single Security Event Log message: … Did format message 1000 times in 12.861s

When I remove CheckReleased then it is over 26 times faster: …Did format message 1000 times in 0.453s

The screenshot below shows that while reading and formatting a single event we will read all task properties which are 60 for this event log:

Whatever the reason for this error check was it makes reading event log messages over a magnitude slower than it should and could be. I know the compat bar is high but is there a chance to remove this safety check. I see no real reason to keep this.