paint-brush
Standardization of Performance Monitoring, Logging, & Exception Handling via a .NET Runtime Wrapperby@lee-mcgraw
461 reads
461 reads

Standardization of Performance Monitoring, Logging, & Exception Handling via a .NET Runtime Wrapper

by Lee McGrawSeptember 9th, 2019
Read on Terminal Reader
Read this story w/o Javascript
tldt arrow

Too Long; Didn't Read

A common issue for teams building applications within a single department is often departments do their own thing. Seemingly each application, each application layer, and even sometimes different method calls within the same application, often handle cross-cutting functionality differently. In this article, I will propose an enterprise level solution to address standardizing exception handling, performance monitoring, and logging. The solution is implemented in a class called UnitOfWork. It can be used across an entire enterprise and/or application. It is not copyrighted, and I hope others find it useful as I have.

Companies Mentioned

Mention Thumbnail
Mention Thumbnail
featured image - Standardization of Performance Monitoring, Logging, & Exception Handling via a .NET Runtime Wrapper
Lee McGraw HackerNoon profile picture

Several years ago, I wanted to have my own performance monitoring solution, so I could monitor all enterprise applications. Few enterprises implement this core cross-cutting application task across the enterprise in the same way. By the phrases “core” and “cross-cutting” I mean a feature or functionality set that touches all application development; it’s not specific to a single application. I think some functionality that is repeated across the enterprise should be done the same standard way.

A common issue for teams building applications within a single department is often departments do their own thing, even calling the same business entity different names. They rarely consult with the established Enterprise Architectural framework, if one even exist. It’s no surprise that they often have different solutions for core processes like performance monitoring, logging, and exception handling. Seemingly, each application, each application layer, and even sometimes different method calls within the same application, often handle cross-cutting functionality differently. Such applications reflect a lack of architectural knowledge, a lack of architectural planning time, and/or, more likely, a deadline that mandates the development team to just "get it done ASAP".

I began to research having a common way to monitor application performance across the enterprise. Ideally, I wanted a simple solution that I could use for all enterprise needs. My first thought was an attribute based solution that I could apply to a method that would create a log entry when the method started and when it ended. This would allow me to identify bottlenecks in the execution of my application, at least for individual method calls, but not for sequential groups of method calls.

Creating an attribute that would create a performance log entry when the method started was easy, but the later was impossible (to my knowledge), unless you modified the IL in a Post-Build event, which isn’t ideal. And, after doing more research, I decided that reflection was not the best way to accomplish my needs, since the operation of reflection alone would skew my performance results. Also, I would prefer to not perform reflection in a production environment. So, my idea of creating an attribute based solution to accomplish my goals was not acceptable to me. 

In this article, I will propose an enterprise level solution to address standardizing exception handling, performance monitoring, and logging. It is implemented in a class called UnitOfWork. It can be used across an entire enterprise and/or application. While this wrapper is called UnitOfWork, do not confuse this with the database concept of a unit of work. This class has nothing to do with a database transaction, however, it would be easy to incorporate such functionality into this class.

I will be approaching this solution from a C#.NET point of view; as such, all the code I discuss will be in C# and .NET Core. I won’t discuss this code line by line, so if you don’t know C# or understand lambda expressions, you probably should stop reading now. I will cover a few of the more interesting parts of the code only, I will not cover every single line of code.   

I acknowledge in advance that this is merely a way to accomplish the goals I have outlined above, and I make no presumption of saying it’s the best way or the only way. Every solution has its own set of issues, including this one. Other technologies do exist the address the same issues I am addressing. I have created this to provide maximum flexibility for any organization that may wish to use it. For instance, if an organization would rather log information (exceptions, logs, performance statistics) to a database, they only need to implement the ILogger interface I have defined to do so, and change their dependency injection configuration to use their own custom logger class. This class supports multiple loggers. I have included a few basic ones as examples. Everything (variables, properties, etc) used is optional and comes with default values. Further still, the entire UnitOfWork class and dependency classes are included in the source code, so feel free to modify it to satisfy your organization’s need. It is not copyrighted, and I only hope others find it as useful as I have.

