Introduction
In our applications, we often need to log information. We often need to log when things go wrong. We often need to log for auditing and reporting purposes. We often need to tailor the amount of logging that is occurring based on what is happening in production.
The Microsoft patterns and practices Semantic Logging Application Block (SLAB) is an excellent way to help manage your logging needs for .net applications. I think two main advantages of SLAB are:
- Having the ability to easily structure (strongly type) your log data.
- Having the ability to decouple logging related events in your applications from decision making on how to consume and log those events.
OK, let's get started with an example!
What Do We Want To Log Today?
Let's do a simple example. We will build a test application that will log 3 types of information:
- Exception - We want to log when exceptions occur.
- Warning - We want to log (perhaps less often) when warnings occur.
- Activity - We want to log (perhaps less often) when a general event or activity occurs.
Getting Started With SLAB
To get started with SLAB and to use it in your .net application is an easy process:
- Add the Semantic Logging Application Block nuget package to your project.
- Add additional Semantic Logging Application Block sink nuget packages for logging to wherever you want to (Azure, text files, etc.).
- Set up your event sources in your application for managing your logging events in a structured way. In our example, we will create a couple of simple event sources.
- Write log related events (using the event sources) at appropriate places in your application. In our example, our test application will be set up to write a few events.
- Setting up listeners to log your messages. In our example, we will use an out of the box listener to log to Azure table storage and a custom listener to log to Loggly.
Setting Up Event Sources
The first thing you should do is set up your event sources, which define the structure and organization of your logging related events. Since the quality of your logging data will depend on this structure and organization, you probably will do a little up front planning to figure out how you want to organize the logging related events that you envision you will need in your application. You will also consider how you will want to view and/or report on that logging data.
Below is an ActivityEventSource, where we define a method for an activity event that has occurred, and we want to track a title, category, and message:
public class ActivityEventSource : EventSource
{
private static readonly Lazy<ActivityEventSource> Instance =
new Lazy<ActivityEventSource>(() => new ActivityEventSource());
public static ActivityEventSource Log
{
get { return Instance.Value; }
}
[Event(100, Message = "Activity Occurred", Opcode = EventOpcode.Info,
Level = EventLevel.Informational)]
public void ActivityOccurred(string title, string category, string message)
{
if (this.IsEnabled()) {
WriteEvent(100, title, category, message);
}
}
}
The general practice for event sources is to have a singleton with a static Log property, which is then used to call logging related methods. So, we would call ActivityEventSource.Log.ActivityOccurred() to indicate that an activity has occurred.
Notice the Event attribute for our method. Each event should have a unique number. You can also additional tags such as a Message, an Opcode (for kind of event), and event Level, etc.
Below is an IssueEventSource, where we define methods for warnings and exceptions that have occurred, with information such as messages, stack trace, and source:
public class IssueEventSource : EventSource
{
private static readonly Lazy<IssueEventSource> Instance =
new Lazy<IssueEventSource>(() => new IssueEventSource());
public static IssueEventSource Log
{
get { return Instance.Value; }
}
[NonEvent]
public void WarningOccurred(Exception ex)
{
if (ex != null)
{
WarningOccurred(ex.Message, ex.ToString(), ex.Source, ex.StackTrace);
}
}
[Event(500, Message = "Warning Occurred", Level = EventLevel.Warning)]
public void WarningOccurred(string basicMessage, string detailedMessage, string source,
string stackTrace)
{
if (this.IsEnabled()) {
WriteEvent(500, basicMessage, detailedMessage, source, stackTrace);
}
else
{
Trace.TraceWarning(String.Format("Basic Message: {0}, Detailed Message: {1}, Source: {2}, Stack Trace: {3}", basicMessage, detailedMessage, source, stackTrace));
}
}
[NonEvent]
public void ExceptionOccurred(Exception ex)
{
if (ex != null)
{
ExceptionOccurred(ex.Message, ex.ToString(), ex.Source, ex.StackTrace);
}
}
[Event(501, Message = "Exception Occurred", Level = EventLevel.Error)]
public void ExceptionOccurred(string basicMessage, string detailedMessage, string source,
string stackTrace)
{
if (this.IsEnabled()) {
WriteEvent(501, basicMessage, detailedMessage, source, stackTrace);
}
else
{
Trace.TraceError(String.Format("Basic Message: {0}, Detailed Message: {1}, Source: {2}, Stack Trace: {3}", basicMessage, detailedMessage, source, stackTrace));
}
}
}
Note that there are additional methods with the NonEvent attribute. This allows you to define alternate method signatures for the same event. In our case, we can choose to log warning and exception events with an instance of Exception.
Also note that the exception and warning methods are generally similar, but have a different EventLevel defined in the Event attribute. This will be critical in decision making on how to log warnings vs. more important exceptions.
These methods are also defined to send the events to standard Trace if no listeners are defined to handle the events in another manner.
The attached download has a more complete IssueEventSource, with additional method signatures for warnings and exceptions, and also methods for critical exceptions.
Writing Logging Related Events
To write out our logging related events, we will create a simple winforms test app to allow you to enter text for issue, warning, and activity log events, and log them by clicking on the corresponding log button:
Clicking on the log buttons will initiate logging the event to the corresponding event source method:
public TestApp()
{
InitializeComponent();
}
private void btnLogIssue_Click(object sender, EventArgs e)
{
IssueEventSource.Log.ExceptionOccurred(new Exception(txtIssue.Text));
txtIssue.Text = "";
}
private void btnLogWarning_Click(object sender, EventArgs e)
{
IssueEventSource.Log.WarningOccurred(new Exception(txtWarning.Text));
txtWarning.Text = "";
}
private void btnLogActivity_Click(object sender, EventArgs e)
{
ActivityEventSource.Log.ActivityOccurred("Testing a logging activity", "Event",
txtActivity.Text);
txtActivity.Text = "";
}
}
Well, what happens to these logging related events? Nothing right now, except that issues and warnings will go to standard Trace. We need to set up some listeners to do something else with these logging related events.
Setting Up A Listener To Log Messages
SLAB has several out of the box listeners that you can use to write out your logging related messages (text, SQL Server, etc.). Let's set up a listener to write our logging data to a Windows Azure table. Below is a LoggingService, where we choose to create an azure table listener and also choose to write all of our logging related events to an Azure table named "SLAB":
public class LoggingService
{
private EventListener _azureDbListener;
private static readonly Lazy<LoggingService> ServiceInstance =
new Lazy<LoggingService>(() => new LoggingService());
public static LoggingService Instance
{
get { return ServiceInstance.Value; }
}
public void Start()
{
try
{
_azureDbListener = WindowsAzureTableLog.CreateListener("dev",
@"UseDevelopmentStorage=true;", "SLAB");
_azureDbListener.EnableEvents(IssueEventSource.Log, EventLevel.Verbose);
_azureDbListener.EnableEvents(ActivityEventSource.Log, EventLevel.Verbose);
}
catch (Exception ex)
{
Trace.TraceError(String.Format("Exception occured while trying to start the {0} logging listener: {1}",
"Azure Table", ex.Message));
}
}
}
Now that we have a logging service defined for sending logging messages, we can start this up in our little test application, and we call LoggingService.Instance.Start():
public TestApp()
{
InitializeComponent();
LoggingService.Instance.Start();
}
private void btnLogIssue_Click(object sender, EventArgs e)
{
IssueEventSource.Log.ExceptionOccurred(new Exception(txtIssue.Text));
txtIssue.Text = "";
}
private void btnLogWarning_Click(object sender, EventArgs e)
{
IssueEventSource.Log.WarningOccurred(new Exception(txtWarning.Text));
txtWarning.Text = "";
}
private void btnLogActivity_Click(object sender, EventArgs e)
{
ActivityEventSource.Log.ActivityOccurred("Testing a logging activity", "Event",
txtActivity.Text);
txtActivity.Text = "";
}
}
With semantic logging, you can configure the listeners to run in or out of process. How we configure the listeners does not impact our code that logs the event source information, which nicely decouples our decision making on how to handle logging from the places where we log when things occur.
Let's run our application again and see what happens, entering issues, warnings, and activities and logging them.
Here we can see some events that have been logged to the SLAB Azure table in local dev storage:
Notice with the Azure table dynamic columns we have different columns corresponding to different data points for each of our event source methods.
Defining A Listener To Write To Loggly
One of the cool things with SLAB is that you can write your own listeners to handle the logging events in any way you see fit. Here we are going to create a custom listener to write logging events to Loggly, a popular logging facility.
To use a listener to write to Loggly, you will need to perform the following additional steps:
- Set up a test account with Loggly. You can continue to use a small dev account for free.
- Add the loggly-csharp nuget package to your project. This provides a .net API to send messages to Loggly.
- Add the Reactive Extensions nuget package to your project. We will use this extension to simplify the creation of our listener.
To create a custom listener, I looked at the source code for some standard SLAB listeners as a guide (I looked at the flat file and SQL Server listeners as an example).
Following is the LogglyLog that sets up the Loggly EventListener which subscribes to a sink that will log messages to Loggly:
public static class LogglyLog
{
public static EventListener CreateListener()
{
var listener = new ObservableEventListener();
listener.LogToLoggly();
return listener;
}
public static SinkSubscription<LogglySink> LogToLoggly(this IObservable<EventEntry> eventStream)
{
var sink = new LogglySink();
var subscription = SubscribeWithLoggly(eventStream, sink);
return new SinkSubscription<LogglySink>(subscription, sink);
}
public static IDisposable SubscribeWithLoggly(IObservable<EventEntry> source,
IObserver<LogglyEventEntry> sink)
{
return source.Select(s => new LogglyEventEntry(s)).Subscribe(sink);
}
}
We will use the CreateListener() method to create a listener to log to Loggly and enable certain events to be logged to Loggly.
To write out logging events to Loggly, we need a certain format for an event entry. The LogglyEventEntry defines this format as a basic message and a payload dictionary of additional details, and a constructor to initialize from any EventEntry:
public class LogglyEventEntry
{
public string Message { get; set; }
public Dictionary<string, object> EventItems { get; set; }
public LogglyEventEntry(EventEntry entry)
{
try
{
Message = entry.FormattedMessage;
EventItems = new Dictionary<string, object>();
EventItems.Add("EventId", entry.EventId);
EventItems.Add("ProviderId", entry.ProviderId);
EventItems.Add("EventDate", entry.Timestamp.UtcDateTime);
for (int i = 0; i < entry.Payload.Count; i++)
{
EventItems.Add(entry.Schema.Payload[i], entry.Payload[i]);
}
}
catch (Exception e)
{
SemanticLoggingEventSource.Log.CustomSinkUnhandledFault(e.ToString());
}
}
}
The LogglySink handles the meat of using the loggly-csharp api and writing the messages to Loggly (the loggly-csharp handles the messages to Loggly in an asynchronous manner):
public class LogglySink : IObserver<LogglyEventEntry>, IDisposable
{
private readonly object lockObject = new object();
private readonly object flushLockObject = new object();
private ILogglyClient logger;
private bool disposed;
private volatile TaskCompletionSource<bool> flushSource = new TaskCompletionSource<bool>();
public LogglySink()
{
logger = new LogglyClient();
flushSource.SetResult(true);
}
~LogglySink()
{
this.Dispose(false);
}
public Task FlushAsync()
{
lock (this.flushLockObject)
{
return this.flushSource.Task;
}
}
protected virtual void Dispose(bool disposing)
{
if (disposing)
{
if (!this.disposed)
{
lock (this.lockObject)
{
if (!this.disposed)
{
this.disposed = true;
}
}
}
}
}
private void OnSingleEventWritten(LogglyEventEntry entry)
{
try
{
lock (this.lockObject)
{
var logEvent = new LogglyEvent();
logEvent.Data.Add("Message", entry.Message);
foreach (var item in entry.EventItems)
{
logEvent.Data.Add(item.Key, item.Value);
}
logger.Log(logEvent);
}
}
catch (Exception e)
{
SemanticLoggingEventSource.Log.CustomSinkUnhandledFault(e.ToString());
}
}
public void Dispose()
{
this.Dispose(true);
GC.SuppressFinalize(this);
}
public void OnCompleted()
{
this.FlushAsync().Wait();
this.Dispose();
}
public void OnError(Exception error)
{
this.FlushAsync().Wait();
this.Dispose();
}
public void OnNext(LogglyEventEntry value)
{
if (value != null)
{
OnSingleEventWritten(value);
}
}
}
To configure a connection with Loggly, you will need to get your configuraton details and add them to the test application App.config file. You would enter your customer token (Guid), account name, username, and password:
<configSections>
<section name="loggly" type="Loggly.Config.LogglyAppConfig, Loggly.Config" />
</configSections>
<startup>
<supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.5" />
</startup>
<loggly xmlns="Loggly" applicationName="Test App" customerToken="YOUR TOKEN GUID" isEnabled="true" throwExceptions="true">
<transport logTransport="Https" endpointHostname="logs-01.loggly.com" endpointPort="443" />
<search account="YOUR ACCOUNT/DOMAIN NAME" username="USERNAME" password="PASSWORD" />
<tags>
<simple>
<tag value="winforms" />
</simple>
<complex>
<tag type="Loggly.HostnameTag" formatter="host-{0}" />
<tag type="Loggly.ApplicationNameTag" formatter="application-{0}" />
<tag type="Loggly.OperatingSystemVersionTag" formatter="os-{0}" />
<tag type="Loggly.OperatingSystemPlatformTag" formatter="platform-{0}" />
</complex>
</tags>
</loggly>
Now we can update our logging service to add a loggly listener to write exceptions only to Loggly (warnings and other activity messages will not go to Loggly).
public class LoggingService
{
private EventListener _logglyListener;
private EventListener _azureDbListener;
private static readonly Lazy<LoggingService> ServiceInstance =
new Lazy<LoggingService>(() => new LoggingService());
public static LoggingService Instance
{
get { return ServiceInstance.Value; }
}
public void Start()
{
try
{
_logglyListener = LogglyLog.CreateListener();
_logglyListener.EnableEvents(IssueEventSource.Log, EventLevel.Error);
}
catch (Exception ex)
{
Trace.TraceError(String.Format("Exception occured while trying to start the {0} logging listener: {1}",
"Loggly", ex.Message));
}
try
{
_azureDbListener = WindowsAzureTableLog.CreateListener("dev",
@"UseDevelopmentStorage=true;",
"SLAB");
_azureDbListener.EnableEvents(IssueEventSource.Log, EventLevel.Verbose);
_azureDbListener.EnableEvents(ActivityEventSource.Log, EventLevel.Verbose);
}
catch (Exception ex)
{
Trace.TraceError(String.Format("Exception occured while trying to start the {0} logging listener: {1}",
"Azure Table", ex.Message));
}
}
}
Again, none of this affects our code where we log when things occur. Let's run our test application again, entering some more issues, warnings, and activities.
Here are some issues that have been logged to Loggly. Notice that no warnings or activities appear.
In Conclusion
I hope that has been a useful exercise on using SLAB and building a custom listener for Loggly. Dig into the example project and build your own event sources and listeners. Happy coding!
