Instrumenting Your Application to Measure its Performance Part 4 Using EventKeywords for Event Filtering

 

Introduction

In the last article, I demonstrated how to implement a class derived from EventSource for instrumenting a sales application called BizGear. In this article I’ll build upon that implementation to show you how to use the event keyword to filter specific areas of your application’s instrumentation.

You can find the source code to this article in my GitHub repository  BizGear

Many applications have multiple layers to separate responsibilities. In this demo, we’ll assume the application we’re instrumenting has three layers- the Presentation layer, the Business Logic layer, and the Data layer.

As discussed in previous articles, a large application often has multiple contexts of responsibility. A sales order application may have a part of the application responsible for sales processing, a part which handles merchandise returns, and a part for inventory management. Each context of responsibility spans across the multiple layers.

 

image

 

Sometimes you may want to enable event generation in all parts of your application. More often though, you will want to narrow event generation to specific areas of interest. One way to accomplish this narrowing is using the EventKeywords.

We’ll add to the EventSources project class and create a new class InventoryContextEventSource.

I want to show you is how to accomplish the following:

  • Generate events for each layer in a specific context.
    For example, capture events for the Sales context, in the vertical stack: Presentation, Business, and Data layers.

  • Filter for events on a specific layer for a specified context
    For example, capture events for the Sales context in only the Presentation Layer.
  • Filter for events on multiple contexts on different layers of the context.
    For example, capture events at the points noted by red stars:
    • Capture events for the Sales contexts in the Presentation layer and Business layers.
    • Capture events for the Inventory Context in the Business Layer
    • Capture events Merchandise Return Context in the Presentation and Data layers .

 

image

 

 


Project Updates

The first update we’ll make is extending the Keywords class in SalesContextEventSource.

Add two additional EventKeywords Business, DataAccess, and Service

Keywords
  1. public class Keywords
  2. {
  3.     public const EventKeywords Presentation = (EventKeywords)0x0001;
  4.     public const EventKeywords Business = (EventKeywords)0x0002;
  5.     public const EventKeywords DataAccess = (EventKeywords)0x0004;
  6.     public const EventKeywords Service = (EventKeywords)0x0008;
  7. }

 

Next, add two new methods to SalesContextEventSource, Business, Data, and Service. Be sure to increment the Event value for the three new methods and to match the values in the Event attribute and the WriteEvent() method. Your SalesContextEventSource class should appear similar to the following:

SalesContextEventSource
  1. //guid for this provider:  {d5b29467-62f5-54a9-4861-96cf631b95b4}
  2. [EventSource(Name = EventSourceNames.SalesContext)]
  3. public class SalesContextEventSource : EventSource
  4. {
  5.     public static readonly SalesContextEventSource Log = new SalesContextEventSource();
  6.  
  7.     [Event(1, Level = EventLevel.Informational, Keywords = Keywords.Presentation)]
  8.     public void Presentation(string className, string methodName, string data){ if (IsEnabled()) WriteEvent(1, className, methodName, data); }
  9.  
  10.     [Event(2, Level = EventLevel.Informational, Keywords = Keywords.Business)]
  11.     public void Business(string className, string methodName, string data) { if (IsEnabled()) WriteEvent(2, className, methodName, data); }
  12.  
  13.     [Event(3, Level = EventLevel.Informational, Keywords = Keywords.DataAccess)]
  14.     public void Data(string className, string methodName, string data) { if (IsEnabled()) WriteEvent(3, className, methodName, data); }
  15.  
  16.     [Event(4, Level = EventLevel.Informational, Keywords = Keywords.Service)]
  17.     public void Service(string className, string methodName, string data) { if (IsEnabled()) WriteEvent(4, className, methodName, data); }
  18.     
  19.     public class Keywords
  20.     {
  21.         public const EventKeywords Presentation = (EventKeywords)0x0001;
  22.         public const EventKeywords Business = (EventKeywords)0x0002;
  23.         public const EventKeywords DataAccess = (EventKeywords)0x0004;
  24.         public const EventKeywords Service = (EventKeywords)0x0008;
  25.     }
  26. }

 

Next, add two strings in the EventSourcesNames class for the names of the Inventory and Merchandise Returns contexts:

EventSourceNames
  1. public static class EventSourceNames
  2. {
  3.     //guid for this provider:  {d5b29467-62f5-54a9-4861-96cf631b95b4}
  4.     public const string SalesContext = "Acme-BizGear-SalesContext";
  5.  
  6.     //guid for this provider:  {9a9cf874-7496-5df5-6e80-1c5804eccd57}
  7.     public const string InventoryContext = "Acme-BizGear-InventoryContext";
  8.  
  9.     //guid for this provider:  {3e4539f0-447d-5791-0b48-ee4106c9ced8}
  10.     public const string MerchandiseReturnContext = "Acme-BizGear-MerchandiseReturnsContext";
  11. }

 

