Using Win ADK's Windows Performance Analyzer with EventSource

This is the third post in our discussion regarding the use of ETW tools with EventSource API in .net framework 4.5. In the previous posts, we have discussed how we can use PerfView (link), LogMan, PerfMon, PerfMonitor and TraceRpt with our EventSource (link). This post is about using Windows Performance Analyzer.

Windows Performance Analyzer can be used to analyze ETL [Event Trace Log] files. These ETL files can be generated from any ETW tool including PerfView, XPerf or Windows Performance Recorder (WPR). Here XPerf is a legacy ETW tool. PerfView is available as a separated single file download from Microsoft Download Center.



Here WPR and WPA are part of Windows Performance Toolkit, which can be installed with Windows ADK (Assessment & Deployment Toolkit). The toolkit can be downloaded from Microsoft's Download Center.



Just make sure that Windows Performance toolkit is installed by the installer.



After installation, you should see the toolkit in the start menu. There are two tools including Windows Performance Analyzer (WPA) and Windows Performance Recorder (WPR).



Let's use PerfView to generate ETL file for ETW events generated for a sample application. Now WPA relies on additional specific events in ETL files when a trace is stopped. The release version of PerfView doesn't generate those events in the file but there is a separate download from Vance Morrison's blog. Hopefully, this feature should be added to the release version soon.



We need to run PerfView with Admin Privileges. We have a very simple application which just writes a couple of events to ETW and exits. PerfView should be able to push those events to ETL file. But first let's first look at event's data with Activity Id (s) and RelatedActivity Id (s).



Just look at the extra events generated from Morrison's PerfView in order to support WPA.



PerfView generates the ETL file in the same folder by default. It is in compressed format. We can decompress and open the ETL file in Windows Performance Analyzer. We can drop the Generic Events to Analysis view to see the details about particular events and their order. I think this can be improved further as you still don't see activity and related activity Ids here.



Download

   

Transfer Events & Activity Based Logging using EventSource .net 4.5.1

Logs are never looked at in isolation. If we need to look at the log in order to determine the root cause of a problem then it is a particular scenario that we are interested in. With the great testing efforts we do before releasing a product, there might be still some dormant issues which might have been missed. But since they are not apparent and not very easy to reproduce, we are specially interested in the particular order of operations user performed in order to uncover the dormant issue. We need end-to-end tracing support for our .net applications.

Enterprise applications never work in isolation. We have learnt that there cannot ever be a global enterprise system which deals with everything in the Enterprise. So these applications and machines work together in order to accomplish an enterprise operation. That is why everyone has started talking about enterprise integration, I think this would continue to grow.It is possible that our applications perform great in isolation but there are issues when they work together. The only way to uncover such issues is to use the same logging using some identifiers so that we could correlate these operations to understand the scenario.

ETW has long supported the scenario based logging using Transfer Events. You can even find some reference in Park & Buch's article published in 2007 in msdn magazine. The support is provided through tagging these events with Activity Id. The technology supports a scenario based Id (Activity Id), with a related Activity Id for each event.



When .net framework 4.5 was released, the transfer events were missing from the API. EventSource API is based on Manifest based ETW providers rather than the classic provider (no need to register events at install time). This feature has been there for both of these provider. Since technology already supports it, it was just a matter of time to include the support in the API, and .net 4.5.1 does include that support now.

Improvements in EventSource API to support Transfer Events
In order to support transfer events, Microsoft has provided various little updates in EventSource API in .net 4.5.1. Let's start with the EventSource type itself. In order to identify scenario, EventSource is provided with a new property called CurrentThreadActivity. This can be used as the Activity Id for a particular scenario. This is a read-only property. In order to specify the value, there are two modifier methods. This is one of the biggest improvement in .net framework 4.5.1. This is strategic.



We use WriteEvent() method in [Event] methods in order to write events data to ETW infrastructure. There are two new WriteEvent() methods introduced by the same type to include related Activity Id for the operation. The latter of the following methods provides better performance.



Both of these Ids are available through EventWrittenEventArgs in EventListener's OnEventWritten() method. There are two new properties added to the type. The ActivityId is the same as the CurrentActivityId value for the EventSource when WriteEvent() is called; and RelatedActivityId is the value passed as one of the argument to the method.



Sample Event Source with Transfer Events
Let's create a sample C# application using .net framework 4.5.1. Here we are using Visual Studio 2013 RC. The EventSource has two event methods; one of which is TransferEventEx which uses activity Ids.


And here is an EventListener using AcitivityId and RelatedActivityId from EventWrittenEventArgs.


Now we can use the above EventListener to enable the events written using MyEventSource. First we need to set the ActivityId for the scenario, then we need to specify the operation based Id; used as RelatedActivityId.


Transfer Events for Inter-application Enterprise Scenarios
As stated in the beginning, the real benefit of transfer events can be observed tracing end-to-end scenarios performed across application boundaries. The following is an example of a scenario identified by an Id = X (Activity Id). There are three related activities in the scenario tagged with related activity Id (s) identified with A, B and C. These applications can use ETW for their event logs. For the case of EventSource (manifest based provider), these events can be picked up by a central Semantic Logging Service. The data for these events can be pushed to an event store or any other sink of interest.



Download

October 2013, What a month this has been...

October is about to pass. But what an amazing months it has been...

The greatest skill a developer has to have is to adjust within a group of people. Believe me, this is even difficult than developing a technical skill. Interpersonal communication is a craft and one needs to master it in order to better survive for selling the ideas. Since we are in the business of consulting for software services, we need to move between organizations every few months and years. Not all the people are welcoming, they have different psychologies and motivations. These events prove to be a practice. You need to go to the venue, introduce yourself, present in the presence of total strangers - you have no idea about their backgrounds.

Few Advices & Lessons Learned
Humor is an interpersonal lubricant. Since we are interacting with the audience for the first time, we need to break the barrier of being strange. Humor is the universal lubrication of friction between people. You are never strange for the people who smile with you. Although this is the most effective technique, but this can go either way. You need to pull off the joke really well. Like an actor, the punch line has to be effective. Practice it, tell it a few times to your friends no matter how annoying they become.

One must go through the session material before the session. I have realized that we try to be very detail oriented when are creating slides for our presentation. These conferences and code camps are not class room sessions. People are interested in links and ideas they can take home. This give them direction for their technical development. We need to give them as much as possible in the limited time we have. But the most important thing is to motivate them enough about the stuff that they study further after the event. We need to be fresh for the event, so take a nap before the event.

We can also record the session if possible. This is one of the take away item for yourself. A recorded session can be useful for preparing yourself if you are speaking about the same stuff later on. This is specially useful if you have been away focusing on some other technological stuff for a few months. You can also publish them for general audience if you think this might help them learning about the topic.

We must time box our session. A session has a list of agenda items. We need to make sure that we time box the agenda so that we are able to cover each item and still be able to finish our session in time. If there is an item which is taking more time, tell about some pointers the audience might take away with them. We must also be ourselves, confident and to the point. Call your family or friend for a little chit chat in the morning.

Session Slides
I have presented my thoughts and ideas over two areas from a huge list of Microsoft technology stack. They are as follows:

1. Cross Platform Development using Portable Class Libraries
2. Event Source API, ETW and Semantic Logging Application Block

I have uploaded the session slides on my sky drive. You can view it here or download it if you want to view them offline.



Session Videos
Here are the session videos from the events in Silicon Valley, Boston and Southwest Florida Code camps.

semanticLogs from Muhammad Siddiqi on Vimeo.

Portable Class Libraries - Boston Codecamp 20 from Muhammad Siddiqi on Vimeo.

slab from Muhammad Siddiqi on Vimeo.

Cross Platform Development with Portable Class Libraries from Muhammad Siddiqi on Vimeo.

Download Code
You can also download the code from these sessions. I even uploaded that to my sky drive.

