EventParser.cs

/* 
Licensed to the Apache Software Foundation (ASF) under one
or more contributor license agreements.  See the NOTICE file
distributed with this work for additional information
regarding copyright ownership.  The ASF licenses this file
to you under the Apache License, Version 2.0 (the
"License"); you may not use this file except in compliance
with the License.  You may obtain a copy of the License at

  http://www.apache.org/licenses/LICENSE-2.0

Unless required by applicable law or agreed to in writing,
software distributed under the License is distributed on an
"AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
KIND, either express or implied.  See the License for the
specific language governing permissions and limitations
under the License.
*/
using System.Diagnostics;
using System.Runtime.InteropServices;
using System.Text;

namespace etwlib
{
    using static TraceLogger;
    using static NativeTraceConsumer;
    using static NativeTraceControl;

    public class EventParser
    {
        private EventParserBuffers m_Buffers;
        private long m_UniqueId;
        private ParsedEtwEvent? m_ParsedEvent;
        private long m_PerfFreq;
        private bool m_SkipUserData;

        public EventParser(
            EVENT_RECORD Event,
            EventParserBuffers Buffers,
            long PerfFreq)
        {
            m_Buffers = Buffers;
            m_Buffers.SetEvent(Event);
            m_UniqueId = Event.EventHeader.TimeStamp;
            m_PerfFreq = PerfFreq;
        }

        public EventParser(
            Guid ProviderGuid,
            EVENT_DESCRIPTOR EventDescriptor,
            nint InfoBuffer,
            EventParserBuffers Buffers
            )
        {
            m_SkipUserData = true;
            m_Buffers = Buffers;
            var record = new EVENT_RECORD();
            record.EventHeader.Size = (ushort)Marshal.SizeOf(typeof(EVENT_RECORD));
            record.EventHeader.Descriptor = EventDescriptor;
            record.EventHeader.ProviderId = ProviderGuid;
            m_Buffers.SetEvent(record);
            m_Buffers.SetTraceInfo(InfoBuffer);
            m_UniqueId = DateTime.Now.ToBinary();
        }

        public
        void
        DumpDiagnosticInfo(string DestinationFolder)
        {
            var size = m_Buffers.m_Event.EventHeader.Size;
            var rawEvent = new byte[size];
            Marshal.Copy(m_Buffers.m_EventBuffer, rawEvent, 0, size);
            string target = Path.Combine(DestinationFolder, $"Event-raw-" +
                $"{m_UniqueId:X}.bin");
            File.WriteAllBytes(target, rawEvent);
            target = Path.Combine(DestinationFolder, $"Event-text-" +
                $"{m_UniqueId:X}.txt");
            File.WriteAllText(target, m_ParsedEvent?.ToString());
        }