For my solution, I decided a generic wrapper class that doesn’t suffer the performance issues of reflection, but does solve the issues, was my best bet. I could easily pass a lambda expression, or an array of lambda expressions, to my wrapper class, and it could create a log entry, then run the lambda expression(s), then log the duration of execution. This gives me control over the granularity of logging. Also, I have the source code that I can modify to suit any needs I may have in the future. Another perk to this solution is it’s free. ;)

It should be noted that the IN and OUT types are the same for all the lambda expressions being run in a single UnitOfWork class instance; however, that doesn’t mean that the IN or OUT couldn’t be a tuple of multiple types, or even an list of tuples of types. Another wonderful thing about lambda expressions is that all the objects that are visible when they are defined are also available inside of the expression itself. For example, if I create a database connection before I instantiate an UnitOfWork class, then the lambda expression(s) that I define for the UnitOfWork has access to that database connection object.  The returned OUT type is the result of the last run lambda expression, but I have created two publicly accessible list properties that saves/clones the result of both inputs and outputs after each lambda expression’s execution, if more than one lambda expression is defined. These are serialized using the Json Serializer after each lambda expression’s execution and added to the list; however, only public member values are saved. I clone these IN and OUT values for pretty obvious reasons; think about ByRef and ByVal. I started to use the binary serializer to get all member values, but that requires the type to have the Serializable attribute to be applied to it.

As I built this wrapper I started to realize that it could encapsulate much more than just my performance monitoring needs. I realized my class could solve another common problem (a common problem, but rarely commonly solved across the enterprises) — exception handling. In most applications, the user is protected from the details of an exception thrown, since that information is pretty useless to the application user, but has very important relevance for the developer and his team that needs to debug the issue. This wrapper logs the much needed detailed exception information for developer debugging, while shielding that information from the application user. As an example, if a SQL exception is thrown, perhaps the only thing the application’s user really needs to see is "The requested operation failed; please try again." Basically, the user friendly message is meaningless to the developer, but shields the user from the devil in the details. The developer wants to see the details behind what happened. 

But, sometimes, I don’t want to handle exceptions in certain methods; sometimes I want the exception to bubble up to the caller. So, I added both the exception handling code, as well as the flexibility to specify if you want the class to rethrow the exception to the caller. If you elect to have this wrapper not handle the exception inside of its own TryCatch, then an exception will bubble up like normal.

Also, my choice of a class versus a struct or a static method, or even an extension method, was made for several reasons. The benefit of allowing parameters to be set via a class initializer was one reason. While I have provided several constructors for common object creation needs, I often find a class initializer beneficial for class creation to set properties not available in the constructor. Also, to me, class initializers are far easier to read. As far as the overhead of a class being created, I don’t see that as an issue. I considered making this a struct, to avoid garbage collection, but if an instance of UnitOfWork were to be passed as a parameter to other classes, then that could have a very serious impact on the memory stack, as a copy would be made and passed, rather than a reference passed. Garbage collection in .NET is generally faster than the C++ delete method. Class creation is negligible in .NET. It only becomes issue when you create classes inside of a loop with large (millions) quantities of elements. This class uses no unmanaged or disposable resources, but if the methods you pass to it do, then you should dispose of those responsibly yourself. If you modify this class to use unmanaged or disposable resources, you may need to utilize using statements and possibly implement IDisposable and the appropriate methods.

3 attributes of interest that are somewhat new to .NET. CallerMemberName, CallerLineNumber, and CallerFilePath attributes are applied to the Execute method. These are defined in the System.Runtime.CompilerServices namespace, and their names pretty much define what they do. I will let you look those up for yourself; they simply provide more information to the person that reviews any exception logging issues. 

I have a property called UnitOfWorkName. You should give this a meaningful name because it will appear in the logs. Remember, this name applies to all of the lambda expressions you pass into this class.

The last constructor is the only one that is of importance, as it does the work. The last parameter to this constructor is meaningless, so just ignore it. It is only there to provide an unique signature. This is protected scope for obvious reasons, so anyone who inherits from this class can access it. The scope/visibility of everything in this class has a reason. For instance, the Function property get is private, and, again, for obvious reasons, to prevent bypassing the whole purpose of this wrapper class.

