Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Reading Windows Logs efficiently and fast

What I'm trying to accomplish is a C# application that will read logs from the Windows Event Logs and store them somewhere else. This has to be fast, since some of the devices where it will be installed generate a high amount of logs/s.

I have tried three approaches so far:

Local WMI: it didn't work good, there are too many errors and exceptions caused by the size of the collections that need to be loaded. EventLogReader: I though this was the perfect solution, since it allows you to query the event log however you like by using XPath expressions. The problem is that when you want to get the content of the message for each log (by calling FormatDescription()) takes way too much time for long collections. E.g: I can read 12k logs in 0.11s if I just go over them. If I add a line to store the message for each log, it takes nearly 6 minutes to complete exactly the same operation, which is totally crazy for such a low number of logs. I don't know if there's any kind of optimization that might be done to EventLogReader in order to get the message faster, I couldn't find anything either on MS documentation nor on the Internet.

I also found that you can read the log entries by using a class called EventLog. However, this technology does not allow you to enter any kind of filters so you basically have to load the entire list of logs to memory and then filter it out according to your needs. Here's an example:

EventLog eventLog = EventLog.GetEventLogs().FirstOrDefault(el => el.Log.Equals("Security", StringComparison.OrdinalIgnoreCase));
var newEntries = (from entry in eventLog.Entries.OfType()
orderby entry.TimeWritten ascending
where entry.TimeWritten > takefrom
select entry);

Despite of being faster in terms of getting the message, the use of memory might be high and I don't want to cause any issues on the devices where this solution will get deployed.

Can anybody help me with this? I cannot find any workarounds or approaches to achieve something like this.

Thank you!.

like image 606
Lucas Álvarez Lacasa Avatar asked Nov 22 '18 11:11

Lucas Álvarez Lacasa


1 Answers

You can give the EventLogReader class a try. See https://docs.microsoft.com/en-us/previous-versions/bb671200(v=vs.90).

It is better than the EventLog class because accessing the EventLog.Entries collection has the nasty property that its count can change while you are reading from it. What is even worse is that the reading happens on an IO threadpool thread which will let your application crash with an unhandled exception. At least that was the case some years ago.

The EventLogReader also gives you the ability to supply a query string to filter for the events you are interested in. That is the way to go if you write a new application.

Here is an application which shows how you can parallelize reading:

using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.Eventing.Reader;
using System.Linq;
using System.Threading.Tasks;

namespace EventLogReading
{
    class Program
    {
        static volatile bool myHasStoppedReading = false;

        static void ParseEventsParallel()
        {
            var sw = Stopwatch.StartNew();
            var query = new EventLogQuery("Application", PathType.LogName, "*");

            const int BatchSize = 100;

            ConcurrentQueue<EventRecord> events = new ConcurrentQueue<EventRecord>();
            var readerTask = Task.Factory.StartNew(() =>
            {
                using (EventLogReader reader = new EventLogReader(query))
                {
                    EventRecord ev;
                    bool bFirst = true;
                    int count = 0;
                    while ((ev = reader.ReadEvent()) != null)
                    {
                        if ( count % BatchSize == 0)
                        {
                            events.Enqueue(ev);
                        }
                        count++;
                    }
                }
                myHasStoppedReading = true;
            });

            ConcurrentQueue<KeyValuePair<string, EventRecord>> eventsWithStrings = new ConcurrentQueue<KeyValuePair<string, EventRecord>>();

            Action conversion = () =>
            {
                EventRecord ev = null;
                using (var reader = new EventLogReader(query))
                {
                    while (!myHasStoppedReading || events.TryDequeue(out ev))
                    {
                        if (ev != null)
                        {
                            reader.Seek(ev.Bookmark);
                            for (int i = 0; i < BatchSize; i++)
                            {
                                ev = reader.ReadEvent();
                                if (ev == null)
                                {
                                    break;
                                }
                                eventsWithStrings.Enqueue(new KeyValuePair<string, EventRecord>(ev.FormatDescription(), ev));
                            }
                        }
                    }
                }
            };

            Parallel.Invoke(Enumerable.Repeat(conversion, 8).ToArray());

            sw.Stop();
            Console.WriteLine($"Got {eventsWithStrings.Count} events with strings in {sw.Elapsed.TotalMilliseconds:N3}ms");
        }

        static void ParseEvents()
        {
            var sw = Stopwatch.StartNew();
            List<KeyValuePair<string, EventRecord>> parsedEvents = new List<KeyValuePair<string, EventRecord>>();
                
            using (EventLogReader reader = new EventLogReader(new EventLogQuery("Application", PathType.LogName, "*")))
            {
                EventRecord ev;
                while ((ev = reader.ReadEvent()) != null)
                {
                    parsedEvents.Add(new KeyValuePair<string, EventRecord>(ev.FormatDescription(), ev));
                }
            }

            sw.Stop();
            Console.WriteLine($"Got {parsedEvents.Count} events with strings in {sw.Elapsed.TotalMilliseconds:N3}ms");
        }

        static void Main(string[] args)
        {
            ParseEvents();
            ParseEventsParallel();
        }
    }
}
Got 20322 events with strings in 19,320.047ms
Got 20323 events with strings in 5,327.064ms

This gives a decent speedup of a factor 4. I needed to use some tricks to get faster because for some strange reason the class ProviderMetadataCachedInformation is not thread safe and uses internally a lock(this) around the Format method which defeats paralell reading. The key trick is to open the event log in the conversion threads again and then read a bunch of events of the query there via the event bookmark Api. That way you can format the strings independently.

Update1

I have landed a change in .NET 5 which increases performance by a factor three up to 20. See https://github.com/dotnet/runtime/issues/34568. You can also copy the EventLogReader class from .NET Core and use this one instead which will give you the same speedup.

The full saga is described by my Blog Post: https://aloiskraus.wordpress.com/2020/07/20/ms-performance-hud-analyze-eventlog-reading-performance-in-realtime/

like image 76
Alois Kraus Avatar answered Oct 05 '22 15:10

Alois Kraus