Next, add two new classes to the EventSources project: InventoryContextEventSource and MerchandiseReturnContextEventSource.

Your EventSources project should look similar to this:

image

 

At this point, the only significant difference between the event source classes is the class names. For expediency, you can copy and paste the contents of SalesContextEventSource to the InventoryContextEventSource and MerchandiseReturnContextEventSource files. Then rename the class names appropriately.

Your InventoryContextEventSource should look similar to the following:

InventoryContext
  1. //guid for this provider:  {9a9cf874-7496-5df5-6e80-1c5804eccd57}
  2. [EventSource(Name = EventSourceNames.InventoryContext)]
  3. public class InventoryContextEventSource : EventSource
  4. {
  5.     public static readonly InventoryContextEventSource Log = new InventoryContextEventSource();
  6.  
  7.     [Event(1, Level = EventLevel.Informational, Keywords = Keywords.Presentation)]
  8.     public void Presentation(string className, string methodName, string data) { if (IsEnabled()) WriteEvent(1, className, methodName, data); }
  9.  
  10.     [Event(2, Level = EventLevel.Informational, Keywords = Keywords.Business)]
  11.     public void Business(string className, string methodName, string data) { if (IsEnabled()) WriteEvent(2, className, methodName, data); }
  12.  
  13.     [Event(3, Level = EventLevel.Informational, Keywords = Keywords.DataAccess)]
  14.     public void Data(string className, string methodName, string data) { if (IsEnabled()) WriteEvent(3, className, methodName, data); }
  15.  
  16.     [Event(4, Level = EventLevel.Informational, Keywords = Keywords.Service)]
  17.     public void Service(string className, string methodName, string data) { if (IsEnabled()) WriteEvent(4, className, methodName, data); }
  18.  
  19.     public class Keywords
  20.     {
  21.         public const EventKeywords Presentation = (EventKeywords)0x0001;
  22.         public const EventKeywords Business = (EventKeywords)0x0002;
  23.         public const EventKeywords DataAccess = (EventKeywords)0x0004;
  24.         public const EventKeywords Service = (EventKeywords)0x0008;
  25.     }
  26. }

 

 


Enabling Multiple Providers

For your first test, you should verify that the three event providers – SalesContextEventSource, InventoryContextEventSource, and MerchandisReturnEventSource—will generate expected events.

First, modify the console application to call each event source:

Code Snippet
  1. private static void TestSalesLogging()
  2. {
  3.     var tstMsg1 = "111111111_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_";
  4.     var tstMsg2 = "123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_";
  5.     var tstMsg3 = "123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_";
  6.     var tstMsg4 = "123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_";
  7.     var tstMsg5 = "123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_";
  8.     var tstMsg6 = "123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_";
  9.     var tstMsg = tstMsg1 + tstMsg2 + tstMsg3 + tstMsg5;
  10.  
  11.     SalesContextEventSource.Log.Presentation("Sales_Presentation_className", "Sales_presentation_MethodName", tstMsg);
  12.     SalesContextEventSource.Log.Presentation("Sales_Presentation_className", "Sales_presentation_MethodName", "Sales presentation data");
  13.     SalesContextEventSource.Log.Business("Sales_Business_ClassName", "Sales_business_MethodName", "sales business Data");
  14.     SalesContextEventSource.Log.Data("Sales_Data_ClassName", "Sales_data access_MethodName", "sales data access data");
  15. }
  16.  
  17. private static void TestBusinessLogging()
  18. {
  19.     InventoryContextEventSource.Log.Presentation("Business_Presentation_className", "Business_presentation_MethodName", "Business presentation data");
  20.     InventoryContextEventSource.Log.Business("Business_Business_ClassName", "Business_business_MethodName", "Business business Data");
  21.     InventoryContextEventSource.Log.Data("Business_Data_ClassName", "Business_data access_MethodName", "Business data access data");
  22. }
  23.  
  24. private static void TestMerchandiseLogging()
  25. {
  26.     MerchandiseReturnContextEventSource.Log.Presentation("MerchandiseReturn_Presentation_className", "MerchandiseReturn_presentation_MethodName", "MerchandiseReturn presentation data");
  27.     MerchandiseReturnContextEventSource.Log.Business("MerchandiseReturn_MerchandiseReturn_ClassName", "MerchandiseReturn_MerchandiseReturn_MethodName", "MerchandiseReturn business Data");
  28.     MerchandiseReturnContextEventSource.Log.Data("MerchandiseReturn_Data_ClassName", "MerchandiseReturn_data access_MethodName", "MerchandiseReturn data access data");
  29. }

 

Next, modify the .cmd file so Logman enables an ETW session which listens to all three event sources.

To accomplish this, create a separate text file containing the even providers and tell Logman to use the configuration file.

Create a text file called providers.txt and enter the following three lines:

“{d5b29467-62f5-54a9-4861-96cf631b95b4}”
“{9a9cf874-7496-5df5-6e80-1c5804eccd57}”
“{3e4539f0-447d-5791-0b48-ee4106c9ced8}”

Next, create a new file called CreateBizGear.cmd and enter the following line into the file:

LOGMAN create trace BizGear -o C:\ETWTraces\BizGear.etl -pf providers.txt -f bincirc -max 1000

The –pf parameter tells Logman to reference the providers.txt file.

Enter Logman /query and you should see a Data Collector Set called BizGear.

Enter Logman /query BizGear and you should see output similar to the following screen capture:

image

 

In the above screen capture, notice that BizGear is configured to listen for the three event providers, for all keywords on each event provider, and the current status is stopped.

Enter Logman /start BizGear to enable the data collector.

Run the console application

Enter Logman /stop BizGear to stop listening for events and have ETW flush its buffers to the ETL file.

Start PerfView and open the generated ETL file. You should see all the events. In the following screen capture, I highlighted the events for the InventoryContext on the left and you can see the event data on the right:

image

Left hand pane:

image

Right hand pane:

image

 


Filtering Event Generation to Specific Layers

Consider a scenario where you want to generate events for only the SalesContextEventSource, Presentation layer.

Delete the current BizGear data collection by entering Logman /Delete BizGear.

Modify the providers.txt file to contain just the following line:

“{d5b29467-62f5-54a9-4861-96cf631b95b4}” 0xFFFFFFF1

Run CreateBizGear.cmd again to create the data collection. Notice that only the SalesContext event provider is configured, and the KeywordsAny is now set to “0xFFFFFF1”. (I’ll give more details later in this article why “0xFFFFFFF1” is used.

image

Enter Logman /start BizGear to start the collection. Run the console application. Stop event capture and flush the ETW buffers to the ETL file by entering Logman /stop BizGear

Run PerfView to examine the captured events:

image

Although the console application called event generation for all providers, only the SalesContextEventSource, in the Presentation layer, has generated an event.


Filtering multiple contexts, multiple layers

In this example we want to generate events for:

  • SalesContextEventSource: Presentation and Business Layer
  • InventoryContextEventSource: Business Layer
  • MerchandiseReturnContextEventSource: Presentation and Data Layer

First, delete the current BizGear data collector.

Next, enter the following lines in the file providers.txt (without the line wrapping)

“{d5b29467-62f5-54a9-4861-96cf631b95b4}” 0xFFFFFFF3 0x04
#Sales Context Presentation and Business Layer (1 | 2), level Informational

“{9a9cf874-7496-5df5-6e80-1c5804eccd57}” 0xFFFFFFF2 0x04
#Inventory Context Business layer (2), level informational

“{3e4539f0-447d-5791-0b48-ee4106c9ced8}” 0xFFFFFFF5 0x04
#Merchandise Context Presentation and Data layer (1 | 4), level Informational

The second value on each line specifies the keywords you want to enable for event generation.

Recall the keywords are 1 = Presentation, 2 = Business and 4 = Data Access.

To enable event generation for the Presentation and Business layer, do a logical “or” of 0x1 and 0x2 (turn off the bit for Data Access layer) for a result 0x3. 0xFFFFFFF3 which will enable logging for the Presentation and Business layer.

The third parameter on the line, 0x04, is the EventLevel to capture. EventLevels are set as:

  • Log Always (0x00)
  • Critical (0x01)
  • Error (0x02)
  • Warning (0x03)
  • Informational (0x04)
  • Verbose (0x05)

In your class files, you specified the event level Informational. You’ll set the same here, which is 0x04.

(In later examples I’ll show, you may want to configure event capturing for only Critical and Error events and ignore the Informational level events)

Run Logman /query BizGear and verify the level and KeywordsAny values are correct:

image

 

Start an ETW session by entering Logman /start BizGear

Run the console application again. Then stop the data collector.

Run PerfView to examine the current event captures:

In the left hand pane you should see:

image

And in the right hand pane:

image

As desired, our event generation is limited to

  • SalesContextEventSource, Presentation and Business Layer
  • InventoryContextEventSource, Business Layer
  • MerchandiseReturnContextEventSource, Presentation and Data Layer

At this point in the series of articles you’ve how to do the following:

  • Define event sources to capture events from different parts of your application
  • Use Logman to enable capturing all event in the application
  • Use Logman to filter specific areas of concerns in specific layers of your application.

Up to this point I’ve used a console application to simulate how different parts of your application would interface to the classes derived from EventSource.

In future articles, I’ll use a simple client application, built as a WPF application, using DLLs representing the Business Layer and Data Access layer, to show different ways we may use our event classes in a real application.

This entry was posted in ETW and tagged . Bookmark the permalink.

Leave a Reply

Your email address will not be published. Required fields are marked *


*