Wednesday, September 18, 2013

EntLib Semantic Logging App Block - Event Text Formatting

In the discussion around Reactive Event Sourcing , we discussed briefly about text formatting for ETW messages. In this post, we are trying to understand the text formatting in a little more details discussing the different options available for text formatting for event data provided by EventSource as supported by Semantic Logging Application Block [SLAB].

In the examples for this post, we are going to be using Semantic Logging Service. We have discussed about it in the past. You can get yourself started with the installation and configuration of the service here: [Semantic Logging Service]

Sample Event Source
Let's create a sample console application EventSourceFormatting.csproj. We are adding the following EventSource to the project. It has only a single logging method which can be used when there is a request for password hashing.

Message Formatting
EventSource allows us to add a formatted message to the payload. Just look at the definition of RequestForPasswordHashing() method. Here we are decorating the event method with the Message property. You can notice that we are using it like string.Format() where we are expecting the arguments. The arguments are used from the Event method parameters with the same indexing. So for the example here, it would be using req for {0} and userName for {1}. The runtime would format the message using them and assign to event's Message.

The message and payload for the above event should be logged as follows:

Here we have called the event method as follows:

If you are using Semantic Logging Service to test this code with Sql LocalDB, you can use the following service configuration:

The message formatting as we described above, can format the message adding additional details from the payload. But we might need more than that. We might need to add some text in header and footer of the log being generated if we are using a file or console based sink.

SLAB supports text, 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.

EventTextFormatter is the simplest of all text formatters. It supports qualifying the event's data with additional details including header and footer. These are not the header and footer for the whole log file but each event data would be enveloped in them. Here We can add the following FlatFileSink to our service configuration. It has a simple EventTextFormatter with some specified header and footer details.

The Event Level specified on the sink is the minimum level. If there are error level events generated by one of the event source specified by the sink then they are also logged. You can notice how our event data is decorated with header and footer as specified in the above configuration using the EventTextFormatter by the FlatFileSink.

There is one more amazing option with EventTextFormatter which is missing in the other supported IEventTextFormatters (s). The option is called VerbosityThreshold. This is to further qualify the event for which we desire to apply this formatting. Let's first update our events as follows:

In the following example, we are interested in all the events from the specified EventSource which are at least set as [ Level = Informational]. But we want the additional verbose details only in the case of events with Informational level.

So all the events with level less than Informational wouldn't have the detailed verbose event detail. By default this is set as Error. That is why we were already seeing the detailed event data for Error level event. For our example, the data would be pushed to the sink as follows:

We can use XmlEventTextFormatter without any changes to the source application. Let's see below where we are updating the configuration of Semantic Logging Service. We are using the same Event source, still interested in the same event level. We are even logging to the same file but just in a different format i.e. Xml.

Here is how the same event data is logged in a different format. We don't have the header and footer data as we had for EventTextFormatter.

You can notice that message is still formatted in the same way.

Similar is the case for pushing the event data to the sink in JSON format. In the following Semantic Logging Service configuration, we have used JsonEventTextFormatter with FlatFileSink.

And now the same event data is pushed out to the file in JSON formatter. We don't even need to restart the source application for this change. Just look at the same data in a different format. This time this is JSON.

Why DataTimeFormat Property?
In our EventSourceAnalyzer discussion we mentioned that DateTime data type is not supported for event payload. If you look at the definition of IEventTextFormatter, it has a DateTimeFormatter property. Why in the world do you need to format this when it is not even supported. Just Don't get too excited!!!

The DateTimeFormat is not for the payload data. It is for the event data. If you look at the log file, you can find that all the events are logged with TimeStamp. This formatting is to applied for that Timestamp. Let's update the service configuration as follows:

Just notice the TimeStamp format. You can compare this with the TimeStamp format before.

Source Sinks & Supporting EventTextFormatters
It must be remembered that all sinks don't support every text formatter. There are only a few which support these formatters. In the following image, I have tried to list sinks and the supporting Event Text formatters.

Source Sinks support a maximum of a single text formatter. It can be any of the supported text formatter as presented above.

Changing the Semantic Logging Service Configuration
It must be remembered that we don't need to restart the service after every changes in the service configuration including additional / removal of an event sink. Here we are running the service as a console application. Just look at the detailed message when we changed the configuration. Isn't that great? Zindabad!!!


No comments: