January 28, 2020 12:00 pm

TraceProcessor 0.3.0

By / Software Engineer, Windows Developer Team

TraceProcessor version 0.3.0 is now available on NuGet with the following package ID:

Microsoft.Windows.EventTracing.Processing.All

This release contains some feature additions and bug fixes since version 0.2.0. (A full changelog is below). Basic usage is still the same as in version 0.1.0.

The focus of this release has been in preparation for a forthcoming version 1.0.0, including many minor changes to naming and data types moving towards a finalized version 1 API.

Also, this release adds trace.UseStreaming(), which supports accessing multiple types of trace data in a streaming manner (processing data as it is read from the trace file, rather than buffering that data in memory). For example, a syscalls trace can be quite large, and buffering the entire list of syscalls in a trace can be quite expensive. The following code shows accessing syscall data in the normal, buffered manner via trace.UseSyscalls():

</p>
<p>using Microsoft.Windows.EventTracing; using Microsoft.Windows.EventTracing.Processes; using Microsoft.Windows.EventTracing.Syscalls; using System; using System.Collections.Generic; class Program { static void Main(string[] args) { if (args.Length != 1) { Console.Error.WriteLine("Usage: "); return; } using (ITraceProcessor trace = TraceProcessor.Create(args[0])) { IPendingResult pendingSyscallData = trace.UseSyscalls(); trace.Process(); ISyscallDataSource syscallData = pendingSyscallData.Result; Dictionary syscallsPerCommandLine = new Dictionary(); foreach (ISyscall syscall in syscallData.Syscalls) { IProcess process = syscall.Thread?.Process; if (process == null) { continue; } if (!syscallsPerCommandLine.ContainsKey(process)) { syscallsPerCommandLine.Add(process, 0); } ++syscallsPerCommandLine[process]; } Console.WriteLine("Process Command Line: Syscalls Count"); foreach (IProcess process in syscallsPerCommandLine.Keys) { Console.WriteLine($"{process.CommandLine}: {syscallsPerCommandLine[process]}"); } } } }</p>
<!-- /wp:shortcode -->

<!-- wp:paragraph -->
<p>With a large syscalls trace, attempting to buffer the syscall data in memory can be quite expensive, or it may not even be possible. The following code shows how to access the same syscall data in a streaming manner, replacing trace.UseSyscalls() with trace.UseStreaming().UseSyscalls():</p>
<!-- /wp:paragraph -->

<!-- wp:shortcode -->
<p> using Microsoft.Windows.EventTracing; using Microsoft.Windows.EventTracing.Processes; using Microsoft.Windows.EventTracing.Syscalls; using System; using System.Collections.Generic; class Program { static void Main(string[] args) { if (args.Length != 1) { Console.Error.WriteLine("Usage: "); return; } using (ITraceProcessor trace = TraceProcessor.Create(args[0])) { IPendingResult pendingThreadData = trace.UseThreads(); Dictionary syscallsPerCommandLine = new Dictionary(); trace.UseStreaming().UseSyscalls(ConsumerSchedule.SecondPass, context =&gt; { Syscall syscall = context.Data; IProcess process = syscall.GetThread(pendingThreadData.Result)?.Process; if (process == null) { return; } if (!syscallsPerCommandLine.ContainsKey(process)) { syscallsPerCommandLine.Add(process, 0); } ++syscallsPerCommandLine[process]; }); trace.Process(); Console.WriteLine("Process Command Line: Syscalls Count"); foreach (IProcess process in syscallsPerCommandLine.Keys) { Console.WriteLine($"{process.CommandLine}: {syscallsPerCommandLine[process]}"); } } } } 

By default, all streaming data is provided during the first pass through the trace, and buffered data from other sources is not available. This example shows how to combine streaming with buffering – thread data is buffered before syscall data is streamed. As a result, the trace must be read twice – once to get buffered thread data, and a second time to access streaming syscall data with the buffered thread data now available. In order to combine streaming and buffering in this way, the example passes ConsumerSchedule.SecondPass to trace.UseStreaming().UseSyscalls(), which causes syscall processing to happen in a second pass through the trace. By running in a second pass, the syscall callback can access the pending result from trace.UseThreads() when it processes each syscall. Without this optional argument, syscall streaming would have run in the first pass through the trace (there would be only one pass), and the pending result from trace.UseThreads() would not be available yet. In that case, the callback would still have access to the ThreadId from the syscall, but it would not have access to the process for the thread (because thread to process linking data is provided via other events which may not have been processed yet).

Some key differences in usage between buffering and streaming:

  1. Buffering returns an IPendingResult<T>, and the result it holds is available only before the trace has been processed. After the trace has been processed, the results can be enumerated using techniques such as foreach and LINQ.
  2. Streaming returns void and instead takes a callback argument. It calls the callback once as each item becomes available. Because the data is not buffered, there is never a list of results to enumerate with foreach or LINQ – the streaming callback needs to buffer whatever part of the data it wants to save for use after processing has completed.
  3. The code for processing buffered data appears after the call to trace.Process(), when the pending results are available.
  4. The code for processing streaming data appears before the call to trace.Process(), as a callback to the trace.UseStreaming.Use...() method.
  5. A streaming consumer can choose to process only part of the stream and cancel future callbacks by calling context.Cancel(). A buffering consumer always is provided a full, buffered list.

Sometimes trace data comes in a sequence of events – for example, syscalls are logged via separate enter and exit events, but the combined data from both events can be more helpful. The method trace.UseStreaming().UseSyscalls() correlates the data from both of these events and provides it as the pair becomes available. A few types of correlated data are available via trace.UseStreaming():

Code

Description

trace.UseStreaming().UseContextSwitchData() Streams correlated context switch data (from compact and non-compact events, with more accurate SwitchInThreadIds than raw non-compact events).
trace.UseStreaming().UseScheduledTasks() Streams correlated scheduled task data.
trace.UseStreaming().UseSyscalls() Streams correlated system call data.
trace.UseStreaming().UseWindowInFocus() Streams correlated window-in-focus data.

Additionally, trace.UseStreaming() provides parsed events for a number of different standalone event types:

Code

Description

trace.UseStreaming().UseLastBranchRecordEvents() Streams parsed last branch record (LBR) events.
trace.UseStreaming().UseReadyThreadEvents() Streams parsed ready thread events.
trace.UseStreaming().UseThreadCreateEvents() Streams parsed thread create events.
trace.UseStreaming().UseThreadExitEvents() Streams parsed thread exit events.
trace.UseStreaming().UseThreadRundownStartEvents() Streams parsed thread rundown start events.
trace.UseStreaming().UseThreadRundownStopEvents() Streams parsed thread rundown stop events.
trace.UseStreaming().UseThreadSetNameEvents() Streams parsed thread set name events.

Finally, trace.UseStreaming() also provides the underlying events used to correlate data in the list above. These underlying events are:

Code

Description

Included in

trace.UseStreaming().UseCompactContextSwitchEvents() Streams parsed compact context switch events. trace.UseStreaming().UseContextSwitchData()
trace.UseStreaming().UseContextSwitchEvents() Streams parsed context switch events. SwitchInThreadIds may not be accurate in some cases. trace.UseStreaming().UseContextSwitchData()
trace.UseStreaming().UseFocusChangeEvents() Streams parsed window focus change events. trace.UseStreaming().UseWindowInFocus()
trace.UseStreaming().UseScheduledTaskStartEvents() Streams parsed scheduled task start events. trace.UseStreaming().UseScheduledTasks()
trace.UseStreaming().UseScheduledTaskStopEvents() Streams parsed scheduled task stop events. trace.UseStreaming().UseScheduledTasks()
trace.UseStreaming().UseScheduledTaskTriggerEvents() Streams parsed scheduled task trigger events. trace.UseStreaming().UseScheduledTasks()
trace.UseStreaming().UseSessionLayerSetActiveWindowEvents() Streams parsed session-layer set active window events. trace.UseStreaming().UseWindowInFocus()
trace.UseStreaming().UseSyscallEnterEvents() Streams parsed syscall enter events. trace.UseStreaming().UseSyscalls()
trace.UseStreaming().UseSyscallExitEvents() Streams parsed syscall exit events. trace.UseStreaming().UseSyscalls()

If there are other types of data that you think would benefit from streaming support, please let us know.

As before, if you find these packages useful, we would love to hear from you, and we welcome your feedback. For questions using this package, you can post on StackOverflow with the tag .net-traceprocessing, and issues can also be filed on the eventtracing-processing project on GitHub.

The full changelog for version 0.3.0 is as follows:

