Performance Timers

Written By : Lam Chan

When I build out API's or services type applications, I tend to go a little heavy on the logging so that it is easy to identify issues with the processing.  I am the type of developer who does not like to scour through event logs for exceptions and then have to back trace that to the code from the source event since I feel that is inefficient if you're dealing with production issues.  So everything is logged into INFO, WARN, ERROR categories and I adjust my logging mechanism to only record the level of details I need for the environment. 

Time and time again, I've run into wanting to capture how long does "X" segment of code takes to process.  So I've developed this piece of code that does just that.  I'm leveraging the IDisposable interface because it neatly ties into how my stop watch timer works anyways.

Here is the code of my Stopwatch implementation

    public class LogTimer : IDisposable 
    {
        private readonly Stopwatch _stopwatch;
        private readonly  Logger_logger;
        private readonly object _id;

        public LogTimer(Logger logger)
        {
            _stopwatch = new Stopwatch();
            _stopwatch.Start();
            
            _logger = logger;
        }

        public LogTimer(Logger logger, BaseDto message) : this(logger)
        {
            _id = message.Id;

            _logger.RecordStart(message);
        }

        public void Dispose()
        {
            _stopwatch.Stop();
            _logger.RecordEnd(_id, _stopwatch.Elapsed);
        }
    }

 

Note the dataImportData stuff is not important.  I'm just passing in some data for extra logging so I can trace back in the log which data processing is associated with the timer log.  I need this in mult-threaded applications where the log is written into from multiple source timings.  What is important is the starting of the stopwatch in the constructor and the stopping of the stopwatch and logging of the stopwatch duration in the Dispose method.

And this is how you would use it.

                using (var timer = new LogTimer(_logger, dataImportData))
                {
                    var result = _processDataImport.Process(dataImportData);

                    _logger.Record(result);    
                }

See how I'm utilizing the "using" statement and wrapping all of my logic I want a performance data around. 

Tags: ,

No comments yet.

Post your comment