Benutzer:MovGP0/Performance/Event Tracing

Event Tracing for Windows (ETW)

NEVER LOG NULL VALUES!

Advantages

Built-in
High-Performance
automatic buffering
event production can be enabled and disabled at runtime
filtering mechanism
integrate event from multipe sources
OS and .NET uses ETW
typed and ordinal (sortable) instead of just strings

Install

.NET 4.5

Namespace:

using System.Diagnostics.Tracing;

.NET 4.5 does not support Channels. Use the Microsoft.Diagnostics.Tracing NuGet Package for Channel support.

.NET 4.0

Namespace:

using Microsoft.Diagnostics.Tracing;

NuGet Packages:

Install-Package Microsoft.Diagnostics.Tracing.EventSource
Install-Package Microsoft.Diagnostics.Tracing.TraceEvent

Optional Packages

Install-Package EventSourceProxy # .NET 4.5
Install-Package EventSourceProxy.NuGet # .NET 4.0
Install-Package Microsoft.Diagnostics.Tracing.EventRegister # EventRegister.exe extracts Manifest files from binary

Defining Event

using System.Diagnostic.Tracing;

namespace EtlDemo
{
   [EventSource(Name="Company-Department-Application-UniqueEventSourceName")]
   internal sealed class Events : EventSource
   {
      // Singleton Instance to where the Events are written to. 
      public static readonly Lazy<Events> _log = new Lazy<Events>();

      // private constructor
      private Events ()
      {
      }

      public static Log
      {
          get { return _log.Value; }
      }

      // define Tasks, Opcodes, and Keywords classes
      // values can be Int32 or Int64 
      // use values that allow concatenation with binary-AND (&) operations
      public class Keywords
      {
         public const EventKeywords General = (EventKeywords) 0x0001;
         public const EventKeywords PrimeOutput = (EventKeywords) 0x0002;
      }

      public class Opcodes
      {
          public const EventOpcode Start = (EventOpcode) 0x0001;
          public const EventOpcode Stop = (EventOpcode) 0x0002;
      }

      public class Tasks
      {
          public const EventTask Start = (EventTask) 0x0001;
          public const EventTask Stop  = (EventTask) 0x0002;
      }

      // IDs are needed to preserve the order of methods 
      internal const int ProcessingStartId = 1;
      internal const int ProcessingFinishId = 2;
      internal const int FoundPrimeId = 3;

      [Event(ProcessingStartId, Level = EventLevel.Informational, Keywords = Keywords.General)]
      public void ProcessingStart()
      {
         if(IsEnabled())
         {
            WriteEvent(ProcessingStartId);
         }
      }

      [Event(ProcessingFinishId, Level = EventLevel.Informational, Keywords = Keywords.General)]
      public void ProcessingFinish()
      {
         if(IsEnabled())
         {
            WriteEvent(ProcessingFinishId);
         }
      }

      [Event(FoundPrimeId, Level = EventLevel.Informational, Keywords = Keywords.PrimeOutput, Message = "The prime number is {0}")]
      public void FoundPrime(long primeNumber)
      {
         if(IsEnabled())
         {
            WriteEvent(FoundPrimeId, primeNumber);
         }
      }

      // mark overloaded methods and generic methods that call an event method with [NonEventAttribute]
   }
}

Usage:

Events.Log.FoundPrime(5L);

Create ETW Event Listener

///<summary>Stores information about which event should get captured by the listener</summary>
class SourceConfig
{
   public string Name { get; set; }
   public EventLevel Level {get; set; }
   public EventKeywords Keywords { get; set; }
}

abstract class BaseListener : EventListener
{
   var configs = new List<SourceConfig>();

   protected BaseListener(IEnumerable<SourceConfig> sources)
   {
      configs.AddRange(sources);

      foreach(var source in configs)
      {
         var eventSource = FindEventSource(source.Name);
         if(eventSource != null)
         {
            EnableEvents(eventSource, source.Level, source.Keywords);
         }
      }
   }

   private static EventSource FindEventSource(string name)
   {
      foreach(var eventSource in EventSource.GetSources())
      {
         if(string.Equals(eventSource.Name, name))
         {
            return eventSource;
         }
      }

      return null; 
   }

   ///<summary>Find Event Sources that are created after the program has started</summary>
   protected override void OnEventSourceCreated(EventSource evnetSource)
   {
      base.OnEventSourceCreated(eventSource);
      
      foreach(var source in configs)
      {
         if(string.Equals(source.Name, eventSource.Name))
         {
            EnableEvents(eventSource, source.Level, source.Keywords);
         }
      }
   }

   ///<summary>Gets called every time an event is written by the sources for the current listener</summary>
   protected override void OnEventWritten(EventWrittenEventArgs eventData)
   {
      WriteEvent(eventData); // relay to abstract method
   }

   protected abstract void WriteEvent(EventWrittenEventArgs eventData;)
}

Console Listener

class ConsoleListener : BaseListener
{
   public ConsoleListener(IEnumerable<SourceConfig> sources) : base(sources)
   {
   }

   protected override void WriteEvent(EventWrittenEventArgs eventData)
   {
      string outputString; 

      switch(eventData.EventId)
      {
         case Events.ProcessingStartId: 
            outputString = string.Format("ProcessingStart ({0})", eventData.EventId);
            break;

         case Events.ProcessingFinishId: 
            outputString = string.Format("ProcessingFinish ({0})", eventData.EventId);
            break;

         case Events.FoundPrimeId: 
            outputString = string.Format("FoundPrime ({0}): {1}", eventData.EventId, (long)eventData.Payload[0]);
            break;

         default: 
            throw new InvalidOperationException("Unknown event");
      }

      Console.WriteLine(outputString); 
   }
}

File Listener

class ConsoleListener : BaseListener
{
   private StreamWriter writer;

   public ConsoleListener(IEnumerable<SourceConfig> sources) : base(sources)
   {
      writer = new StreamWriter(outputFile);
   }

   protected override void WriteEvent(EventWrittenEventArgs eventData)
   {
      var output = new StringBuilder();
      var time = DateTime.UtcNow;
      output.AppendFormat("{0:yyyy-MM-dd-HH:mm:ss.fff} - {1} - ", time, eventData.Level);

      switch(eventData.EventId)
      {
         case Events.ProcessingStartId: 
            output.Append("ProcessingStart");
            break;

         case Events.ProcessingFinishId: 
            output.Append("ProcessingFinish");
            break;

         case Events.FoundPrimeId: 
            output.Append("FoundPrime - {0:No}", eventData.Payload[0]);
            break;

         default: 
            throw new InvalidOperationException("Unknown event");
      }

      writer.WriteLine(output.ToString());
   }

   public override void Dispose()
   {
      writer.Close();
      base.Dispose();
   }
}

Register ETW Events in EventLog

The build creates the binary (.dll) and an Manifest (.man). Those are registered using wevtutil:

# run as admin
wevtutil install-manifest PROJECTNAME.man /mf:"PROJECTNAME.dll" /rf:"PROJECTNAME.dll"

Events should now be visible in Event Viewer.

Semantic Logging Application Block (SLAB)

In-Process

Create a separate Project that is only referenced in Debug.

public sealed class SemanticLoggingManager : IDisposable
{
    private static readonly ObservableEventListener _listener = new ObservableEventListener();
    
    public static IDisposable AppendListenerToEventSource([NotNull]EventSource eventSource)
    {
        listener.EnableEvents(eventSource, EventLevet.LogAlways, Keywords.All);
        listener.LogToConsole();
        // listener.LogToConsole(new JsonEventTextFormatter(EventTextFormatting.Indentend), colorMapper); 
        // listener.LogToConsole(new XmlEventTextFormatter(), colorMapper); 
        
        Disposable.CreateNew(() => 
        {
            listener.DisableEvents(eventSource);
            // eventSource.Dispose();
        });
    }
    
    public void Dispose()
    {
        _listener.Dispose();
    }
}

public partial class App : Application
{
    protected override void OnStartup(StartupEventArgs e)
    {
        base.OnStartup(e);
        AppendListenerToEventSource();
    }
    
    private IDisposable _eventSourceListener;
    
    [Conditional("DEBUG")]
    private void AppendListenerToEventSource()
    {
        _eventSourceListener = SemanticLoggingManager.AppendListenerToEventSource(MyEventSource.Log);
    }
    
    public override OnExit(ExitEventArgs e)
    {
        DisposeListener();
        base.OnExit(e);
    }
    
    [Conditional("DEBUG")]
    private void DisposeListener()
    {
        _eventSourceListener.Dispose();
        MyEventSource.Log.Dispose();
    }
}

Out-Of-Process

Installing and running the Out-of-Process Windows Service/Console Host. In: MSDN, Microsoft Patterns & Practices. Microsoft, abgerufen am 14. Juni 2015 (englisch).

NuGet Libraries