        public
        ParsedEtwEvent?
        Parse()
        {
            Trace(TraceLoggerType.EtwEventParser,
                  TraceEventType.Verbose,
                  $"Parsing event 0x{m_UniqueId:X}");

            //
            // Ignore string-only events and those generated by WPP.
            //
            if (m_Buffers.m_Event.EventHeader.Flags.HasFlag(
                    EventHeaderFlags.StringOnly) ||
                m_Buffers.m_Event.EventHeader.Flags.HasFlag(
                    EventHeaderFlags.TraceMessage))
            {
                Trace(TraceLoggerType.EtwEventParser,
                    TraceEventType.Warning,
                    "Ignoring string-only or WPP-generated event");
                return null;
            }
            //
            // Ignore events that require legacy WMI MOF manifest to parse user data.
            //
            if (m_Buffers.m_Event.EventHeader.EventProperty.HasFlag(
                EventHeaderPropertyFlags.LegacyEventLog))
            {
                Trace(TraceLoggerType.EtwEventParser,
                    TraceEventType.Warning,
                    "Ignoring legacy event log style event");
                return null;
            }

            m_ParsedEvent = new ParsedEtwEvent();

            //
            // Get stuff hanging right off the EVENT_RECORD's header
            //
            m_ParsedEvent.Version = m_Buffers.m_Event.EventHeader.Descriptor.Version;
            m_ParsedEvent.EventId = m_Buffers.m_Event.EventHeader.Descriptor.Id;
            m_ParsedEvent.KeywordsUlong = m_Buffers.m_Event.EventHeader.Descriptor.Keyword;
            m_ParsedEvent.ProcessId = m_Buffers.m_Event.EventHeader.ProcessId;
            m_ParsedEvent.ThreadId = m_Buffers.m_Event.EventHeader.ThreadId;
            m_ParsedEvent.ActivityId = m_Buffers.m_Event.EventHeader.ActivityId;
            //
            // Event timestamp is stored in QPC format, convert to a scaled
            // 100-ns standard system time that DateTime can cope with.
            //
            if (m_Buffers.m_Event.EventHeader.TimeStamp != 0)
            {
                var scaledTimestamp = (long)
                    (m_Buffers.m_Event.EventHeader.TimeStamp * 10000000.0 / m_PerfFreq);
                m_ParsedEvent.Timestamp = DateTime.FromFileTime(scaledTimestamp);
            }
            m_ParsedEvent.Provider.Id = m_Buffers.m_Event.EventHeader.ProviderId;

            //
            // The remaining parser steps require TRACE_EVENT_INFO. We cache the
            // resulting buffer internally for the remainder of processing this
            // event.
            //
            if (!GetTraceEventInfo())
            {
                return null;
            }

            //
            // Use TDH to parse meta information from the event descriptor
            // inside the event header (keywords, opcode, task, etc)
            //
            Trace(TraceLoggerType.EtwEventParser,
                TraceEventType.Information,
                "Parsing trace event meta information");
            if (!ParseMetaInformation())
            {
                return null;
            }

            //
            // Parse "extended data" which is stuff added by the OS to every
            // ETW event - like SID, stack trace, process start key,
            // and so on (some of these must be turned on when you call
            // EnableTraceEx)
            //
            Trace(TraceLoggerType.EtwEventParser,
                TraceEventType.Information,
                "Parsing trace extended data");
            if (!ParseExtendedData())
            {
                return null;
            }

            Trace(TraceLoggerType.EtwEventParser,
                 TraceEventType.Information,
                 m_ParsedEvent.ToString());

            //
            // Use TDH and the manifest to parse custom "user data" which
            // has information unique to this provider. If the caller is
            // using EventParser to parse manifest information, which won't
            // have actual event data, UserData will be ignored.
            //
            Trace(TraceLoggerType.EtwEventParser,
                TraceEventType.Information,
                "Parsing trace user data");
            if (!m_SkipUserData)
            {
                if (m_Buffers.m_Event.UserDataLength <= 0)
                {
                    Trace(TraceLoggerType.EtwEventParser,
                          TraceEventType.Information,
                          "Event contained no user data.");
                    return m_ParsedEvent;
                }

                Trace(TraceLoggerType.EtwEventParser,
                      TraceEventType.Information,
                      "Event has " + m_Buffers.m_Event.UserDataLength +
                      " bytes of user data.");
            }
            else if (m_Buffers.m_TraceEventInfo.PropertyCount == 0)
            {
                Trace(TraceLoggerType.EtwEventParser,
                      TraceEventType.Information,
                      "Event manifest has no template data.");
                return m_ParsedEvent;
            }

            //
            // Instantiate a PropertyParser to reuse the pre-allocated buffers.
            //
            var propertyParser = new PropertyParser(m_Buffers, m_SkipUserData);
            if (!propertyParser.Initialize())
            {
                return null;
            }

            //
            // Parsing begins at the top level properties. The PropertyParser.Parse
            // method will recurse as needed.
            //
            var success = propertyParser.Parse(
                0,
                m_Buffers.m_TraceEventInfo.TopLevelPropertyCount,
                new StringBuilder());
            if (!success)
            {
                return null;
            }

            if (m_SkipUserData)
            {
                //
                // If we're just parsing the manifest, the caller needs to know the
                // relationship of fields that reference other fields for their
                // value - like a Buffer field that references a BufferSize field.
                //
                propertyParser.ResolveBackreferences();
            }

            m_ParsedEvent.TemplateData = propertyParser.m_ParsedEtwTemplateItems;
            return m_ParsedEvent;
        }

        private
        bool
        GetTraceEventInfo()
        {
            if (m_SkipUserData)
            {
                //
                // Caller already had this and passed it into overloaded ctor.
                //
                return true;
            }
            uint bufferSize = (uint)EventParserBuffers.TRACE_EVENT_INFO_SIZE;
            var status = TdhGetEventInformation(
                m_Buffers.m_EventBuffer,
                0,
                nint.Zero,
                m_Buffers.m_TraceEventInfoBuffer,
                ref bufferSize);
            if (status != ERROR_SUCCESS)
            {
                Trace(TraceLoggerType.EtwEventParser,
                     TraceEventType.Error,
                     $"TdhGetEventInformation failed: {status:X}");
                return false;
            }
            m_Buffers.SetTraceInfo();
            return true;
        }