EventSource & Performance for High Volume Events

.net framework 4.5 introduced EventSource API to write events using ETW infrastructure. The choice of ETW infrastructure has made the writing of events lightning fast. Now they can be consumed by any ETW consumer. If the event provider is not enabled, then the events just fall on the floor. On the other hand, if a session is already established, they are written to ETW session buffers. Now they can be consumed by the consumers. The event provider (EventSource) doesn't really have to wait until the messages are consumed. This is independent on the number of consumers registered for a particular type of events. We have discussed about ETW tools and their usage with EventSource API [Reference].



As we discussed above, the choice of ETW infrastructure has made EventSource API extremely fast. But we can even improve on it further. But remember that these recommendations would be useful in the case for high volume events generally. For low frequency events, although you would have performance improvement, but this might not be very noticeable.

Optimization # 1: Use IsEnabled() before WriteEvent()
ETW controllers can enable a provider before registration of provider. So when a provider registers itself and starts emitting events, a session is automatically created and they are forwarded to the buffer. In order to prove that, we can start Semantic Logging Service (from Application Block) and then run our application. Our service should still be able to consume the events. On the other hand, if the provider is not enabled, the events just fall on the floor by the ETW infrastructure. In order to improve it, we can check if the event provider is enabled so that we don't even use the WriteEvent() definition in base class. It does check the same thing in the base class as well.

When an Event Provider is enabled (generated for EventSource), it receives a command to enable itself. We can even use this command in our custom EventSource by overriding OnEventCommand() method. You don't need to use the definition of base class method as there is an empty implementation of the virtual method.



It caches this in a local variable. So EventSource can use this field to check if it is enabled. There is no property available in EventSource type to check that but we can find IsEnabled() method to do just that. Now a method might cause some confusion for you thinking it might be slow as it might do some other stuff and could slow it down further. As the development team suggests, it is just a field fetch. We can also verify this by dotPeeking into the framework assembly from Windows folder.



As a matter of fact there are two overloads of the method. One of these overloads is parameter less. The other one is more interesting, it lets us check if the provider is enabled for a particular level and keyword, which makes it more interesting.



Optimization # 2: Convert static field fetch to local member fetch
This suggestion is not for EventSource implementation but it refers to the use of EventSource instance in the logging site. The logging site is the code from where we call EventSource's methods. As we have seen several examples in this blog, EventSource implementation is singleton based [See singleton], it is a static variable fetch at the call site. Here is an example of the usage:



As we know static variable fetch is more expensive than an instance member fetch, we can assign the singleton instance to a local instance member. In order to improve the usage of EventSource's method, we can assign this to a local variable. Then we can use the local member at the logging site.



Optimization #3: Minimize the number of EventSources in the application
In a previous post, we discussed about the mapping between EventSource and ETW Event providers. Actually the framework registers an Event Provider in ETW infrastructure for every EventSource in the application. This is done using ETW EventRegister API. This allows the framework to pass a command to the EventSource from external controllers.

The framework also maintains a list of EventSources in the application domain. We can get the list of all EventSource (s) in the application domain using the static GetSources() method in EventSource type.



Both of these tasks are performed at startup. Since this would depend on the number of EventSource (s) in the applications so the higher number for event sources in your application would mean slower startup. This can be resolved by minimizing the number of EventSource in your application. I would definitely not suggest an EventSource for each type in your application. There can be two options to resolve this.

The first option is using Partial types. We can span the same type across different files in the same assembly. All of these definitions are combined to generate a consolidated type by the compiler. We generally organize our types in different folders in a project. Here each folder generally represents types belonging to the same group. We can provide all the event methods definition for the method group for the types in this folder.

Most of the real life projects span more than one projects. In this case, we should still be able to minimize the number of EventSource (s), by defining on for each group, in order to improve the startup performance. Here each event source can take care of instrumentation requirement for a group of types in your application. You can group them logically or the way you want.

Optimization # 4: Avoid fallback WriteEvent method with Object Array Parameter
There are various overloads of WriteEvent() methods in EventSource type. We need to call WriteEvent() method from our [Event] methods in EventSource type. One of these overloads is an overload with params array. If none of the overload matches your call then the compiler automatically falls back to this overload.



We should be avoiding the fallback method as much as possible for performance reasons as it is reported to be 10-20 times more expensive. This is because the arguments need to cast to object, an array needs to be allocated and these casted arguments are added to the array. Then calling the methods with these arguments as serialized.

In order to avoid using the fallback overload, we can introduce new WriteEvent() method by overriding it.

SLAB, EventSource and Standard ETW Tools

As we have been discussing through the past few posts that we can direct event log data generated through EventSource to be saved in different destinations. EntLib6 provides a number of sinks provided just for that purpose out of the box. They include support for console, files, Sql Server database and Windows Azure Table storage. We have also seen how we can direct the event's data to Windows Event Log [Discussion]. It would be interesting to see how we can use the existing ETW tools to view the event's data generated using EventSource API in .net framework 4.5.

EventSource API is based on registration free ETW [Event Tracing for Windows] data. This means we don't have to register an ETW event provider for generation and consumption of these events. The existing tools including LogMan and Windows Performance Analyzer are based on registered event providers. But since EventSource API is still based on the same ETW infrastructure, we can register the Event Provider manually and direct the events' data to an ETL file. Since these tools can work with this format, we can use our expertise in these tools to troubleshoot and analyzer situations we need this data for.

It must be remembered that EventSource API uses ETW infrastructure only in the case of out-proc listeners.

Performance Monitor [Perfmon.exe]
Since EventSource establishes an ETW session for out-proc consumers, we should be able to use PerfMon to see the details of the session.



As an ETW provider, each event source is assigned with a GUID. We can note the unique identifier from the properties of the provider. This identifier is generally used by ETW controllers to start / stop a session. We can also verify that the streaming mode for the configured EventSource as Real time.



PerfMonitor.exe
Like PerfView, PerfMonitor is also based on TraceEvent library. The major benefit of PerfMonitor over Perfmon is that the former can be used as an ETW controller.



https://bcl.codeplex.com/releases/view/99985

Logman
Internally Logman seems to use Performance Logs & Alerts service. If the service is not running, the utility just starts this. Make sure that we are running the command prompt with Administrative privileges.



Here we are creating a trace data collector using Logman utility.


After running the above command, we should be able to find the specified collector when queried. This can also be done using Logman. The utility supports a verb "query" which list all the data collectors.



We need to start the data collection for the events generated from the event provider. In order to do that we can use Logman's start verb with the provider's name as follows:

Querying the provider again should show the status of the provider as Running. This should ensure that the command ran successfully.



Stopping the trace session should flush the trace data in the ETL file. Here is the file generated for our provider in the same folder as we specified while creating trace data collection for the provider.



Logman also registers a user-defined trace which can be viewed with Performance Monitor.



Tracerpt
This is another useful Windows Utility for ETW data. One of the usage for this utility could be to process the ETL files generated using any other tool. It can be used to generate human readable files from the binary data. Let's see the following usage:


The above command should generate dumpfile.xml and summary.txt in the same folder. For the events generated for our event provider, the following files are generated. You can open them to have an idea about the expected format for the generated files. We should note that the utility allows us to control the names and format of dump and summary file names and formats. The supported formats for dump file include XML (default), CSV and EVTX.

  

We can also generate xml (default) or html based report for the generated events data. Here we are generating the report in html format. It generates the report based on the etl file provided in the same command.


You can have a look at the following report generated for events generated from our event source.



Tracerpt can also use ETW data from real time sessions. We can use PerfMon to determine the session we are interested in. We can then use the same name with -rt switch for TraceRpt. Here is the session details for our event source.

EntLib6 - EventSource & Keywords for Semantic Logs

In this post we are going to discuss two very common details for defining event source. They are EventLevel and EventKeyword. They are so central for defining and enabling events. Yet, it is very easy to make mistake in using or expecting a particular behavior with the values used for them. The value assigned to them might include other values as well, which might come as a surprise for others.

Event Level
As we discussed, the event level selected for enabling a listener is the maximum value of the level which would be forwarded to the subscribed sinks. All events assigned with levels equal or lesser than the assigned enumeration values are considered enabled.

I have really felt that intellisence is not really useful in this case. The levels are ordered in the ascending order of their names. It could have been really useful if they could be available in the order of their values [but there are some things in life you cannot get, hence the void... :)]



Let us try to make it a little easier. We can come up with an acronym like from top to bottom, it is VIWECL. In order to remember this, we can come up with some catchy phrase like Very Intelligent Wife so Extremely Cool Life. Here whatever level we specify to enable the event source, all the lower levels are automatically included. I think we should not forget it now. When someone special is involved, it is better to try not to forget...



Keywords As Power of 2
It must be remembered that keywords must be assigned values in power of 2. It makes it easier to enable and disable the events. Here is an inner class Keywords defined in an EventSource. You can see that the values are 1, 2, 4, 8. They are powers of 0, 1, 2, 3 respectively.


In order to understand how we can use these keywords, we need to understand the bit mask for these keywords. We have the bit masks for Creation, AdmissionApproved, FeeDeposited and TransferCreditHours.



Definition of EventSource
Let us introduce an EventSource. The event source has four [Event] based methods. The methods are using the values of keywords defined above. They are also assigned with particular


Special Event Level & Keyword
EventLevel.LogAlways has special meaning when we use it to enable the events. It means to ignore levels when filtering is being applied i.e. all levels are considered. Since this is a perfectly fine EventLevel value which could be assigned to an Event method, it might get confusing when you would just want to enable the events assigned to this level, as it has a specific mean in this scenario. I think we should better avoid it when defining our events. I still have this in my EventSource just to give you an example.

Similar is the case for Keywords.All. It means to include all keywords. Basically, when we don't specify an Keyword to enable a scenario, all those events which are assigned with a specific value of keywords are just ignored. If we want to consider all of them instead, we can use this value for EventKeyword when enabling events. It has a value -1. We can use this value for enabling all keywords with xml configuration in the case of Semantic Logging Service configuration.

Configuration for In-Proc usage
As we have discussed before we can use SLAB both In-Proc and Out-Proc scenarios. For the In-Proc scenarios, we can enable the events using ObservableEventListener specifying the details of event's levels and keywords we are specially interested in. Let's first consider the case of specials for level and keyword. Here we are using EventLevel.Always and Keyword.All, which means to say, I want to log everything.


And it does have all the logs, no matter what Level or Keywords they are assigned with. Here is the output for the above code:



EventLevel.LogAlways with other keywords
Let's see the following combination. Here we are using EventLevel.LogAlways with two keywords.


If you go back and look at the definition of our EventSource, we don't have this combination of Level and Keywords for any event. There is only one event with Level assigned as EventLevel.LogAlways, but that has different keyword assigned.

So does it mean, it should include none of the events? Acutally No!!!

As we have discussed before, it has a special meaning the case when we are enabling event. It means to ignore whatever value of level assigned to events. In other words, just use the keywords specified for enabling the events. So it should just enable the two events, defined with the specified keywords. If we run this code, it shows the following output:



Level is the Max Level for Events
As we have discussed in the stairs diagram for Events. The event level assigned is the maximum value for the EventLevel considered for logging. In the following example, we are using EventLevel.Error for enabling the event. If we look at the diagram, we should realize, it would automatically include EventLevel.Critical and EventLevel.LogAlways. Let's change the configuration as follows:


As expected, it includes events assigned with levels as EventLevel.Error, EventLevel.Critical and EventLevel.LogAlways. Here is the output:



-matchAnyKeyword for Out-Proc Configuration
We can use a similar configuration for Out-Proc scenario. In the Semantic Logging service provided by Semantic Logging Application Block, matchAnyKeyword attribute is provided for source configuration. The value assigned to this keyword is treated differently. It is the sum of all keywords we want to enable. Here we want to enable Keyword.Creation and Keyword.AdmissionApproved. We need to just add the two numbers to calculate the value which should be assigned to the attribute. We can also use bit calculation by masking the two keyword bits. We can then convert the value in decimal as follows:



Let's use this in the configuration for the service. Here we are interested in the events with maximum level assigned as EventLevel.Informational. We are specially interested in the two keywords specified above.


Since we are using Windows Azure Sink with Storage Simulator, we should be able to see the following events logged in SLAB table.



Download

EntLib6 SLAB - Events Versioning

Semantic Logging Application Block's main focus is event consumption. It is based on EventSource introduced in .net framework 4.5. It allows these events to be consumed In-Proc and Out-Proc. But no system is free from any changes. Logging should also accommodate system changes. EventSource allows its events to be tagged with version numbers. This is part of metadata defined for the [Event] methods.

Let's assume we deploy the example application as developed in previous example. After two months the client calls and asks if we could add an additional fields to Students. The field would be used to record Age of student. Since student creation is being logged, we would need to log this information as well. In this post we will be trying to accommodate this change.


It is also possible that we might need to add additional methods to the EventSource due to additional logging needs. We need to make sure that we are assigning them appropriate keywords and levels as expected by the downstream consumption system. As discussed before, they can also be outside the system.

Versioning & EventSource
We must remember that these versions cannot co-exist in an overloaded fashion in an EventSource as in the following code. As we have discussed before, these methods map to the Event Types for ETW infrastructure, it would generate a duplicate key, which is not allowed.


Here we have just overloaded StudentCreatedCore() method decorated with EventAttribute. It has an additional parameter studentName. Here we have kept the Id as same for the Event but included Version with some value assigned. We have also added the similar property in the other overloaded method. In the public method, we are deciding which method to use based on certain condition. The world is really a happy place to live...

Let's see how our unit test behave in this case. Hmm, it fails with the details about possible issue at runtime because of more that one events with the same name.



Let me tell you that the code compiles just fine in this case. This is to save us from experiencing an exception at runtime and then cursing ourselves for missing the obvious.



Let's update the definition of the EventSource removing the earlier version of the [Event] method.


Versioning & Events Consumption
Since Events are generated to be consumed In-Proc or Out-Proc systems. The events detail can be used by automation system to generate reports and notifications for the infrastructure and management teams responsible for the health and monitoring for the system. They expect a certain payload and message format. Since they can be persisted, the data for historic and current payload structure would co-exist in the persistence storage. They need some way to decide what format to use based on some data. Version is the best candidate for this. The reports can use versioning to decide which payload format should be used by the automation system. We must remember that we cannot enable / disable the events based on versions or even [Event].

Let's update the configuration of Semantic Logging Service for the update. Here we are adding an Azure Sink. The sink is enabled for the EventSource defined above for all the events with a maximum level set as Informational.


As we generate these events in the source system. They are provided to the Semantic Logging Service by the ETW infrastructure. TracingService hooks up to the ETW infrastructure for these events. As the events are received they are passed to the avaiable sinks. These sinks are utilized based on their configuration of the events source and keywords they are interested in. For our events, they are pushed to the azure development table storage. Just notice the payload for the new version and old version. In this way, they can be easily identified and operated on.



Download

Enterprise Library 6 - SLAB - Supporting Complex Types for Payload

Previously we have discussed there are only certain primitive types supported by EventSource introduced in .net framework 4.5. This post is an attempt how we can work around this limitation. Actually, we can decorate EventSource methods with [Event] and [NonEvent] attributes. The other most important point is the following:

[Event] methods can be private.

We can use this to only include private [Event] methods which would be used to generate ETW manifest from the EventSource. Additionally we can introduce public methods in the EventSource type supporting the non-primitive custom type as parameters. Hence these object-oriented types make writing the logs easier without putting any load on the underlying infrastructure supporting the event mechanism.

Let's create a sample C# project targeting .net framework 4.5. We add a type EventSourceWithComplexType to the project. As you can see below this is an EventSource. Here we are using Lazy initialization introduced in .net framework 4.0 for singleton implementation [Please refer here for singleton implementation]. It has a private constructor to make sure that it cannot be instantiated from outside. The most noticeable thing is its two methods. Here we have a method StudentCreatedCore() decorated with [Event] attribute, has a list of parameters including types supported by the ETW infrastructure. It has a corresponding StudentCreated() method with [NonEvent] attribute. It has a public access modified and has a non-primitive type for parameter. The most important thing is that it is using the StudentCreatedCore() method.


Can The implementation satisfy EventSourceAnalyzer?
We have discussed that we can use EventSourceAnalyzer for testing our EventSource implementation [Discussion]. Let's see if we can satisfy EventSourceAnalyzer for the above implementation. We just need to call InspectAll() method with an instance of the EventSource. Here we are using xUnit for testing supported by resharper. You need to install the nuget package. You would also need to get EnterpriseLibrary.SemanticLogging package for using EventSourceAnalyzer.


As a matter of fact, EventSourceAnalyzer has no complaints and the unit test passes. Zindabad!



Listening for Events
Now let's see if we can listen for events using this EventSource implementation. Here we are attaching the EventSource with ConsoleSink using the ConsoleLog [Discussion]. We are using the same EventLister to enable the events. Here we are just using the public method on EventSource type with an instance of Student type. Let's see if we could see the event's data on the console [keep the spirit high, friend!!!].


And we do see that event's data is being printed on the console in the same format as we provided in the StudentCreatedCore() method. Hence the runtime was able to do it from the private method. It has no problem with generating the ETW manifest for private [Event] methods and using it at run-time. Zindabad!



Download


Love for other people what you love for yourself.    [Prophet Muhammad - Salallahu-Alaihe-Wasallam]

Semantic Logging Application Block In-Proc Usage

Semantic Logging Application Block provides various types of sinks. They include Console, File based, SQL Server and Windows Azure Table based sinks. We have been discussing how we can use these sinks out-proc. In this post we will be trying to focus how we can use these sinks in-proc i.e. in the same process where the ETW events are generated from. This is specially useful for scenarios where it is not feasible for running Semantic Logging Service as a separate process. I think the most common use would be desktop applications.

Let's create a sample console application SLABInProcApp targeting .net framework 4.5.



Since we would be using the sinks in process. We need to use the necessary nuget packages. As we know FlatFile, RollingFlatFile and Console sinks are directly available in EnterpriseLibrary.SemanticLogging package. The SQL Server and Windows Azure Table sinks are available in EnterpriseLibrary.SemanticLogging.Database and EnterpriseLibrary.SemanticLogging.WindowsAzure packages respectively. Since these packages have a dependency on EnterpriseLibrary.SemanticLogging package, installing these two packages should take care of all the necessary dependencies. These are the packages and their dependencies as shows in Package Visualizer.



And this is how the packages.config should look like for the project.

Now let us introduce our custom EventSource we have been using in these posts. As we have been seeing, it must inherit EventSource type available in System.Diagnostic.Tracing namespace. We can also introduce the necessary types for keywords, tasks. Here we have two logging methods with Event Ids set as 1 and 2.


IObservable<EventEntry> Implementation
SLAB provides ObservableEventListener. This is a specialized EventListener available (.net framework 4.5). As its name suggests, this is an observable type implementing IObservable<EventEntry>. Now SLAB provides various extension method to hook this observable type to the available sinks. In order to keep the world simple, for a given sink type X, the available extension is named as LogToX().



Here we seem to be interested in pushing the logs to Console, SQL Server and Windows Azure table. So we would be needing ConsoleSink, SqlDatabaseSink and WindowsAzureTableSink. These are provided through ConsoleLog, SqlDatabaseLog and WindowsAzureTableLog types respectively through their corresponding LogToX() methods. The extension methods for logging to SQL Server and Windows Azure Table are made available through installing their respective nuget packages.