Vance Morrison: TraceEvent ETW Library published as a NuGet Package. In: MSDN Blog. Microsoft, 15. August 2013, abgerufen am 2. Mai 2017.
Install-Package Microsoft.Diagnostics.Tracing.TraceEvent

Tools

LogMan

logman -query providers > providers.txt # List all installed Providers

PerfView

PerfView. In: Download Center. Microsoft, abgerufen am 4. August 2014 (englisch).

Windows Performance Recorder (WPR) and Windows Performance Analyzer (WPA)

Requires Windows 8/8.1
WPR can be used instead of PerfView
Windows Assessment and Deployment Kit (Windows ADK) for Windows 8.1 Update. In: Download Center. Microsoft, abgerufen am 14. Juni 2015 (englisch).

Guidelines

Auditing
- infrequent
- security or data change
- operaton may not continue when audit fails
Logging
- for error reporting
- visible to Admins; no confidential data
- operation should continue when logging fails
Tracing
- for Program Flow
- very frequent
- visible to Admins; no confidential data
- operation should continue when tracing fails

EventSource

Name must be unique
Name should not be a GUID (default)

EventId

numbering starts at 0x0001
increment by 1
do not change (would break things when the user has an installed manifest)

Performance

Limit Number of EventSources (performance, clarity)
Ensure calling IsEnabled() to limit traced events
Avoid using WriteEvent(int, params object[]); use custom overloads instead
Consider impact of preprocessing
avoid string formatting; use Message instead
beware of Closures; might introduce bugs

Severity Level

Member	Usage
Critical	critical error that caused a major failure
Error	errors that signify a problem
Warning	Warning that indicates a problem, but is not an error (ie. disk almost full)
Informational	Events or messages that are not errors
LogAlways	Event cannot be filtered and is always recorded
Verbose	Lengthy events or messages

Defined Keywords

use predifined keywords where appropriate
provide own keywords

Member	Usage
AuditFailure	Failed security audit. Use only for security log.
AuditSuccess	Successful security audit. Use only for security log.
CorrelationHint	Transfer event where the activity ID is a computed value and is not guaranteed to be unique (ie. not a GUID)
EventLogClassic	Events that are raised using the RaiseEvent function.
None	Event gets not filtered by keyword filter.
Sqm	Service Quality Mechanism (SQM) event
WdiContext	Windows Diagnostic Infrastructure (WMI) context event
WdiDiagnostic	Windows Diagnostic Infrastructure (WMI) diagnostic event

Opcodes

use predifined opcodes where appropriate
provide own opcodes

Member	Usage
DataColletionStart
DataCollectionStop
Extension
Info
Receive	Activity receives data or resources
Reply
Send	Activity receives sends data or resources
Start	Application, transaction, or activity starts
Stop	Application, transaction, or activity stops
Suspend	Application or activity is suspended

Dependency Injection

Do not implement the interface on the EventSource
Use a wrapper class that uses a singleton of the EventSource internally

Internetquellen

Mattias Högström: Application Analysis with Event Tracing for Windows (ETW). In: CodeProject. 7. August 2013, abgerufen am 14. März 2015 (englisch).
Mattias Högström: EtwDataViewer - Analyze, visualize, and make sense of your ETW logs. In: CodeProject. 7. August 2013, abgerufen am 14. März 2015 (englisch).

Benutzer:MovGP0/Performance/Event Tracing

Inhaltsverzeichnis

Event Tracing for Windows (ETW)

Advantages

Install

.NET 4.5

.NET 4.0

Optional Packages

Defining Event

Create ETW Event Listener

Console Listener

File Listener

Register ETW Events in EventLog

Semantic Logging Application Block (SLAB)

In-Process

Out-Of-Process

NuGet Libraries

Tools

LogMan

PerfView

Windows Performance Recorder (WPR) and Windows Performance Analyzer (WPA)

Guidelines

Severity Level

Defined Keywords

Opcodes

Dependency Injection

Internetquellen

Navigationsmenü

Benutzer:MovGP0/Performance/Event Tracing

Event Tracing for Windows (ETW)

Advantages

Install

.NET 4.5

.NET 4.0

Optional Packages

Defining Event

Create ETW Event Listener

Console Listener

File Listener

Register ETW Events in EventLog

Semantic Logging Application Block (SLAB)

In-Process

Out-Of-Process

NuGet Libraries

Tools

LogMan

PerfView

Windows Performance Recorder (WPR) and Windows Performance Analyzer (WPA)

Guidelines

Severity Level

Defined Keywords

Opcodes

Dependency Injection

Internetquellen

Navigationsmenü

Suche