        private
        bool
        ParseMetaInformation()
        {
            var buffer = m_Buffers.m_TraceEventInfoBuffer;

            try
            {
                if (m_Buffers.m_TraceEventInfo.ProviderNameOffset > 0)
                {
                    m_ParsedEvent!.Provider.Name = Marshal.PtrToStringUni(
                        nint.Add(buffer, m_Buffers.m_TraceEventInfo.ProviderNameOffset))!;
                }

                if (m_Buffers.m_TraceEventInfo.LevelNameOffset > 0)
                {
                    m_ParsedEvent!.Level = Marshal.PtrToStringUni(
                        nint.Add(buffer, m_Buffers.m_TraceEventInfo.LevelNameOffset))!.Trim();
                }
                else
                {
                    m_ParsedEvent!.Level =
                        m_Buffers.m_Event.EventHeader.Descriptor.Level.ToString().Trim();
                }

                if (m_Buffers.m_TraceEventInfo.ChannelNameOffset > 0)
                {
                    var name = Marshal.PtrToStringUni(
                        nint.Add(buffer, m_Buffers.m_TraceEventInfo.ChannelNameOffset))!.Trim();
                    m_ParsedEvent.Channel = new ParsedEtwString(
                        name, m_Buffers.m_Event.EventHeader.Descriptor.Channel);
                }
                else if (m_Buffers.m_Event.EventHeader.Descriptor.Channel != 0)
                {
                    m_ParsedEvent.Channel = new ParsedEtwString(
                        "", m_Buffers.m_Event.EventHeader.Descriptor.Channel);
                }

                m_ParsedEvent.Provider.Source =
                    m_Buffers.m_TraceEventInfo.Source.ToString();
                var keywords = new List<string>();
                if (m_Buffers.m_TraceEventInfo.KeywordsNameOffset > 0)
                {
                    for (int offset = m_Buffers.m_TraceEventInfo.KeywordsNameOffset; ;)
                    {
                        var str = Marshal.PtrToStringUni(nint.Add(buffer, offset));
                        if (string.IsNullOrEmpty(str))
                        {
                            break;
                        }
                        keywords.Add(str.Trim());
                        offset += Encoding.Unicode.GetByteCount(str) + 2;
                    }
                }
                if (keywords.Count > 0)
                {
                    m_ParsedEvent.Keywords = string.Join(",", keywords);
                }

                if (m_Buffers.m_TraceEventInfo.TaskNameOffset > 0)
                {
                    var name= Marshal.PtrToStringUni(
                        nint.Add(buffer, m_Buffers.m_TraceEventInfo.TaskNameOffset))!.Trim();
                    m_ParsedEvent.Task = new ParsedEtwString(
                        name, m_Buffers.m_Event.EventHeader.Descriptor.Task);
                }
                else if (m_Buffers.m_Event.EventHeader.Descriptor.Task != 0)
                {
                    m_ParsedEvent.Task = new ParsedEtwString(
                        "", m_Buffers.m_Event.EventHeader.Descriptor.Task);
                }

                if (m_Buffers.m_TraceEventInfo.OpcodeNameOffset > 0)
                {
                    var name = Marshal.PtrToStringUni(
                        nint.Add(buffer, m_Buffers.m_TraceEventInfo.OpcodeNameOffset))!.Trim();
                    m_ParsedEvent.Opcode = new ParsedEtwString(
                        name, m_Buffers.m_Event.EventHeader.Descriptor.Opcode);
                }
                else if (m_Buffers.m_Event.EventHeader.Descriptor.Opcode > 0)
                {
                    m_ParsedEvent.Opcode = new ParsedEtwString(
                        "", m_Buffers.m_Event.EventHeader.Descriptor.Opcode);
                }
            }
            catch (Exception ex)
            {
                Trace(TraceLoggerType.EtwEventParser,
                    TraceEventType.Error,
                    $"An exception occurred when marshaling the " +
                    $"TRACE_EVENT_INFO struct: {ex.Message}");
                return false;
            }
            return true;
        }

