Application Event Logging

The Art of Logging

Log Book

During my time as a Naval Nuclear Field Machinist Mate I did a lot of logging.  The data points we logged were not for busy work, they had a reason and a purpose.

Logging certain data points around the same time multiple times a day is a lot of data.  As you know this data lets you see trends, maybe detect a potential equipment failure before it happens.

Application logging in the enterprise is not much different.  The hard part is knowing what to log, where to log, and how to log it.  I hope this article will help you answer some of those questions.

 

 

What to Log

The most obvious thing to log are errors.  You really should be logging things that are hitting your catch block of any try catch.  To be honest there are a few other things we should be logging.

Admin Activity

I believe it is good practice to log activity in your application’s administrative interface.  You do not have to get overly detailed, keep it simple at first, in fact the easiest thing to log would be changes.

Logging changes gives you an obvious event to tap into and perform your logging.  If someone updates a setting, you should log who updated what, from what to what and when.

Viewing Sensitive Data

If you have an interface that allows authorized users to view sensitive data you should log it.  When I say sensitive I am referring to Personally Identifiable Data, Payment Card Industry, or HIPAA data.  You should log who viewed it, when they viewed it, and if possible what they viewed.

Logging what they viewed is not as hard as you might think.  You don’t need to replicate the record or data they viewed.  In fact you should not replicate this data!  Just log the generic activity or page they viewed along with some kind of Id that would allow an auditor a way to see what the user viewed.

Where to Log It

Your first instinct may be to log the data to a database.  While this is much better than nothing chances are there is something in place already.  At the very least there is probably something that monitors logs, which dictates where you log.

In fact, I bet your enterprise is probably using something like Splunk.  If so, the easiest place for you to log, at least on a Windows machine, is the Event Viewer.  This is really very easy.

How to Log It

There are many different ways to log events.  I am going to show you one way, a rather simple way.  You could use this, improve it, or make your own way altogether.  In the code below you will see namespaces for generic places in a generic project.

Interfaces

You may think an interface for logging is a bit over the top.  I might actually agree with you in some cases, but I want to keep this easy and generic.  So lets create a simple logging interface, we will call it ILogging.cs.  I like to put things that could be referenced in many places in a Common project.  My real project will then reference that Common one.

using System;

namespace Common.Interfaces
{
    public interface ILogging : IDisposable
    {
        /// <summary>
        /// This method is really for testing purposes.
        /// </summary>
        /// <returns>string</returns>
        string GetLastMessage();
    
        void LogError(Exception e);
    
        void LogError(string message);
    
        void LogInformation(string message);
    }
}

Remember, an Interface is like a contract.  If you are not familiar with interfaces I highly recommend Jeremy Clark’s video on C# Interfaces.  Our interface uses the IDisposable interface and has four methods.  One is something for testing and the others are various ways to log errors or information.

Implement Our Interface

Now we need to create a class that will implement our interface.  For my example we will place it into a Helpers project that references the interface in a Common project.  Since your interface uses IDisposable we must implement that interface as well.  Visual Studio makes it really simple to do this, but I’m just going to place the code here for you.

using System;
using System.Diagnostics;

namespace Helpers
{
    public class LogToEventLog : Common.Interfaces.ILogging
    {
        private EventLog eventLog;
        // You could set the appName from a setting in the web.config/app.config or elsewhere
        // I put it here just to keep things simple
        private const string appName = "My Application";
        
        public LogToEventLog()
        {
            eventLog = new EventLog();
            if(!EventLog.SourceExists(appName))
            {
                EventLog.CreateEventSource(appName, "Application");
            }
            eventLog.Log = "Application";
            eventLog.Source = appName;
        }
    
        #region Public Methods
        /// <summary>
        /// This method is really for testing purposes.
        /// You will see what I mean in the unit test.
        /// It returns the last message logged.
        /// </summary>
        /// <returns>string</returns>
        public string GetLastMessage()
        {
            EventLogEntryCollection logEntries = eventLog.Entries;
            return logEntries[logEntries.Count - 1].Message;
        }
        public void LogError(Exception e)
        {
            LogEvent(e.Message, EventLogEntryType.Error);
        }
    
        public void LogError(string message)
        {
           LogEvent(message, EventLogEntryType.Error);
        }
    
        public void LogInformation(string message)
        {
            LogEvent(message, EventLogEntryType.Information);
        }
        #endregion
    
        #region Private Methods
        private void LogEvent(string message, EventLogEntryType messageType)
        {
            eventLog.WriteEntry(message, messageType);
        }
        #endregion
    
        #region IDisposable Support
        private bool disposedValue = false; // To detect redundant calls
    
        protected virtual void Dispose(bool disposing)
        {
            if (!disposedValue)
            {
                if (disposing)
                {
                    eventLog.Dispose();
                }
    
                // TODO: free unmanaged resources (unmanaged objects) and override a finalizer below.
                // TODO: set large fields to null.
    
                disposedValue = true;
            }
        }
    
        // TODO: override a finalizer only if Dispose(bool disposing) above has code to free unmanaged resources.
        // ~Logging() {
        //   // Do not change this code. Put cleanup code in Dispose(bool disposing) above.
        //   Dispose(false);
        // }
    
        // This code added to correctly implement the disposable pattern.
        public void Dispose()
        {
            // Do not change this code. Put cleanup code in Dispose(bool disposing) above.
            Dispose(true);
            // TODO: uncomment the following line if the finalizer is overridden above.
            // GC.SuppressFinalize(this);
        }
        #endregion
    }
}

You will notice I am only logging strings.  I let the Event Viewer handle the date and time stamp.  I only want to see critical information, usually the exception message or the exception message with some extra text.

Testing Our Logging Class

The joys of testing.  You should always make use of Unit Tests.  They may seem like a hassle at first, but in the long run they are very helpful.

using System;
using Microsoft.VisualStudio.TestTools.UnitTesting;
using Helpers;

namespace ProjectTests
{
    [TestClass]
    public class HelperTests
    {
        [TestMethod]
        [TestCategory("Event Logging")]
        public void Logging_WriteStringEvent_Test()
        {
            //Arrange
            string message = String.Format("Test at {0}", DateTime.Now);
            string lastMessage = "";

            //Act
            try
            {
                using (Common.Interfaces.ILogging logging = new LogToEventLog())
                {
                    logging.LogInformation(message);
                    lastMessage = logging.GetLastMessage();
                }
            }
            catch (Exception e)
            {
                Assert.Fail(e.Message);
            }

            //Assert
            Assert.AreEqual(message, lastMessage);
        }
    }
}

Remember that method that I sad was just for testing?  I will admit, you really don’t need to have it as part of the interface, and thus not part of the logging class.  I put it in there to help make the testing a bit easier.

Please notice the way I constructed the message to use in testing.  I added the DateTime.Now string.  This will help keep things to the moment we tested.

You will also notice I am testing to the interface even though we are using our LogToEventLog class.

All Done?

Technically we are not finished, but I cannot go through your code and use our logging class.  Since we are logging to the Event Viewer this means Splunk can easily take in that data and take other actions.

Summary

I really hope you found this helpful.  Using processes that are already in place may not be fun, but it can be a good thing.  If all of the other developers in the Enterprise are logging the same way it makes troubleshooting a bit easier.  In our case, all we have to do is go to the Event Viewer, or have an admin go there and sent us the entries for the application in question.

Advertisements

About SheldonS

Web developer for over 15 years mainly with Microsoft technologies from classic ASP to .NET 4. Husband, father, and aspiring amateur photographer.

Posted on March 13, 2016, in Bits, C# and tagged . Bookmark the permalink. Leave a comment.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: