Table of Contents s178

EventSource Rich Event Payload Support
Spec Status: Complete / Last updated: 10/15/2015 4:33 AM
Product Unit / FEATURE TEAM

EventSource

Table of Contents

1. .NET V4.5 EventSource Payloads 1

2. Rich EventSource Payloads 1

2.1 Payloads and Serialzation 1

3. Transformation of Data in the EventListener 2

4. Rich Payloads an Event Tracing For Windows (ETW) 3

5. Complex Example 4

6. Guidance 6

Page 4

1. .NET V4.5 EventSource Payloads

When EventSource was introduced in the V4.5 version of the .NET Runtime, it supported the following payloads

1) Primitive types (bool, byte, short, char, int, long, float, double)

2) string, DateTime, Guid

This is sufficient for a broad range of event payloads. However from time to time it is useful to log more complex data that contains arrays or sub-records. (or more typically arrays of sub-records). In the .NET V4.6 library (or Version 1.1 of the EventSource Nuget Package), EventSource supports rich data payloads that include arrays and records.

2. Rich EventSource Payloads

Since Version 4.6, the rules have changed as follows

A valid EventSource payload type T is

1) A type permitted in .NET V4.5

Primitive types (bool, byte, short, char, int, long, float, double)
string, DateTime, Guid

2) An IEnumerable<T1> where T1 is an EventSource payload type.

3) A class that is either

Is decorated with the System.Diagnostics.Tracing.EventDataAttribute
Is decorated with the System.Runtime.CompilerServices.CompilerGeneratedAttribute

In addition all public properties on the class are EventSource payloads types.

4) Is the System.Collections.Generic.KeyValuePair<string,T1> where T1 is a EventSource payload type

These rules have the following implications

1) Since Arrays are IEnumerable, rule (2) implies arrays are valid

2) Since anonymous types (e.g. new { field1=3, field2=”hi” }, are decorated by the compiler with the CompilerGeneratedAttribute attribute, rule (3b) imply that anonymous types are also valid EventSource payloads if their fields are.

3) Since Dictionaries (or IDictionary) with a string key are IEnumerable<KeyValuePair<string, T> rule (2) and (4) imply that Dictionary<string T> is a valid EventSource payload type if T is.

The simple way of internalizing this is that EventSource support a form of ‘typed JSON’. This capability makes it roughly as expressive as both JSON and XML.

2.1 Payloads and Serialzation

A common question is why do EventSource types need to be decorated with the ‘EventDataAttribute’? The answer is in the presumption of serialization. A logging system really is expected to rather quickly just ‘outside’ the process, either by writing its data to a file or by sending it to some other process or machine or database for processing. In general serialization of an arbitrary .NET type is simply impossible. Thus in general passing an arbitrary type to EventSource is an error that we wish to catch. We can do this if we require types to ‘opt in’ by attaching an EventDataAttribute to its declaration. Attaching this attribute declares that the type

1) Follows the rules for a valid EventSource type

2) Object Identity is not used by the type (it is just a container of values).

3) No instance will passed that has cycles in its object graph.

3. Transformation of Data in the EventListener

So it is now possible to do something like this

// define a ‘plain old data’ class

[EventData]

class SimpleData {

public string Name { get; set; }

public int Address { get; set; }

}

[EventSource(Name = "Samples-EventSourceDemos-RuntimeDemo")]

public sealed class RuntimeDemoEventSource : EventSource

{

// define the singleton instance of the event source

public static RuntimeDemoEventSource Log = new RuntimeDemoEventSource();

// define a new event.

public void LogSimpleData(string message, SimpleData data) { WriteEvent(1, message, data); }

}

And call it like this

RuntimeDemoEventSource.Log.LogSimpleData(

"testMessage",

new SimpleData() { Name = "aName", Address = 234 });

There could then be a Listener which subscribes to it as so

class MyListener : EventListener

{

// Turn on RuntimeDemo EventSource the instant we learn about it.

protected override void OnEventSourceCreated(EventSource eventSource)

{

if (eventSource.Name == "Samples-EventSourceDemos-RuntimeDemo")

EnableEvents(eventSource, EventLevel.Informational);

}

// Gets called each time an event is written.

protected override void OnEventWritten(EventWrittenEventArgs eventData)

{

if (eventData.EventName == "LogSimple")

{

var name = (string)eventData.Payload[0];

var simpleData = (IDictionary<string, object>) eventData.Payload[1];

string simpleDataNameField = (string) simpleData["Name"];

int simpleDataAddressField = (int)simpleData["Address"];

}

As a review of how EvenListeners work, you subscribe to events by creating a subclass of the EventListener class. This class will call ‘OnEventSourceCreated’ each time a new EventSource comes into existence (or was in existence when the EventListener was created). This gives the EventListener an opportunity to subscribe to the EventSource. If it does subscribe (as we do in the example above), the ‘OnEventWritten’ will be called for each event. The EventWrittenEventArgs contains all the information about the event, and in particular the ‘Payload’ List. This list will have entry for each payload field (in order). Thus for the example above Payload[0] will correspond to the ‘message’ parameter and Payload[1] will correspond to the ‘data’ parameter.

The question is ‘what is the type of Payload[1]? The ‘obvious’ answer is that it would be an instance of the ‘SimpleData’ however that has a number of problematic consequences

1) It couples the Listener processing code to the code being instrumented. This is typically problematic because Listeners and Instrumentation code are maintained by separate groups and version at different rates. Using types defined in the instrumented code in the EventListener logic tightly couples that code to the code being instrumented, causing deployment grief.

2) It works very poorly for anonymous types. Anonymous types don’t have names, which means you can’t cast to it, which means you can’t get at the fields. You have to use reflection which is pretty unfortunate.

3) Building a generic logger is complex. If you simply wanted to pretty print the data in a sensible way (e.g. dump it in JSON syntax, a likely scenario), this would require reasonably complex reflection.

So instead EventSource uniformly returns an IDictionary<string, object> as the type of payload whenever a class is passed. Thus you need to cast to this type, and the fetch the field by looking up by the field name. This allows the processing code to be independent of the types that were passed to the EventSource. As a side effect, it also solves issues (2) and (3) above.

This transformation drives home an important point

· Objects passed through EventSource are to only be used for data contained in them. In particular object identity is not preserved and should not be relied on.

4. Rich Payloads an Event Tracing For Windows (ETW)

Existing Manifest-based ETW does not fully support rich payloads. For this reason EventSource’s ETW listener does not support Rich Payloads unless it is being serialized using the EtwSelfDescribingEventFormat. Thus you need to either use the Write<T> API (which always uses that format), or you need to add a declaration in the constructor of your EventSource to ask that the self-describing format be used instead of the Manifest based format. Thus we add the code in red below to our example:

[EventSource(Name = "Samples-EventSourceDemos-RuntimeDemo")]

public sealed class RuntimeDemoEventSource : EventSource

{

// Rich payloads only work when the self-describing format

private RuntimeDemoEventSource() : base(EventSourceSettings.EtwSelfDescribingEventFormat) { }

// define the singleton instance of the event source

public static RuntimeDemoEventSource Log = new RuntimeDemoEventSource();

// define a new event.

public void LogSimpleData(string message, SimpleData data) { WriteEvent(1, message, data); }

}

This new self-describing event format is relatively new. At the present time (8/2015) the self-describing events are supported in

1) Versions of Windows Performance Toolkit WPR.exe with a major version > 10

2) In PerfView performance tool Version 1.7.28 or later (V1.8 to be published by 9/2015)

3) By the OS TDH APIs, for Windows 10 (or backported to Windows 8 or 7)

4) The .NET ETW parsing package TraceEvent Nuget Package Version 1.1.35 or later. See this blog for a walk-through of samples.

5. Complex Example

So far we have shown only one of the more trivial examples of EventSource’s expanded data payload capability. Here we give a more complex example where we log

1) LogArray : passing an list of integers

2) LogNode: pass NodeData class that has inside it arrays an dictionaries

3) LogDictionary: passing a dictionary (which gets logged as a list of key-value pairs)

For the example we need to define our Node structure that we wish to log

// In this example we might be logging a node in a graph, whose value is reasonably complex.

[EventData]

public class NodeData

{

public string NodeName { get; set; }

public int NodeId { get; set; }

public int[] ChildNodeIds { get; set; }

public Dictionarystring, int> UserValues { get; set; }

}

And we define the LogArray, LogNode, and LogDictionary methods in the EventSource. In addition to the complex data value, we also pass a string ‘message’ value (just to show we can do it).

[EventSource(Name = "Samples-EventSourceDemos-RuntimeDemo")]

public sealed class RuntimeDemoEventSource : EventSource

{

// define the Load Event. Calling this method logs the event

public void LogSimpleData(string message, SimpleData data) { WriteEvent(1, message, data); }

public void LogArray(string message, IEnumerableint> data) { WriteEvent(2, message, data); }

public void LogNode(string message, NodeData data) { WriteEvent(3, message, data); }

public void LogDictionary(string message, Dictionarystring, int> keyValues)

{ WriteEvent(4, message, keyValues); }

// define the singleton instance of the event source

public static RuntimeDemoEventSource Log = new RuntimeDemoEventSource();

private RuntimeDemoEventSource() : base(EventSourceSettings.EtwSelfDescribingEventFormat) { }

}

And then call these logging methods on made-up data.

// Make up some values that you wish to log.

var aList = new Listint>() { 3, 4, 5, 6 };

var aDictionary = new Dictionarystring, int>() { { "user1", 1 }, { "user2", 2 } };

var aNode = new NodeData

{

NodeName = "Test",

NodeId = 1,

ChildNodeIds = new int[] { 3, 4, 5 },

UserValues = aDictionary

};

// Logging the complex values above.

RuntimeDemoEventSource.Log.LogArray("testMessage", aList);

RuntimeDemoEventSource.Log.LogDictionary("testMessage", aDictionary);

RuntimeDemoEventSource.Log.LogNode("testMessage", aNode);

Which completes the instrumentation code. We can then set up our EventListener to process these events. It works pretty much as expected, switching on the payload name and then casting each of the payload arguments to what it gets transformed to (in the case of a node, an IDictionary<string, object>). However in the case of serializing a Dictionary (done both in the LogDictionary event and the ‘UserValues’ field of LogNode event), we use a helper function DictionaryfromKeyValues.

// Gets called each time an event is written.

protected override void OnEventWritten(EventWrittenEventArgs eventData)

{

switch (eventData.EventName)

{

case "LogArray": {

string name = (string)eventData.Payload[0];

var arrayValues = (IEnumerableint>) eventData.Payload[1];

foreach(int arrayValue in arrayValues)

{

// Process a value in the array.

}

} break;

case "LogNode":

{

string name = (string)eventData.Payload[0];

var node = (IDictionarystring, object>) eventData.Payload[1];

var nodeName = node["Name"];

var nodeID = (int)node["NodeId"];

var childrenIDs = (IEnumerableint>)node["ChildrenIds"];

var userValues = DictionaryFromKeyValues(node["UserValues"]);

// Process the Node

} break;

case "LogDictionary": {

string name = (string) eventData.Payload[0];

var keyValues = DictionaryFromKeyValues(eventData.Payload[1]);

// Process the Dictionary

break;

}

The reason for this is because a dictionary is not handled specially by EventSource. It is simply serializing it as a list of Key-Value Pairs using its default algorithm. Thus the dictionary

var TestDict = new Dictionarystring, int> { { "value1", 1 }, { "value2", 2 } };

Comes out in the EventListener as a List of Dictionaries where each dictionary represents one key value pair. Thus it looks like so.

var Morphed = new ListDictionarystring, object> {

new Dictionarystring, object> {

{ "key", "value1" },

{ "value", 1 }

new Dictionarystring, object> {

{ "key", "value2" },

{ "value", 2 }

}

};

This is typically inconvenient, so the DictionaryFromKeyValues function morphs it back to what it was before it was serialized. The code that does this is reasonably straightforward.

/// <summary>

/// Take an EventSource serialized dictionary (which is a list of key-value pair classes)

/// and return a dictionary that has those elements in it.

/// </summary>

private Dictionarystring, object> DictionaryFromKeyValues(object dictionary)

{

var ret = new Dictionarystring, object>();

foreach (var item in dictionary as IEnumerableobject>)

{

var keyValue = item as IDictionarystring, object>;

ret.Add((string)keyValue["Key"], keyValue["Value"]);

}

return ret;

}

If serializing a Dictionary is common enough, EventSource will probably supply this function as a convenience routine.

6. Guidance

We have seen that in .NET V4.6 (and the EventSource Nuget package 1.1), have significantly extended the kinds of payloads you can have. It does come with caveats however

1) Event Processing is slower. This is fine if the events are happening 100X a second or less, but if the events are firing thousands of times or more, it is probably going to be noticeable. You should be avoiding rich payloads in verbose events.

2) ETW only supports the rich payloads if you use the Self-Describing Event format. This is not a concern if you are using EventListeners rather than ETW as your event sink.