        private
        unsafe
        bool
        ParseExtendedData()
        {
            if (!m_Buffers.m_Event.EventHeader.Flags.HasFlag(
                    EventHeaderFlags.ExtendedInfo) ||
                m_Buffers.m_Event.ExtendedDataCount <= 0)
            {
                Trace(TraceLoggerType.EtwEventParser,
                    TraceEventType.Warning,
                    "Event contained no extended data.");
                return true;
            }

            Trace(TraceLoggerType.EtwEventParser,
                TraceEventType.Information,
                $"Event has {m_Buffers.m_Event.ExtendedDataCount}" +
                $" extended data items.");

            nint buffer = m_Buffers.m_Event.ExtendedData;
            for (int i = 0; i < m_Buffers.m_Event.ExtendedDataCount; i++)
            {
                var item = (EVENT_HEADER_EXTENDED_DATA_ITEM)Marshal.PtrToStructure(
                    buffer, typeof(EVENT_HEADER_EXTENDED_DATA_ITEM))!;
                var size = (int)item.DataSize;
                if (size == 0)
                {
                    Trace(TraceLoggerType.EtwEventParser,
                        TraceEventType.Error,
                        "Corrupt extended data, zero-length extended data item.");
                    return false;
                }
                nint data = new nint((void*)item.DataPtr);
                try
                {
                    switch (item.ExtType)
                    {
                        case EventHeaderExtendedDataType.Sid:
                            {
                                var binarySid = new byte[size];
                                Marshal.Copy(data, binarySid, 0, size);
                                var sid = new System.Security.Principal.SecurityIdentifier(binarySid, 0);
                                m_ParsedEvent!.UserSid = sid.ToString();
                                break;
                            }
                        case EventHeaderExtendedDataType.RelatedActivityId:
                            {
                                break;
                            }
                        case EventHeaderExtendedDataType.ProcessStartKey:
                            {
                                m_ParsedEvent!.ProcessStartKey = Marshal.ReadInt64(data);
                                break;
                            }
                        case EventHeaderExtendedDataType.StackTrace32:
                            {
                                if (!ParseStackwalkAddresses(data, size, true))
                                {
                                    return false;
                                }
                                break;
                            }
                        case EventHeaderExtendedDataType.StackTrace64:
                            {
                                if (!ParseStackwalkAddresses(data, size, false))
                                {
                                    return false;
                                }
                                break;
                            }
                        default:
                            {
                                break;
                            }
                    }
                }
                catch (Exception ex)
                {
                    Trace(TraceLoggerType.EtwEventParser,
                        TraceEventType.Error,
                        $"Failed to cast extended data item #{i}" +
                        $", type {item.ExtType}, length {item.DataSize}" +
                        $", pointer 0x{item.DataPtr:X}: {ex.Message}");
                    return false;
                }
                size = Marshal.SizeOf(typeof(EVENT_HEADER_EXTENDED_DATA_ITEM));
                buffer = nint.Add(buffer, size);
            }
            return true;
        }

        private
        bool
        ParseStackwalkAddresses(nint Buffer, int Size, bool Is32bit)
        {
            var minSize = sizeof(ulong) + sizeof(uint);
            if (Size < minSize)
            {
                Trace(TraceLoggerType.EtwEventParser,
                      TraceEventType.Error,
                      $"Corrupt extended data, not enough data for " +
                      $"at least one stackwalk address {(Is32bit ? "(32-bit)" : "(64-bit)")}");
                return false;
            }
            int numElements = 0;

            if (Is32bit)
            {
                numElements = (Size - sizeof(ulong)) / sizeof(uint);
            }
            else
            {
                numElements = (Size - sizeof(ulong)) / sizeof(ulong);
            }

            if (numElements == 0 || numElements > MaxStackwalkFrames)
            {
                Trace(TraceLoggerType.EtwEventParser,
                      TraceEventType.Error,
                      $"Corrupt extended data, invalid number of " +
                      $"stackwalk addresses {(Is32bit ? "(32-bit)" :
                        "(64-bit)")}: {numElements}");
                return false;
            }

            m_ParsedEvent!.StackwalkAddresses = new List<ulong>();
            var pointer = Buffer;

            //
            // MatchId is a unique identifier the consumer can use to tie kernel and
            // user stackwalk frames together for a single event. For events where both
            // are captured inside a single event, this number is 0.
            //
            var matchId = (ulong)Marshal.ReadInt64(pointer);
            m_ParsedEvent.StackwalkMatchId = matchId;
            pointer = nint.Add(pointer, sizeof(ulong));

            m_ParsedEvent.StackwalkAddresses = new List<ulong>();
            for (int s = 0; s < numElements; s++)
            {
                if (Is32bit)
                {
                    m_ParsedEvent.StackwalkAddresses.Add((ulong)Marshal.ReadInt32(pointer));
                    pointer = nint.Add(pointer, sizeof(uint));
                }
                else
                {
                    m_ParsedEvent.StackwalkAddresses.Add((ulong)Marshal.ReadInt64(pointer));
                    pointer = nint.Add(pointer, sizeof(ulong));
                }
            }

            if (m_ParsedEvent.StackwalkAddresses.Count == 0)
            {
                Trace(TraceLoggerType.EtwEventParser,
                      TraceEventType.Error,
                      $"No stackwalk addresses found.");
                return false;
            }

            m_ParsedEvent.StackwalkAddresses =
                m_ParsedEvent.StackwalkAddresses.OrderByDescending(s => s).ToList();
            return true;
        }
    }
}