Ok, next is the exception details. The ExceptionDispatchInfo class defines a few static methods that allow for the capture of an exception’s state. It is part of the System.Runtime.ExceptionServices namespace. I remember the first time I had to debug an error that was throwing an exception but the call stack was gone (what a joy to discover). If you want to have your exceptions bubble up to your calling location (this is the default behavior), then you will get the original exception including its saved call stack. 

I have defined several explicit cast operators should you wish to cast this class to a different, more useful type. The meaning of these cast operators is clear. If you read and understand this class, you should understand those easily. I have put comments throughout the code where I thought it would be useful.

I have put an extension method that does part of what this wrapper in the code as well, should you be interested in looking at it. Also, I typed up a quick ExecuteTransaction extension method for you to look at if you want the functionality of a database unit of work (included in the code). I prefer to handle database transactions in stored procedures myself, but feel free to use this. Simply select all the code below and paste it into a single C# cs file.

I think any experienced C# developer should be able to read the code and understand it. For that reason, I have not discussed the code itself. It is below for your perusal. UnitOfWork is a flexible, free, and modifiable generic class wrapper that solves many core enterprise issues. In this case, performance monitoring, logging, and exception handling were addressed. I can think of other things that could be added to this to be of benefit to specific enterprises. Authentication and authorization, to name two, but I leave this to implement for yourself, since that is pretty different for each enterprise.

About the author...

Lee McGraw has worked in the technology industry for over 30 years, first developing on an Apple II. He has served as Enterprise Developer and Architect for entities such as AIG, Ford, Coke, USAA, US Department of Defense and Energy, and many banks.

Thanks to Peter Vogel for proof reading this.

/*
 * Written by Lee McGraw (in my personal free time), Enterprise Architect/Developer US DoD
 * Feel free to modify this code to suit your own needs.
 * An article accompanies this code, titled "Standardization of Performance Monitoring, Logging, and Exception Handling via a .NET Runtime Wrapper"
 * Google it if you are interested.
 */


using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Runtime.CompilerServices;
using System.Runtime.ExceptionServices;
using System.Runtime.Serialization.Json;
using System.Text;
using static System.Console;
using static System.String;


namespace CoreConsoleAppLee
{
    public class MyReferenceClass
    {
        public string Name { get; set; }
    }
    class Program
    {
        public string InstanceMethod(int num)
        {
            return "Inside of Instance Method. " + num.ToString();
        }
        public static string StaticMethod(int num)
        {
            return "Inside of Static Method. " + num.ToString();
        }


        static void Main(string[] args)
        {
            var myProgram = new Program();
            var uow = new UnitOfWork<int, string>(r =>
            {
                return "Inside of Statement Lambda. " + r.ToString();
            })
            {
                UnitOfWorkName = "Demostration of Unit of Work usage."
            };
            uow.AddFunction(r => "Inside of Expression Lambda." + r.ToString());  
            uow.AddFunction(r => StaticMethod(r));
            uow.AddFunction(r => myProgram.InstanceMethod(r));
            var input = 10;
            uow.Execute(input);


            Console.WriteLine("\nInputs to calls...");
            uow.Inputs.ForEach(r =>
            {
                Console.WriteLine(r.ToString());
            });
            Console.WriteLine("\nOutputs to calls...");
            uow.Outputs.ForEach(r =>
            {
                Console.WriteLine(r.ToString());
            });
            
            var uow2 = new UnitOfWork<MyReferenceClass, MyReferenceClass>(r =>
              {
                  r.Name = r.Name.ToUpper();
                  return r;
              });
            uow2.AddFunction(f =>
            {
                f.Name = f.Name.ToLower();
                return f;
            });
            var res = uow2.Execute(new MyReferenceClass { Name = "Daffy Duck" });


            Console.WriteLine("\nInputs to calls...");
            uow2.Inputs.ForEach(r =>
            {
                Console.WriteLine(r.Name.ToString());
            });
            Console.WriteLine("\nOutputs to calls...");
            uow2.Outputs.ForEach(r =>
            {
                Console.WriteLine(r.Name.ToString());
            });


            var i = 0;
        }
    }