Breaking Changes

  • StartTime and StopTime have changed from DateTime to DateTimeOffset (no longer UTC but now preserving the trace time zone offset).
  • The following three properties on IContextSwitchIn were incorrect and have been removed: ThreadState, IsWaitModeSwapable and ThreadRank. These properties remain available from IContextSwitchOut.
  • Metadata has been removed. Use trace.UseMetadata instead.
  • OriginalFileName was removed because it may contain inaccurate data. Use IImage.OriginalFileName instead.
  • IImageWeakKey was removed because it may contain inaccurate data. Use IImage.Timestamp and IImage.Size instead.
  • WeakKey was removed because it may contain inaccurate data. Use Use IImage.Timestamp and IImage.Size instead.
  • DefaultSymCachePath was removed. Use static properties on SymCachePath instead.
  • DefaultSymbolPath was removed. Use static properties on SymCachePath instead.
  • Service snapshots were previously available from both IServiceDataSource and ISystemMetadata. They are now only available from IServiceDataSource.
  • Trace statistics and stack events have had their shapes made consistent with event APIs elsewhere in trace processor.
  • Renames:

    • ExecutingDeferredProcedureCall was removed. Use ICpuSample.IsExecutingDeferredProcedureCall instead.
    • ExecutingInterruptServicingRoutine was removed. Use ICpuSample.IsExecutingInterruptServicingRoutine instead.
    • IsWaitModeSwapable was incorrect and has been renamed IsUserMode.
    • The enum RawWaitReason has been renamed KernelWaitReason.
    • The RawWaitReason property on IContextSwitchOut has been renamed WaitReason.
    • StartTime has been renamed to EnterTime, and ISyscall.StopTime has been renamed to ExitTime.
    • ErrorCode has been changed to ExitCode for consistency.
    • UniqueKey has been renamed to ObjectAddress for accuracy.
    • TimeRange has been renamed to TraceTimeRange.
    • DiskIOPriority has been renamed to IOPriority.
    • A few core types named GenericEvent* have been renamed to TraceEvent* for consistency, since they also apply to classic and unparsed events (TraceEventHeaderFlags, TraceEventHeaderProperties and TraceEventType).
    • Trace statistics-related types are now in the Event namespace instead of the Metadata namespace.
    • StackEvent-related types are now in the Event namespace instead of the Symbols namespace.
    • Type has been replaced by TraceEvent.HeaderType.
    • EventProperty has been renamed to HeaderProperties.
    • Core extensibility types have been moved from the .Events namespace up to the Microsoft.Windows.EventTracing namespace.
    • Size has been renamed to Length for consistency.
    • WindowsTracePreprocessor has been renamed to TraceMessage for accuracy.
    • IsWindowsTracePreprocessor has been renamed to IsTraceMessage for accuracy.
  • Data Type Updates:
    • Most properties on IContextSwitch, IContextSwitchOut IContextSwitchIn have been made nullable for correctness.
    • uint Processor has been changed to int Processor on multiple types.
    • ID-like properties (for example, ProcessId and ThreadId) have been changed from uint to int for consistency with .NET.
    • UserStackRange is now nullable, and Base and Limit addresses have been swapped to match KernelStackRange ordering and actual Windows stack memory layout.
    • The type of RemainingQuantum on IContextSwitchOut has been changed from int? to long? due to observed data overflow.
    • Throughout the API, timestamp properties are now of type TraceTimestamp rather than Timestamp. (TraceTimestamp implicitly converts to Timestamp).
  • Cleanup:

    • ITraceTimestampContext has a new method (GetDateTimeOffset).
    • EventContext is now a ref struct instead of a class.
    • UserData is now of type ReadOnlySpan<byte> instead of IntPtr. The associated EventContext.UserDataLength has been removed; instead use EventContext.UserData.Length.
    • ExtendedData is now of type ExtendedDataItemReadOnlySpan, which is enumerable, rather than IReadOnlyList<ExtendedDataItem>.
    • TraceEvent has been split from EventContext and moved to EventContext.Event.
    • ICompletableEventConsumer has been replaced by ICompletable.
    • EventConsumerSchedule and IScheduledEventConsumer have been replaced by ConsumerSchedule and IScheduledConsumer.
    • Completion requests are no longer included in trace.Use(IEventConsumer) and require a separate call to trace.UseCompletion.
    • PendingResultAvailability has been merged into ConsumerSchedule.
    • UsePendingResult has been moved into an extension method.
    • PreparatoryPass and MainPass have been replaced with FirstPass and SecondPass.
    • WindowInFocus processing will no longer throw an exception when focus change events are missing.
    • Generic event field parsing exceptions will no longer be thrown during processing. Instead they are thrown on access to the Fields property of the IGenericEvent. GenericEventSettings.SuppressFieldParsingExceptions has been removed.
    • MarkHandled and MarkWarning have been removed.

New Data Exposed

  • Streaming window-in-focus data as well as parsed events are now available via trace.UseStreaming().
  • UseClassicEvents() now provides all classic events, not just unhandled ones.
  • Previously the very last ContextSwitch on each processor was omitted from IContextSwitchDataSource.ContextSwitches, as the information about the thread switching in at that time was not present. Now these context switches are included in the list with a null value for IContextSwitch.SwitchIn.
  • A new HypervisorPartitionDataSource has been added that exposes data about the Hyper-V partition the trace was recorded in.
  • TraceTimestamp now provides a .DateTimeOffset property to get the absolute (clock) time for a timestamp.
  • Streaming Last Branch Record (LBR) events are now available via trace.UseStreaming().
  • Streaming ready thread events are now available via trace.UseStreaming().
  • Streaming syscall data as well as parsed events are now available via trace.UseStreaming().
  • Streaming context switch data as well as parsed events (both standard and compact) are now available via trace.UseStreaming().
  • Streaming scheduled task data as well as parsed events are now available via trace.UseStreaming().
  • IContextSwitchOut now contains Rank (only present for the non-legacy implementation).
  • IContextSwitchIn now contains WaitTime (only present for the non-legacy implementation).
  • IScheduledTask now provides user information.
  • NuGet packages for individual namespaces are now available in addition to the .All packages.
  • Streaming thread events are now available via trace.UseStreaming().
  • IThread now provides BasePriority, IOPriority PagePriority, ProcessorAffinity and ServiceId.

Bug Fixes

  • Thread IDs used for syscalls are now taken from a reliable data source.
  • An access violation that could occur on program exit has been fixed.

Other

  • TraceTimestamp now implements IComparable, IEquatable and multiple comparison operators.
  • An event consumer can cancel future event delivery by calling EventContext.Cancel().
  • Scheduled tasks now support the remaining trigger types.