There is some pre-requisites before we can push data to SqlServer and Windows Azure table here for this example. We need to create database (including the required objects). We also need to make sure that Storage Emulator is running on the machine running this application. This is only required for development. For the production application we can provide the necessary connection details. We have discussed the pre-requisites for SQL Server and Windows Azure table here.

And That's it! Ain't that simple!!!

Now we can just run the application. Since we have subscribed to the ConsoleSink through ConsoleLog.LogToConsole() extension method for IObservable<EventEntry> type, we should be seeing the following on the console.



Subscribing to WindowsAzureTableSink should push the following in the development table storage.



And finally we should be able to see the following data in Traces table in the SQL Server database used here:



Simplifying it Further
We can simplify the code even further. We don't need to instantiate ObservableEventListener ourselves. XLog types also provide the necessary CreateListener() methods. In addition to returning a new instance of ObservableEventListener, they also hook up the EventListener instance returned to the respective source sink.


Event Listeners and Application Life Cycles
Please note that this is a very simple example where you see these subscriptions and logging in the same methods. This would not be the same in the real-life application. You can consider this like Trace Listeners, they are added in the beginning of application life cycle. In the same way, EventListener subscriptions can also be done at the similar stage. They would be more suitable for application seams (Mark Seemann).

There are still some limitations about implementing interface type by the EventSource.

Subscribing Custom IObserver<EventEntry>
Since ObservableEventListener implements IObservable<EventEntry>, we can subscribe any IObserver<EventEntry> with this. Let's implement a sample IObserver<EventEntry> implementation.

We can use the CustomObserver to subscribe to the ObservableEventListener now. This should be using OnNext() method for any new event from the listener.


Download Code

EntLib6 - Semantic Logging using Windows Azure Sink - Table Storage

This post is part of series of posts discussing about Semantic Logging Application Block [SLAB]. Earlier we have discussed about how we can push the log data to file and SQL Server storage. In this post we are discussing how we can use Windows Azure Table Storage as a destination of these logs.

Windows Azure Sink Configuration
As we have discussed updating destination and format of the event data requires no changes in the application generating these ETW events if we are using out-proc consumption of these events. SLAB provides Semantic Logging Service. We can use it out-of-the-box to make all these necessary changes without event bringing the application down. The configuration is done in SemanticLogging-Svc.xml configuration file for the service. Here we are using Windows Azure Storage Emulator.


Storage Emulator Not Running / Installed
For our development machine, we first need to install Windows Azure SDK to run the above. We specially need Windows Azure Storage Emulator running for this example. The emulator uses a default account key to test the application logic. In absence of an emulator running on your machine, with the above configuration, you would see the following error in your Semantic Logging Service console.



Installing Windows Azure SDK for .Net 2.1
The SDK is currently on the version 2.1. We can download it from Microsoft Download Center. You can make a selection based on Visual Studio edition you are running on your development machine.



It uses Web PI (Platform Installer) for the installation.



Running Storage Emulator
Running the emulator is easy. We can find it in the start menu. In order to run it from the Windows Azure Command Prompt, we need to use its application name i.e. dsserviceldb.



You should be able to see this running in the System Tray. I have it running on my Windows 7 machine as follows:



Just make sure that, it is running Table Storage service. We need it for Azure Sink as used in the example post.



Now let us run the same application as used in the previous post. The application is generating two ETW events with an Id 1 and 2. As we run it, we should be able to see the SLAB table Development storage. Here we are using the extensions installed in Visual Studio 2012 by Windows Azure SDK.



The extension also supports viewing the storage data. For our example the payload is recorded as follows:



But this seems a bit different than SQL Server sink data. Here it has added additional columns for the payload fields. It is a union of all the fields for all the event types as used by the ETW Event provider defined with the help of EventSource in the source application.