    /// <summary>
    /// This class encapsulates the performance timing, exception handling, and logging of a method and/or a group of methods.  
    /// Do NOT be confused by the name of the class.  It is NOT a database UnitOfWork, although that support could easily be added.  
    /// The purpose of this class is to handle a measurable unit of work, as well as a logical endpoint for exception handling.
    /// </summary>
    /// <typeparam name="IN">Type being passed as input the method; this is not necessarily a single object, because it could be a collection.</typeparam>
    /// <typeparam name="OUT">Type being returned by the method; this is not necessarily a single object, because it could be a collection or a tuple of many types.</typeparam>
    public class UnitOfWork<IN, OUT>
    {
        private const string defaultUnitOfWorkName = "UnitOfWork";


        #region Members


        protected Dictionary<UnitType, Stopwatch> stopWatch { get; set; }
        protected Exception exception { get; set; }
        protected List<ILogger> Loggers { get; set; } = new List<ILogger>();


        #endregion Members        


        #region Properties
        private string CallerMethodName { get; set; }
        private int CallerLineNumber { get; set; }
        private string CallerFilePath { get; set; }
        public string UnitOfWorkName { get; set; } = defaultUnitOfWorkName;
        private string MethodName { get; set; }
        public bool UseStopwatch { get; set; } = true;
        public bool UseTryCatch { get; set; } = true;
        public bool RethrowExceptions { get; set; } = true;


        //private get below to prevent the developer using this to bypass the operational logic of the execute method, thereby negating the intension of this completely.
        public List<Func<IN, OUT>> Functions { private get; set; } = new List<Func<IN, OUT>>();
        public Func<IN, OUT> Function { private get; set; }
        public List<IN> Inputs { get; private set; }
        public List<OUT> Outputs { get; private set; }


        #endregion Properties


        #region Constructors


        public UnitOfWork(
            Func<IN, OUT> function,
            string unitOfWorkName = defaultUnitOfWorkName,
            bool useStopwatch = true,
            bool useTryCatch = true,
            bool rethrowExceptions = true,
            ILogger logger = null)
            : this(new Func<IN, OUT>[] { function }, unitOfWorkName, useStopwatch, useTryCatch, rethrowExceptions, logger, true) { }


        public UnitOfWork(
            Func<IN, OUT>[] functions,
            string unitOfWorkName = defaultUnitOfWorkName,
            bool useStopwatch = true,
            bool useTryCatch = true,
            bool rethrowExceptions = true,
            ILogger logger = null,
            bool uniqueSignaturePurposesOnly = true)
        {
            //the uniqueSignaturePurposesOnly parameter is only there to make this constructor have a unique signature, and can be ignored as it is not used.
            if (functions == null || functions.Length == 0)
            {
                throw new ArgumentException("The value of functions can not be null or empty!");
            }
            InitParameters();
            InitStopwatch();
            InitLoggers();


            void InitParameters()
            {
                Function = functions[0];
                AddFunction(functions);
                UnitOfWorkName = unitOfWorkName ?? defaultUnitOfWorkName;
                //if the parameter was null, then perhaps it was set in the constructor already, else use the Method name
                MethodName = Function.Method.Name;
                UseStopwatch = useStopwatch;
                UseTryCatch = useTryCatch;
                RethrowExceptions = rethrowExceptions;
            }
            void InitLoggers()
            {
#if DEBUG
                Loggers = new List<ILogger>();
                Loggers.Add(logger ?? new ConsoleLogger());
#endif
                if (logger != null)
                {
                    Loggers = Loggers ?? new List<ILogger>();
                    Loggers.Add(logger);
                }


            }
            void InitStopwatch()
            {
                if (useStopwatch)
                {
                    stopWatch = new Dictionary<UnitType, Stopwatch>();
                    stopWatch.Add(UnitType.UnitOfWork, new Stopwatch());
                    stopWatch.Add(UnitType.Method, new Stopwatch());                  
                }
            }
        }


        #endregion Constructor


        #region Methods        


        public void AddFunction(params Func<IN, OUT>[] functions) => Functions.AddRange(functions);
        public void AddLogger(params ILogger[] loggers) => Loggers.AddRange(loggers);


        public OUT Execute(
            IN input,
            [CallerMemberName] string callerMethodName = "",
            [CallerLineNumber] int callerLineNumber = 0,
            [CallerFilePath] string callerFilePath = ""
            )
        {
            OUT result = default(OUT);
            CallerMethodName = callerMethodName;
            CallerLineNumber = callerLineNumber;
            CallerFilePath = callerFilePath;
            if (Functions.Count > 1)
            {
                Inputs = Inputs ?? new List<IN>();
                Outputs = Outputs ?? new List<OUT>();
            }
            if (UseTryCatch)
            {
                try
                {
                    Run();
                }
                catch (Exception e)
                {
                    ExceptionDispatchInfo.Capture(e);
                    exception = e;
                    Loggers.ForEach(log =>
                        log.WriteError($@"
An ERROR has occurred!
{UnitOfWorkName}-{MethodName}",
Concat($@"
Caller Info:
Method={CallerMethodName}
Line={CallerLineNumber} 
Path={CallerFilePath}
", ((ExceptionManager)exception).ToString())
                        )
                    );
                    if (RethrowExceptions) ExceptionDispatchInfo.Throw(e);
                }
                finally
                {
                    End(UnitType.UnitOfWork);
                }
            }
            else
            {
                Run();
            }
            return result;
            void Run()
            {
                Start(UnitType.UnitOfWork);
                Functions?.ForEach(f =>
                {
                    Function = f;
                    MethodName = f.Method.Name;
                    Start();
                    Inputs?.Add(Clone(input));
                    result = (f != null ? f.Invoke(input) : result);
                    Outputs?.Add(Clone(result));
                    End();
                });
                End(UnitType.UnitOfWork);
            }
        }
        protected virtual void Start(UnitType unitType = UnitType.Method)
        {
            if (!UseStopwatch) return;
            Loggers.ForEach(log =>
                log.WriteInfo(
                    generateSource(unitType),
                    generateMessage(unitType, $"Starting at {System.DateTime.Now.ToString()}!")
                )
            );
            if (stopWatch[unitType].IsRunning) stopWatch[unitType].Reset();
            stopWatch[unitType].Start();            
        }
        protected virtual void End(UnitType unitType = UnitType.Method)
        {
            if (!UseStopwatch) return;
            stopWatch[unitType].Stop();
            Loggers.ForEach(log =>
                log.WriteInfo(
                    generateSource(unitType),
                    generateMessage(unitType, Concat("Ran in ", stopWatch[unitType].ElapsedMilliseconds.ToString(), $"ms. Ending at {System.DateTime.Now.ToString()}!"))
                )
            );
        }


        private string generateSource(UnitType unitType)
        {
            return Concat(unitType.ToString(), "|", unitType == UnitType.UnitOfWork ? UnitOfWorkName : MethodName);
        }
        private string generateMessage(UnitType unitType, string postFix = "")
        {
            return Concat("(", unitType == UnitType.UnitOfWork ? UnitOfWorkName : MethodName, ")", postFix);
        }
        /// <summary>
        /// Perform a deep Copy of the object, using Json as a serialization method. 
        /// NOTE: Private members are not cloned using this method.
        /// Serializable attribute is not required, but if it's an object, the class needs a parameterless constructor.
        /// </summary>
        /// <typeparam name="T">The type of object being copied.</typeparam>
        /// <param name="source">The object instance to copy.</param>
        /// <returns>The copied object.</returns>
        private T Clone<T>(T source)
        {
            var result = default(T);
            var jsonString = "";
            using (var stream = new MemoryStream())
            {
                var serializer = new DataContractJsonSerializer(typeof(T));
                serializer.WriteObject(stream, source);
                byte[] json = stream.ToArray();
                jsonString = Encoding.UTF8.GetString(json, 0, json.Length);
            }
            using (var stream = new MemoryStream(Encoding.UTF8.GetBytes(jsonString)))
            {
                var serializer = new DataContractJsonSerializer(typeof(T));
                result = (T)serializer.ReadObject(stream);
            }
            return result;
        }


        #endregion Methods


        #region Cast Operators


        public static explicit operator Func<IN, OUT>(UnitOfWork<IN, OUT> unitOfWork)
            => unitOfWork.Function;
        public static explicit operator List<Func<IN, OUT>>(UnitOfWork<IN, OUT> unitOfWork)
            => unitOfWork.Functions;
        public static explicit operator UnitOfWork<IN, OUT>(List<Func<IN, OUT>> functions)
            => new UnitOfWork<IN, OUT>(functions.ToArray());
        public static explicit operator UnitOfWork<IN, OUT>(Func<IN, OUT> function)
            => new UnitOfWork<IN, OUT>(function);


        #endregion Cast Operators
    }


    public enum UnitType
    {
        Method,
        UnitOfWork
    }
    public static class Extender
    {
        public static void ExecuteTransaction(this System.Data.IDbConnection connection, params System.Data.IDbCommand[] commands)
        {
            using (connection)
            {
                if (connection.State != System.Data.ConnectionState.Open) connection.Open();
                using (var transaction = connection.BeginTransaction())
                {
                    try
                    {
                        foreach (var command in commands)
                        {
                            command.ExecuteNonQuery();
                        }
                        transaction.Commit();
                    }
                    catch
                    {
                        transaction.Rollback();
                    }
                }
            }
        }
        public static OUT Execute<IN, OUT>(this IN toThat,
            bool useTryCatch = true,
            params Func<IN, OUT>[] doThis)
        {
            var result = default(OUT);
            if (toThat == null && doThis == null) return result;
            if (useTryCatch)
            {
                try
                {
                    foreach (var function in doThis)
                    {
                        result = function(toThat);
                    }
                }
                catch
                {
                    throw;
                }
            }
            else
            {
                foreach (var function in doThis)
                {
                    result = function(toThat);
                }
            }
            return result;
        }


        public static void With<T>(this T toThat, Action<T> doThis) where T : class
            => doThis?.Invoke(toThat);
        public static OUT With<IN, OUT>(this IN toThat, Func<IN, OUT> doThis)
            => doThis.Invoke(toThat);
    }


    #region EventViewerLogger


    /// <summary>
    /// You need the .NET Core compatibility nuget package, if you use this in .NET Core, to write to the EventViewer.
    /// Search NuGet for package named Microsoft.Windows.Compatibility.
    /// This could have been accomplished via a delegate too, but that would add overhead,
    /// and if this used enterprise wide, that's the LAST thing we want.
    /// </summary>
    public class EventViewerLogger : ILogger
    {
        public EventViewerLogger() { }
        public virtual void WriteInfo(string source, string message)
        {
            EventLog.WriteEntry(source, message);
        }
        public virtual void WriteError(string source, string message)
        {
            EventLog.WriteEntry(source, message);
        }
    }


    #endregion EventViewerLogger


    #region ConsoleLogger
    public class ConsoleLogger : ILogger
    {
        public ConsoleLogger() { }
        public virtual void WriteInfo(string source, string message)
        {
            WriteLine(source + "-" + message);
        }
        public virtual void WriteError(string source, string message)
        {
            WriteLine(source + "-" + message);
        }
    }


    #endregion ConsoleLogger


    #region ILogger


    /// <summary>
    /// To implement your own logger, implement this interface.  
    /// </summary>
    public interface ILogger
    {
        void WriteInfo(string source, string message);
        void WriteError(string source, string message);
    }


    #endregion ILogger


    public struct ExceptionManager
    {
        private Exception exception;
        private ExceptionManager(Exception exception)
        {
            this.exception = exception;
        }


        public override string ToString()
        {
            var sb = new StringBuilder();
            sb.Append("**********\n");
            do
            {
                sb.Append($"Message:{exception.Message}");
                sb.Append($"\nSource:{exception.Source}");
                sb.Append($"\nTargetSite:{exception.TargetSite}");
                sb.Append($"\nStackTrace:{exception.StackTrace}");
                sb.Append($"\nHelpLink:{exception.HelpLink}");
                exception = exception.InnerException;
                if (exception != null) sb.Append("\n----------");
            } while (exception != null);
            sb.Append("\n**********\n");
            return sb.ToString();
        }
        public static explicit operator Exception(ExceptionManager exceptionManager)
        {
            return exceptionManager.exception;
        }
        public static explicit operator ExceptionManager(Exception exception)
        {
            return new ExceptionManager(exception);
        }
        public static explicit operator string(ExceptionManager exceptionManager)
        {
            return exceptionManager.ToString();
        }
    }
}