Thursday, August 22, 2013

To Log or Not to Log...Really???

We have been trying to emphasize that planning for logging is extremely important. One use that we have seen is obtaining the usage data to improve the product design. The same logs can also be used for a lot of different other reasons as well including legal. A customer might need to see particular data at particular time (e.g. market fluctuations). If we don't keep the logs, we have no way to verify how much trouble user have experienced. We can use this to compensate the customer for damages.

Logging can also be used for health monitoring but it's main use is for registering the activities which could be used for the following:
  • Determining the cause of any failure in the system and steps to reproduce the issue.
  • What parts of application are being used by the users. More classified information can be obtained based on demography and source of request.
  • Applications are generally designed to be flexible. We can determine what use cases are used generally and in what order. We can use this knowledge to build up more sophisticated user interfaces.
  • User flow is very important and the actual flow of application by the user can only be determined based on the actual usage. Hence logging.
Building great products not only attracts the customers who use those products but it also attracts internal customers including people who put their hard work in building more useful products. This is why big technology firms are able to attract talent easily even if their remuneration packages are below market rates. People like to live, work and interact with fellows who have a known record of doing good. This is why the human resource departments of good organisations are filled with attractive resumes. Let me give you a little secret, if you are in a position in your enterprise that you have to interview the candidates, look at the profiles and proficiency of people who are appearing for the interview. If you can't find good candidates, it means that they don't want to work here. Just leave, as the more you will be here, the more you would be considered responsible for being part of the cause of evil perception of the enterprise. The same principle applies for immigration, would you want to immigrate to a war torn county with bad economic shape?

But people do understand the importance of logging...most of them. That's why we see a logging API being used in various projects. These frameworks allow you to slap the strings (may be formatted) to various destinations including console, files or database. The problem is realized when we need to consume this ginormous block of data. Then we try to diffuse the situation by creating in-house tools to consume these logs. Sounds familiar...Shouldn't we be asking this question to ourselves, when this area is so common to an application, why in the world we need to re-invent the wheel? All the code that we write is a liability to the organization we work for. The answer is structured logging. It provides all the API to write the log. Additionally, all the required tools are already available to consume the logs. It can also be used out-proc.

In short, logging might not help you design great systems upfront but it certainly helps to improve the existing systems in ways that you might not realize initially. Structured logging is to log with consumption in mind.

Still friends? I love you...

Sunday, August 18, 2013

SLAB - Reactive Event Sourcing

In the previous post we saw how we can use ETW events generated using EventSource using PerfView. We can also use these events in our application using EventListener. This is another new abstract type provided in .net framework 4.5. The abstract member is OnEventWritten() method. Additionally, it has a virtual method OnEventSourceCreated(). Below is a custom event listener. Here we are overriding the two members. We are just writing the debug messages when these methods are called. During development, debug messages can be seen in the Visual Studio's Debug Output window.

The listener's OnEventWritten method is called when EventSource writes an event. But before that we need to specify what level of events we are interested in from the EventSource. This is called Enabling the events where listener is specified with the EventSource and EventLevel.

You can notice OnEventSourceCreated and OnEventWritten being used by the logs in the Output window. The above code wold result the following logs:

Semantic Logging Application Block
Semantic Logging Application Block is provided in Enterprise Library 6 for supporting structured logging. It enhances EventSource to support logging events in SQL Server and Azure tables. Like other application blocks, this is also available as a Nuget package.

SLAB provides custom implementation of EventListener. The listener is Rx's IObservable. This is named as ObservableEventListener. Since this implements IObservable, it allows subscriptions from Event sinks. The sinks are IObserver (s) to observe on these event listeners.

The application block also provides a specialization of EventSource. This is named as SemanticLoggingEventSource.

In-Process Vs Out-Process
SLAB can be used in-process or out-process. We can use the Nuget package to use the libraries for using it in process. For out of process, it is hosted as a windows service. The service installer is available as a separate download. In the previous post, we discussed how we can use out-process logging with SLAB.

Event Text Formatter
SLAB supports JSON and XML based text formatting. The types are available in Microsoft.Practices.EnterpriseLibrary.SemanticLogging.Formatters namespace available in Microsoft.Practices.EnterpriseLibrary.SemanticLogging assembly. The assembly is downloaded using EnterpriseLibrary.SemanticLogging nuget package.

Event Sinks & Factories
SLAB also provides Event Sinks and their factories. All of these event sinks are IObserver.

Let's install EnterpriseLibrary.SemanticLogging application block nuget package. The package should take care of all its dependencies installation as well, which is only comprised of Newtonsoft.Json package.

Let's also install Rx-Main nuget package for subscriptions using Reactive extensions based subscribers.

In the following code we are subscribing to ObservableEventListener. We can get the messages in the OnNext() method for the subscriber. Here we have also used OnCompleted() and OnError() of the subscriber.

Running the above code would result in the following output. Please notice that the messages being logged using the event source as provided to the listener. Since we are subscribing to the listener, we are getting those messages in OnNext(). Here we are just writing those messages to Debug Window.